Can only send one command to Controller

[eljuanchete]

Hi, using evohome-Listener v2.0.1 (python3 version) with evofw2. I tried evofw3 uart branch but could not get it to work. I am trying to send a setpoint to 3 zones in a loop from Openhab but only the first setpoint is sent. All other two commands are ignored. I have tried to set a delay between the 3 commands, but without luck. The first command is acknowledged

2020-10-22 22:21:45 |1/ - | COMMAND_OUT | SETPOINT_OVERRIDE ['Salon': 20 degC until 2020-10-22T23:55:00Z] Command SENT
2020-10-22 22:21:46 |1/ - | SETPOINT_OVERRIDE | W | GWAY EvoGateway -> CONTROLLER | 20.00°C @ Salon [Zone 1 ] - Until 2020-10-22 23:55:00 2020-10-22 22:21:46 |1/053| SETPOINT_OVERRIDE | I | CONTROLLER -> BROADCAST MESSAGE | 20.00°C @ Salon [Zone 1 ] - Until 2020-10-22 23:55:00 2020-10-22 22:21:46 |1/053| SETPOINT | I | CONTROLLER -> BROADCAST MESSAGE | 20.00°C @ Salon [Zone 1 ]
2020-10-22 22:21:46 |1/053| SETPOINT_OVERRIDE | I | CTL Salon -> GWAY EvoGateway | 20.00°C @ Salon [Zone 1 ] - Until 2020-10-22 23:55:00 2020-10-22 22:21:46 |1/ - | COMMAND_OUT | SETPOINT_OVERRIDE ['Salon': 20 degC until 2020-10-22T23:55:00Z] Command ACKNOWLEDGED

but no more commands are sent.

evolistener.log content is

2020-10-22 22:21:45 |-| MQTT_SUB {'command': 'setpoint_override', 'arguments': {'setpoint': 20, 'zone_id': 1, 'until': '2020-10-22T23:55:00Z'}} 2020-10-22 22:21:45 |1| COMMAND_OUT SETPOINT_OVERRIDE: Sending 'W --- 30:071715 01:088499 --:------ 2349 013 0007D004FFFFFF3717160A07E4' 2020-10-22 22:21:46 |1| SETPOINT_OVERRIDE --- W --- 30:071715 01:088499 --:------ 2349 013 0007D004FFFFFF3717160A07E4 2020-10-22 22:21:46 |1| SETPOINT_OVERRIDE --- 053 I --- 01:088499 --:------ 01:088499 2349 013 0007D004FFFFFF3717160A07E4 2020-10-22 22:21:46 |1| SETPOINT --- 053 I --- 01:088499 --:------ 01:088499 2309 003 0007D0 2020-10-22 22:21:46 |1| SETPOINT_OVERRIDE --- 053 I --- 01:088499 30:071715 --:------ 2349 013 0007D004FFFFFF3717160A07E4

After sending the command, the MQTT topics for cul_evo_gateway/sent_command are

sent_command = True ack = False command = setpoint_override {'setpoint': 20, 'zone_id': 1, 'until': '2020-10-22T23:55:00Z'} evo_msg = W --- 30:071715 01:088499 --:------ 2349 013 0007D004FFFFFF3717160A07E4 failed = False initial_sent_ts = 2020-10-22T20:18:37Z last_retry_ts = 2020-10-15T08:36:08Z org_instruction = {"command": "setpoint_override", "arguments": {"setpoint": 20, "zone_id": 1, "until": "2020-10-22T23:55:00Z"}} retries = 0

and evohome-Listener seems to stop sending MQTT messages anymore. It seems as if the ACK is ACKNOWLEDGED but not recognized so no more commands are processed? I have taken a look at the code but my coding skills are not very good and could not make progress. I think that the problem is in line 1774

if last_sent_command and msg.source == last_sent_command.destination and msg.destination == THIS_GATEWAY_ID:

but I have not been able to find the exact problem.

Do not hesitate to contact for any tests you need. Best regards

[smar000]

That's odd. I am regularly sending messages from openHAB (infact, I send a batch of 4 or 5 messages in one go every 5 minutes to get various openTherm data).

Are your 3 messages showing up in your mqtt broker, and then showing up in the evolistener logs? i.e. are you sure the messages have got through?

[eljuanchete]

Yes, the three messages are being sent via MQTT. Also, although I get "Command ACKNOWLEDGED" events in events.log the MQTT topic ack is always False and the timestamp of this topic in MQTT is the same of the first MQTT message, as well as the timestamp of all the other topics under cul_evo_gateway/sent_command So, it seems that sequence is: 1.- First MQTT message sent 2.- MQTT message subscription processed vi evohome-Listener 3.- MQTT message sent to the controller "Command SENT" 4.- All topics are updated in /sent_command with ack=False, failed=False and retries=0 5.- ACK received from controller "Command ACKNOWLEDGED" 6.- Second MQTT message sent 7.- Third MQTT message sent

So, it seems that between step 5 and 6 at least I am missing ack=True

In case it helps, I have also tried setting different THIS_GATEWAY_ID values in evogateway.cfg as I have seen several different IDs in different posts/issues, and in all cases it seems as if the first message is sent and acknowledged but not the other messages. I have configured a sleep of up to 2 seconds between commands too

Any other idea to continue debugging?

[smar000]

Changing the THIS_GATEWAY_ID should not make any difference, as you are receiving messages back (as confirmed by the acknowledgement of your message).

I genuinely have no idea as to why your repeat commands are not working. It has been working fine for me for 2 years+.

Are you 100% sure that your command messages are getting through to the listener? Each time a command message is sent, it will print this in your window, and save to the file (do a search for COMMAND_OUT in the log). Are you seeing 3 such messages in your log?

Finally, what do you have in your config file for COMMAND_RESEND_TIMEOUT_SECS and COMMAND_RESEND_ATTEMPTS?

[eljuanchete]

Yes, 100% sure. I kept debugging and think I have now found the error. The log file only contains the events, but the docker container log where evohome-listener is running shows an exception when the first MQTT command is processed. That's why it does not continue and no more MQTT messages are sent. I changed all my setup to docker some months ago but did not try to send commands as heating was off in spring/summer.

So, it seems as if there is a problem decoding JSON {"command":"setpoint_override", "arguments" : {"setpoint": 16.0, "zone_id" : 1}}

2020-10-24 00:35:19 |1/ - | COMMAND_OUT | SETPOINT_OVERRIDE ['Salon': 16.0 deg C] Command SENT
Exception in thread Thread-1: Traceback (most recent call last): File "/usr/local/lib/python3.6/threading.py", line 916, in _bootstrap_inner self.run() File "/usr/local/lib/python3.6/threading.py", line 864, in run self._target(*self._args, **self._kwargs) File "/usr/local/lib/python3.6/site-packages/paho/mqtt/client.py", line 3452, in _thread_main self.loop_forever(retry_first_connection=True) File "/usr/local/lib/python3.6/site-packages/paho/mqtt/client.py", line 1779, in loop_forever rc = self.loop(timeout, max_packets) File "/usr/local/lib/python3.6/site-packages/paho/mqtt/client.py", line 1181, in loop rc = self.loop_read(max_packets) File "/usr/local/lib/python3.6/site-packages/paho/mqtt/client.py", line 1572, in loop_read rc = self._packet_read() File "/usr/local/lib/python3.6/site-packages/paho/mqtt/client.py", line 2310, in _packet_read rc = self._packet_handle() File "/usr/local/lib/python3.6/site-packages/paho/mqtt/client.py", line 2936, in _packet_handle return self._handle_publish() File "/usr/local/lib/python3.6/site-packages/paho/mqtt/client.py", line 3216, in _handle_publish self._handle_on_message(message) File "/usr/local/lib/python3.6/site-packages/paho/mqtt/client.py", line 3444, in _handle_on_message self.on_message(self, self._userdata, message) File "/opt/evogateway/evogateway.py", line 487, in mqtt_on_message json_data = json.loads(str(msg.payload, "utf-8")) File "/usr/local/lib/python3.6/json/init.py", line 354, in loads return _default_decoder.decode(s) File "/usr/local/lib/python3.6/json/decoder.py", line 339, in decode obj, end = self.raw_decode(s, idx=_w(s, 0).end()) File "/usr/local/lib/python3.6/json/decoder.py", line 357, in raw_decode raise JSONDecodeError("Expecting value", s, err.value) from None json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0) 2020-10-24 00:35:19 |1/ - | SETPOINT_OVERRIDE | W | GWAY EvoGateway -> CONTROLLER | 16.00°C @ Salon [Zone 1 ]
2020-10-24 00:35:19 |1/052| SETPOINT_OVERRIDE | I | CONTROLLER -> BROADCAST MESSAGE | 16.00°C @ Salon [Zone 1 ]
2020-10-24 00:35:19 |1/052| SETPOINT | I | CONTROLLER -> BROADCAST MESSAGE | 16.00°C @ Salon [Zone 1 ]
2020-10-24 00:35:19 |1/052| SETPOINT_OVERRIDE | I | CTL Salon -> GWAY EvoGateway | 16.00°C @ Salon [Zone 1 ]
2020-10-24 00:35:19 |1/ - | COMMAND_OUT | SETPOINT_OVERRIDE ['Salon': 16.0 deg C] Command ACKNOWLEDGED

Python version is 3.6.8 and Dockerfile is

FROM python:3.6.8 RUN mkdir /opt/evogateway WORKDIR /opt/evogateway RUN pip install --upgrade pip RUN pip install pyserial RUN pip install paho-mqtt RUN pip install enum34 COPY ./data/* /opt/evogateway/ CMD [ "python", "/opt/evogateway/evogateway.py" ]

I changed the container to use UTF-8 and made a test to check python is using UTF8

root@905cf87e0d8b:/opt/evogateway# python Python 3.6.8 (default, Jun 11 2019, 01:16:11) [GCC 6.3.0 20170516] on linux Type "help", "copyright", "credits" or "license" for more information.

print(chr(0x5555)) 啕

So it seems that this is fine. Then uncommented debug lines print(msg.payload) and print(json_data) in lines 483 and 488 and see

b'{"command":"setpoint_override", "arguments" : {"setpoint": 16.0, "zone_id" : 1}}' {'command': 'setpoint_override', 'arguments': {'setpoint': 16.0, 'zone_id': 1}} 2020-10-24 12:29:59 |1/ - | COMMAND_OUT | SETPOINT_OVERRIDE ['Salon': 16.0 deg C] Command SENT
b'' Exception in thread Thread-1: Traceback (most recent call last): File "/usr/local/lib/python3.6/threading.py", line 916, in _bootstrap_inner self.run() File "/usr/local/lib/python3.6/threading.py", line 864, in run self._target(*self._args, **self._kwargs) File "/usr/local/lib/python3.6/site-packages/paho/mqtt/client.py", line 3452, in _thread_main self.loop_forever(retry_first_connection=True) File "/usr/local/lib/python3.6/site-packages/paho/mqtt/client.py", line 1779, in loop_forever rc = self.loop(timeout, max_packets) File "/usr/local/lib/python3.6/site-packages/paho/mqtt/client.py", line 1181, in loop rc = self.loop_read(max_packets) File "/usr/local/lib/python3.6/site-packages/paho/mqtt/client.py", line 1572, in loop_read rc = self._packet_read() File "/usr/local/lib/python3.6/site-packages/paho/mqtt/client.py", line 2310, in _packet_read rc = self._packet_handle() File "/usr/local/lib/python3.6/site-packages/paho/mqtt/client.py", line 2936, in _packet_handle return self._handle_publish() File "/usr/local/lib/python3.6/site-packages/paho/mqtt/client.py", line 3216, in _handle_publish self._handle_on_message(message) File "/usr/local/lib/python3.6/site-packages/paho/mqtt/client.py", line 3444, in _handle_on_message self.on_message(self, self._userdata, message) File "/opt/evogateway/evogateway.py", line 487, in mqtt_on_message json_data = json.loads(msg.payload.decode("utf-8")) File "/usr/local/lib/python3.6/json/init.py", line 354, in loads return _default_decoder.decode(s) File "/usr/local/lib/python3.6/json/decoder.py", line 339, in decode obj, end = self.raw_decode(s, idx=_w(s, 0).end()) File "/usr/local/lib/python3.6/json/decoder.py", line 357, in raw_decode raise JSONDecodeError("Expecting value", s, err.value) from None json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0) 2020-10-24 12:29:59 |1/ - | SETPOINT_OVERRIDE | W | GWAY EvoGateway -> CONTROLLER | 16.00°C @ Salon [Zone 1 ]
2020-10-24 12:29:59 |1/051| SETPOINT_OVERRIDE | I | CONTROLLER -> BROADCAST MESSAGE | 16.00°C @ Salon [Zone 1 ]
2020-10-24 12:29:59 |1/051| SETPOINT | I | CONTROLLER -> BROADCAST MESSAGE | 16.00°C @ Salon [Zone 1 ]
2020-10-24 12:29:59 |1/051| SETPOINT_OVERRIDE | I | CTL Salon -> GWAY EvoGateway | 16.00°C @ Salon [Zone 1 ]
2020-10-24 12:29:59 |1/ - | COMMAND_OUT | SETPOINT_OVERRIDE ['Salon': 16.0 deg C] Command ACKNOWLEDGED

Then I tried to make some changes in the json.loads line but, to be honest, I don't know very well what I am doing. Do you have any idea on what might be wrong related to this UTF8 coding?

[smar000]

Ah ok, you didn't mention before that you were running in a docker (shouldn't make a difference if done in exactly the same way, but introduces another potential source of problems). I had a quick look at your log above and the respective code, but nothing jumps out. It may be worth trying it out without the docker environment and see if that shows anything further.

Sorry, but unfortunately I don't really have the time to spend much further on this.

[eljuanchete]

Yes, I understand this does not seem related to the script but to the environment where it is running. I have made a quick change to avoid the exception in case an invalid JSON is sent.

The changes proposed are just to catch the exception. This is working fine in my environment. Maybe this can incorporated in evohome-Listener? What do you think?

At beginning of script

from json.decoder import JSONDecodeError

Line 487

  try:
    json_data = json.loads(msg.payload.decode())
    #print(json_data)
    log("{: <18} {}".format("MQTT_SUB", json_data))

    if SYS_CONFIG_COMMAND in json_data:
      if json_data[SYS_CONFIG_COMMAND] in RESET_COM_PORTS:
        new_command = get_reset_serialports_command()
        new_command.instruction = json.dumps(json_data)
      elif json_data[SYS_CONFIG_COMMAND] == CANCEL_SEND_COMMANDS:
        send_queue = []
        last_sent_command = None
        display_and_log(SYSTEM_MSG_TAG, "Cancelled all queued outbound commands")
        return
      else:
        display_and_log(SYSTEM_MSG_TAG, "System configuration command '{}' not recognised".format(json_data[SYS_CONFIG_COMMAND]))
        return
    else:
      new_command = get_command_from_mqtt_json(json_data)

    send_queue.append(new_command)
  except JSONDecodeError as e:
    return

[smar000]

Thanks. I'll consider it next time I'm looking at the code, but in general I don't like silently dropping errors. Better to understand the cause of the problem and then try to address that if possible (admittedly not always easy!).

[dhuizinga]

I apologize in advance for what is likely inappropriate use of this commenting-on-a-closed-issue to gain some specific knowledge on the topic of using this script with docker, but can I ask whether the the end the docker approach below is now functional, @eljuanchete ?

Python version is 3.6.8 and Dockerfile is

FROM python:3.6.8 RUN mkdir /opt/evogateway WORKDIR /opt/evogateway RUN pip install --upgrade pip RUN pip install pyserial RUN pip install paho-mqtt RUN pip install enum34 COPY ./data/* /opt/evogateway/ CMD [ "python", "/opt/evogateway/evogateway.py" ]

And while on the subject, it looks as if the dockerfile above uses the script already present on the host. Is there an idiot-proof way of including even the retrieval of the (latest) script from this repository in above dockerfile?

Again, apologies if inappropriate, kindly tell me what would be the appropriate way to discuss such topics :)

[eljuanchete]

Hello, this is (IIRC) the docker file I used (more or less like yours except you are not installing ramsesrf (take into count that a new release of ramses_rf with breaking changes has just been released so maybe you should use the previous one)) FROM python:3

RUN mkdir /opt/evogateway WORKDIR /opt/evogateway

RUN pip install pyserial RUN pip install paho-mqtt RUN pip install enum34 RUN pip install colorama RUN pip install ramses_rf

COPY ./data/* /opt/evogateway/

CMD [ "python", "/opt/evogateway/evogateway.py" ]

I did not configure an automated download and perform manual upgrades I seem to recall that I had problems while setting up the latest version due to the changes in config files, but can’t remember what was the problem and how I solved it. I just can tell that once I got it working it has been running smoothly since then Sorry I cannot be of much help here Best regards

El 6 sept 2021, a las 21:57, dhuizinga @.***> escribió:

I apologize in advance for what is likely inappropriate use of this commenting-on-a-closed-issue to gain some specific knowledge on the topic of using this script with docker, but can I ask whether the the end the docker approach below is now functional, @eljuanchete https://github.com/eljuanchete ?

Python version is 3.6.8 and Dockerfile is

FROM python:3.6.8 RUN mkdir /opt/evogateway WORKDIR /opt/evogateway RUN pip install --upgrade pip RUN pip install pyserial RUN pip install paho-mqtt RUN pip install enum34 COPY ./data/* /opt/evogateway/ CMD [ "python", "/opt/evogateway/evogateway.py" ]

And while on the subject, it looks as if the dockerfile above uses the script already present on the host. Is there an idiot-proof way of including even the retrieval of the (latest) script from this repository in above dockerfile?

Again, apologies if inappropriate, kindly tell me what would be the appropriate way to discuss such topics :)

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/smar000/evoGateway/issues/23#issuecomment-913831253, or unsubscribe https://github.com/notifications/unsubscribe-auth/AGM5I4C6ZGMXXLTG6ZRT3C3UAUMKNANCNFSM4S3WO6EQ. Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.