Command sometimes not executed

[michnovka]

Sometimes when I send command, it is not working. I have to send it 2nd time.

I have captured this in log:

homeassistant  | 2025-01-16 16:22:06.071 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*1*1*41##` was successfully queued.
homeassistant  | 2025-01-16 16:22:06.072 DEBUG (MainThread) [custom_components.myhome] MH202 Gateway (192.168.1.40) Message `*1*1*41##` was successfully unqueued by worker 0.
homeassistant  | 2025-01-16 16:22:06.075 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*1*1*41##` received response `*#4*4*14*0225##`.

the 2nd click does this:

homeassistant  | 2025-01-16 16:22:21.313 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*1*1*41##` was successfully queued.
homeassistant  | 2025-01-16 16:22:21.314 DEBUG (MainThread) [custom_components.myhome] MH202 Gateway (192.168.1.40) Message `*1*1*41##` was successfully unqueued by worker 0.
homeassistant  | 2025-01-16 16:22:21.315 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Command session connection reset, retrying...
homeassistant  | 2025-01-16 16:22:21.315 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Opening command session.
homeassistant  | 2025-01-16 16:22:21.323 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Negotiating command session.
homeassistant  | 2025-01-16 16:22:21.325 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Received nonce: `*#159348384##`
homeassistant  | 2025-01-16 16:22:21.326 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Sending command session password.
homeassistant  | 2025-01-16 16:22:21.327 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Command session established.
homeassistant  | 2025-01-16 16:22:21.383 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*1*1*41##` was successfully sent.
homeassistant  | 2025-01-16 16:22:21.387 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*1*1000#1*41##`
homeassistant  | 2025-01-16 16:22:21.387 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Ignoring translation message `*1*1000#1*41##`
homeassistant  | 2025-01-16 16:22:21.420 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*1*1*41##`
homeassistant  | 2025-01-16 16:22:21.421 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Light 41 is switched on.

So what does this show?

1. that the first command gets response *#4*4*14*0225## (status message that means that somewhere temperature is 22.5 degrees)
2. the 2nd command then initiated session reset and reauthentication, prior to sending message out

[michnovka]

Related anotherjulien/OWNd#8

[HA-n00b-alt]

Pretty much the same:

2025-01-16 20:53:19.107 DEBUG (MainThread) [custom_components.myhome] [MyHomeServer1 gateway - redacted_IP] Message `*1*0*0213##` was successfully queued.
2025-01-16 20:53:19.107 DEBUG (MainThread) [custom_components.myhome] MyHomeServer1 Gateway (redacted_IP) Message `*1*0*0213##` was successfully unqueued by worker 0.
2025-01-16 20:53:19.108 DEBUG (MainThread) [custom_components.myhome] [MyHomeServer1 gateway - redacted_IP] Message `*1*0*0213##` received response `*4*1*3##`.

And at the second press:

2025-01-16 20:53:23.651 DEBUG (MainThread) [custom_components.myhome] [MyHomeServer1 gateway - redacted_IP] Message `*1*0*0213##` was successfully queued.
2025-01-16 20:53:23.651 DEBUG (MainThread) [custom_components.myhome] MyHomeServer1 Gateway (redacted_IP) Message `*1*0*0213##` was successfully unqueued by worker 0.
2025-01-16 20:53:23.651 DEBUG (MainThread) [custom_components.myhome] [MyHomeServer1 gateway - redacted_IP] Command session connection reset, retrying...
2025-01-16 20:53:23.651 DEBUG (MainThread) [custom_components.myhome] [MyHomeServer1 gateway - redacted_IP] Opening command session.
2025-01-16 20:53:23.652 DEBUG (MainThread) [custom_components.myhome] [MyHomeServer1 gateway - redacted_IP] Negotiating command session.
2025-01-16 20:53:23.658 DEBUG (MainThread) [custom_components.myhome] [MyHomeServer1 gateway - redacted_IP] Received SHA challenge: `*98*2##`
2025-01-16 20:53:23.658 DEBUG (MainThread) [custom_components.myhome] [MyHomeServer1 gateway - redacted_IP] Accepting sha256 challenge, initiating handshake.
2025-01-16 20:53:23.660 DEBUG (MainThread) [custom_components.myhome] [MyHomeServer1 gateway - redacted_IP] Sending command session password.
2025-01-16 20:53:23.694 INFO (MainThread) [custom_components.myhome] [MyHomeServer1 gateway - redacted_IP] Message `*1*0*0213##` was successfully sent.
2025-01-16 20:53:23.762 DEBUG (MainThread) [custom_components.myhome] [MyHomeServer1 gateway - redacted_IP] Message received: `*1*0*0213##`
2025-01-16 20:53:23.763 INFO (MainThread) [custom_components.myhome] [MyHomeServer1 gateway - redacted_IP] Light 0213 is switched off.

Btw are you going to merge the commits from Nacho Garcia to this branch? Happy to help testing if helpful

[N-Soares]

I'm having the same problem. Any idea where to look at? Maybe some sort of time out in OWNd?

[michnovka]

Yea, I think its OWNd problem. I dont even think its timeout related, as look at what we both get on the failed message:

Message `*1*0*0213##` received response `*4*1*3##`.

and

 Message `*1*1*41##` received response `*#4*4*14*0225##`

If OWNd got timed out, id expect it not to receive any reply. So either

1. the log is buggy and it shows some nonsense reply, when in fact it really just timed out
2. somewhen before it gets into "broken" state it saves some received WHO=4 command which it does not understand/handle well as reply in some buffer, thus thinking reply to WHO=1 is this nonsense

[michnovka]

The reason why I dont think that the stream times out is that I keep receiving data. Its not like it stops. Just the very first send is broken, afterwards it reconnects and it continues working.

Looking more into it, the issue is likely in OWNd's connection.py in OWNCommandSession::send function.

Look what it does:

1. writes the message to stream and gets result message
2. checks if message is signaling (ACK/NACK)

• 2a - NACK -> try to send message once again. if again NACK, show error
• 2b - ACK -> show succcess message

3. if not signaling message, log it and read the next message until separator. Then it ASSUMES its signaling:

                resulting_message = OWNSignaling(raw_response.decode())

and checks if its ack or nack.

But what happens if the next message is something else? Well the default values are set from OWNSignaling:

class OWNSignaling(OWNMessage):
    """
    This class is a subclass of messages.
    It is dedicated to signaling messages such as ACK or Authentication negotiation
    """

    def __init__(self, data):  # pylint: disable=super-init-not-called
        self._raw = data
        self._family = None
        self._type = "UNKNOWN"
        self._human_readable_log = data

but thats about it, it wont crash.

Anyways, I dont understand why it receives as a reply to lights command that nonsense. I dont see any buffer being outdated or anything, it really looks like it gets that garbage from reader.

[gdluck]

I think the bug is from sending_workers and is more visible when you have more than 1 worker (concurrent commands from "configure"). Somehow it doesn't wait for ACK and fill the queue when processing each task appended.

[michnovka]

https://github.com/michnovka/HomeAssistant-MyHOME/tree/ownd-included I have created this branch which includes OWNd (my version https://github.com/michnovka/OWNd ) inside, without dependency on pypi.

So for debugging, this will make it much easier, as you can just work on the one git repo. Hope it helps and we catch the bug!

[N-Soares]

Message *1*0*0213## received response *4*1*3##.

Isn't this is a command enable heating for the probe 3? It had to be issued by a thermal controller (or by the HA itself).

Since there's no way to ID if the next message is the reply to the request, maybe there is some sort of asynchrony between WHO (automation vs thermal, for example)?

[gdluck]

We need to implement "wait for response" in Queues - basically a message_id to correctly associate the response to request -

https://pastebin.com/DJwL2ydt

[HA-n00b-alt]

Message *1*0*0213## received response *4*1*3##.

Isn't this is a command enable heating for the probe 3? It had to be issued by a thermal controller (or by the HA itself).

Yes but it's nonsense and it's consistent. I just tried again (the example you quoted was my system this morning). Now it shows:

2025-01-17 16:07:12.103 DEBUG (MainThread) [custom_components.myhome] Message `*1*1*0213##` was successfully queued.
2025-01-17 16:07:12.103 DEBUG (MainThread) [custom_components.myhome] Message `*1*1*0213##` was successfully unqueued by worker 0.
2025-01-17 16:07:12.104 DEBUG (MainThread) [custom_components.myhome] Message `*1*1*0213##` received response `*#4*3*13*00##`.  <- this is nonsense and different than this morning, but still WHO 4 
2025-01-17 16:07:12.104 INFO (MainThread) [custom_components.myhome] Message `*1*1*0213##` was successfully sent.

Then at second pressure

2025-01-17 16:07:15.780 DEBUG (MainThread) [custom_components.myhome] Message `*1*1*0213##` was successfully queued.
2025-01-17 16:07:15.780 DEBUG (MainThread) [custom_components.myhome] Message `*1*1*0213##` was successfully unqueued by worker 0.
2025-01-17 16:07:15.780 DEBUG (MainThread) [custom_components.myhome]  Command session connection reset, retrying... <- Would be good to understand why OWNd triggers this only at the second attempt
2025-01-17 16:07:15.780 DEBUG (MainThread) [custom_components.myhome]  Opening command session.
2025-01-17 16:07:15.781 DEBUG (MainThread) [custom_components.myhome]  Negotiating command session.
2025-01-17 16:07:15.786 DEBUG (MainThread) [custom_components.myhome]  Received SHA challenge: `*98*2##`
2025-01-17 16:07:15.786 DEBUG (MainThread) [custom_components.myhome]  Accepting sha256 challenge, initiating handshake.
2025-01-17 16:07:15.788 DEBUG (MainThread) [custom_components.myhome]  Sending command session password.
2025-01-17 16:07:15.822 INFO (MainThread) [custom_components.myhome]  Message `*1*1*0213##` was successfully sent.
2025-01-17 16:07:15.888 DEBUG (MainThread) [custom_components.myhome]  Message received: `*1*1*0213##`
2025-01-17 16:07:15.888 INFO (MainThread) [custom_components.myhome]  Light 0213 is switched on.

[michnovka]

I added code to log the 2nd message when it does not get ACK/NACK as reply. And it sheds some light on whats going on. Look at this:

homeassistant  | 2025-01-17 16:06:16.417 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 3's target temperature is set to 25.0°C.
homeassistant  | 2025-01-17 16:06:16.423 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*3*12*0250*3##`
homeassistant  | 2025-01-17 16:06:16.423 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 3's local target temperature is set to 25.0°C.
homeassistant  | 2025-01-17 16:06:16.424 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*4*1*3##`
homeassistant  | 2025-01-17 16:06:16.424 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 3's mode is set to 'heat'.
homeassistant  | 2025-01-17 16:06:16.426 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*3*13*00##`
homeassistant  | 2025-01-17 16:06:16.426 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 3's local offset is set to 0°C.
homeassistant  | 2025-01-17 16:06:16.457 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*3*0*0225##`
homeassistant  | 2025-01-17 16:06:16.458 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 3's main sensor is reporting a temperature of 22.5°C.
homeassistant  | 2025-01-17 16:06:16.483 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*3*0*0225##`
homeassistant  | 2025-01-17 16:06:16.483 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 3's main sensor is reporting a temperature of 22.5°C.
homeassistant  | 2025-01-17 16:06:16.626 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*4*110*#3##`
homeassistant  | 2025-01-17 16:06:16.627 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 3's mode is set to 'heat'.
homeassistant  | 2025-01-17 16:06:16.629 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*#3*14*#0250*1##`
homeassistant  | 2025-01-17 16:06:16.629 WARNING (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Data received is not a message: `*#4*#3*14*#0250*1##`
homeassistant  | 2025-01-17 16:06:16.863 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*4*#14*0225*1##`
homeassistant  | 2025-01-17 16:06:16.864 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Received heating command, sending query to zone 4
homeassistant  | 2025-01-17 16:06:16.864 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*4##` was successfully queued.
homeassistant  | 2025-01-17 16:06:16.864 DEBUG (MainThread) [custom_components.myhome] MH202 Gateway (192.168.1.40) Message `*#4*4##` was successfully unqueued by worker 0.
homeassistant  | 2025-01-17 16:06:16.864 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*4##` received response `*#4*3*0*0225##`.
homeassistant  | 2025-01-17 16:06:16.864 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*4##` received second response `*#*1##`.
homeassistant  | 2025-01-17 16:06:16.865 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*4##` was successfully sent.
homeassistant  | 2025-01-17 16:06:16.909 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*4*0*0208##`
homeassistant  | 2025-01-17 16:06:16.909 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 4's main sensor is reporting a temperature of 20.8°C.
homeassistant  | 2025-01-17 16:06:16.948 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*4*14*0225##`
homeassistant  | 2025-01-17 16:06:16.949 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 4's target temperature is set to 22.5°C.
homeassistant  | 2025-01-17 16:06:16.951 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*4*12*0225*3##`
homeassistant  | 2025-01-17 16:06:16.952 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 4's local target temperature is set to 22.5°C.
homeassistant  | 2025-01-17 16:06:16.956 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*4*1*4##`
homeassistant  | 2025-01-17 16:06:16.958 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 4's mode is set to 'heat'.
homeassistant  | 2025-01-17 16:06:16.961 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*4*13*00##`
homeassistant  | 2025-01-17 16:06:16.962 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 4's local offset is set to 0°C.
homeassistant  | 2025-01-17 16:06:17.013 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*4*0*0208##`
homeassistant  | 2025-01-17 16:06:17.014 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 4's main sensor is reporting a temperature of 20.8°C.
homeassistant  | 2025-01-17 16:06:17.140 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#13**22*17*05*00*000*05*17*01*2025##`
homeassistant  | 2025-01-17 16:06:17.140 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Gateway's internal datetime is: 2025-01-17 17:05:00+00:00.
homeassistant  | 2025-01-17 16:06:17.186 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*4*110*#4##`
homeassistant  | 2025-01-17 16:06:17.186 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 4's mode is set to 'heat'.
homeassistant  | 2025-01-17 16:06:17.190 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*#4*14*#0225*1##`
homeassistant  | 2025-01-17 16:06:17.190 WARNING (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Data received is not a message: `*#4*#4*14*#0225*1##`
homeassistant  | 2025-01-17 16:06:17.383 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*5*#14*0230*1##`
homeassistant  | 2025-01-17 16:06:17.383 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Received heating command, sending query to zone 5
homeassistant  | 2025-01-17 16:06:17.384 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*5##` was successfully queued.
homeassistant  | 2025-01-17 16:06:17.384 DEBUG (MainThread) [custom_components.myhome] MH202 Gateway (192.168.1.40) Message `*#4*5##` was successfully unqueued by worker 0.
homeassistant  | 2025-01-17 16:06:17.385 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*5##` received response `*#4*4*14*0225##`.
homeassistant  | 2025-01-17 16:06:17.385 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*5##` received second response `*#4*4*12*0225*3##`.
homeassistant  | 2025-01-17 16:06:17.456 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*5*14*0230##`
homeassistant  | 2025-01-17 16:06:17.456 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 5's target temperature is set to 23.0°C.
homeassistant  | 2025-01-17 16:06:17.459 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*5*12*0230*3##`
homeassistant  | 2025-01-17 16:06:17.459 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 5's local target temperature is set to 23.0°C.
homeassistant  | 2025-01-17 16:06:17.462 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*4*1*5##`
homeassistant  | 2025-01-17 16:06:17.462 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 5's mode is set to 'heat'.
homeassistant  | 2025-01-17 16:06:17.464 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*5*13*00##`
homeassistant  | 2025-01-17 16:06:17.464 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 5's local offset is set to 0°C.
homeassistant  | 2025-01-17 16:06:17.494 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*5*0*0223##`
homeassistant  | 2025-01-17 16:06:17.495 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 5's main sensor is reporting a temperature of 22.3°C.
homeassistant  | 2025-01-17 16:06:17.523 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*5*0*0223##`
homeassistant  | 2025-01-17 16:06:17.523 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 5's main sensor is reporting a temperature of 22.3°C.
homeassistant  | 2025-01-17 16:06:17.663 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*4*110*#5##`
homeassistant  | 2025-01-17 16:06:17.664 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 5's mode is set to 'heat'.
homeassistant  | 2025-01-17 16:06:17.673 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*#5*14*#0230*1##`
homeassistant  | 2025-01-17 16:06:17.673 WARNING (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Data received is not a message: `*#4*#5*14*#0230*1##`
homeassistant  | 2025-01-17 16:06:17.913 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*6*#14*0230*1##`
homeassistant  | 2025-01-17 16:06:17.913 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Received heating command, sending query to zone 6
homeassistant  | 2025-01-17 16:06:17.914 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*6##` was successfully queued.
homeassistant  | 2025-01-17 16:06:17.914 DEBUG (MainThread) [custom_components.myhome] MH202 Gateway (192.168.1.40) Message `*#4*6##` was successfully unqueued by worker 0.
homeassistant  | 2025-01-17 16:06:17.914 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*6##` received response `*4*1*4##`.
homeassistant  | 2025-01-17 16:06:17.914 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*6##` received second response `*#4*4*13*00##`.
homeassistant  | 2025-01-17 16:06:17.992 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*6*14*0230##`
homeassistant  | 2025-01-17 16:06:17.992 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 6's target temperature is set to 23.0°C.
homeassistant  | 2025-01-17 16:06:17.995 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*6*12*0230*3##`
homeassistant  | 2025-01-17 16:06:17.995 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 6's local target temperature is set to 23.0°C.
homeassistant  | 2025-01-17 16:06:17.998 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*4*1*6##`
homeassistant  | 2025-01-17 16:06:17.998 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 6's mode is set to 'heat'.
homeassistant  | 2025-01-17 16:06:17.999 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*6*13*00##`
homeassistant  | 2025-01-17 16:06:17.999 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 6's local offset is set to 0°C.
homeassistant  | 2025-01-17 16:06:18.019 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*6*0*0230##`
homeassistant  | 2025-01-17 16:06:18.019 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 6's main sensor is reporting a temperature of 23.0°C.
homeassistant  | 2025-01-17 16:06:18.061 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*6*0*0230##`
homeassistant  | 2025-01-17 16:06:18.061 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 6's main sensor is reporting a temperature of 23.0°C.
homeassistant  | 2025-01-17 16:06:18.212 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*4*110*#6##`
homeassistant  | 2025-01-17 16:06:18.213 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 6's mode is set to 'heat'.
homeassistant  | 2025-01-17 16:06:18.216 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*#6*14*#0230*1##`
homeassistant  | 2025-01-17 16:06:18.217 WARNING (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Data received is not a message: `*#4*#6*14*#0230*1##`
homeassistant  | 2025-01-17 16:06:18.438 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*7*#14*0265*1##`
homeassistant  | 2025-01-17 16:06:18.438 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Received heating command, sending query to zone 7
homeassistant  | 2025-01-17 16:06:18.438 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*7##` was successfully queued.
homeassistant  | 2025-01-17 16:06:18.438 DEBUG (MainThread) [custom_components.myhome] MH202 Gateway (192.168.1.40) Message `*#4*7##` was successfully unqueued by worker 0.
homeassistant  | 2025-01-17 16:06:18.439 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*7##` received response `*#4*4*0*0208##`.
homeassistant  | 2025-01-17 16:06:18.439 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*7##` received second response `*#*1##`.
homeassistant  | 2025-01-17 16:06:18.440 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*7##` was successfully sent.
homeassistant  | 2025-01-17 16:06:18.510 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*7*14*0265##`
homeassistant  | 2025-01-17 16:06:18.510 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 7's target temperature is set to 26.5°C.
homeassistant  | 2025-01-17 16:06:18.515 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*7*12*0265*3##`
homeassistant  | 2025-01-17 16:06:18.515 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 7's local target temperature is set to 26.5°C.
homeassistant  | 2025-01-17 16:06:18.532 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*4*1*7##`
homeassistant  | 2025-01-17 16:06:18.532 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 7's mode is set to 'heat'.
homeassistant  | 2025-01-17 16:06:18.547 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*7*13*00##`
homeassistant  | 2025-01-17 16:06:18.547 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 7's local offset is set to 0°C.
homeassistant  | 2025-01-17 16:06:18.550 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*7*0*0240##`
homeassistant  | 2025-01-17 16:06:18.550 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 7's main sensor is reporting a temperature of 24.0°C.
homeassistant  | 2025-01-17 16:06:18.579 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*7*0*0240##`
homeassistant  | 2025-01-17 16:06:18.579 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 7's main sensor is reporting a temperature of 24.0°C.
homeassistant  | 2025-01-17 16:06:18.724 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*4*110*#7##`
homeassistant  | 2025-01-17 16:06:18.725 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Zone 7's mode is set to 'heat'.
homeassistant  | 2025-01-17 16:06:18.730 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*#7*14*#0265*1##`
homeassistant  | 2025-01-17 16:06:18.730 WARNING (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Data received is not a message: `*#4*#7*14*#0265*1##`
homeassistant  | 2025-01-17 16:06:18.953 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*8*#14*0270*1##`
homeassistant  | 2025-01-17 16:06:18.953 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Received heating command, sending query to zone 8
homeassistant  | 2025-01-17 16:06:18.953 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*8##` was successfully queued.
homeassistant  | 2025-01-17 16:06:18.954 DEBUG (MainThread) [custom_components.myhome] MH202 Gateway (192.168.1.40) Message `*#4*8##` was successfully unqueued by worker 0.
homeassistant  | 2025-01-17 16:06:18.956 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*8##` received response `*#4*5*14*0230##`.
homeassistant  | 2025-01-17 16:06:18.957 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message `*#4*8##` received second response `*#4*5*12*0230*3##`.
homeassistant  | 2025-01-17 16:06:19.029 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*8*14*0270##`
homeassistant  | 2025-01-17 16:06:19.034 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*8*12*0270*3##`
homeassistant  | 2025-01-17 16:06:19.039 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*4*1*8##`
homeassistant  | 2025-01-17 16:06:19.044 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*8*13*00##`
homeassistant  | 2025-01-17 16:06:19.063 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*8*0*0264##`
homeassistant  | 2025-01-17 16:06:19.104 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*8*0*0264##`
homeassistant  | 2025-01-17 16:06:19.246 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*4*110*#8##`
homeassistant  | 2025-01-17 16:06:19.249 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#4*#8*14*#0270*1##`
homeassistant  | 2025-01-17 16:06:19.250 WARNING (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Data received is not a message: `*#4*#8*14*#0270*1##`
homeassistant  | 2025-01-17 16:06:49.016 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#13**22*17*05*32*000*05*17*01*2025##`
homeassistant  | 2025-01-17 16:06:49.016 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Gateway's internal datetime is: 2025-01-17 17:05:32+00:00.
homeassistant  | 2025-01-17 16:07:18.079 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#13**22*17*06*01*000*05*17*01*2025##`
homeassistant  | 2025-01-17 16:07:18.079 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Gateway's internal datetime is: 2025-01-17 17:06:01+00:00.
homeassistant  | 2025-01-17 16:07:48.134 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#13**22*17*06*31*000*05*17*01*2025##`
homeassistant  | 2025-01-17 16:07:48.134 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Gateway's internal datetime is: 2025-01-17 17:06:31+00:00.
homeassistant  | 2025-01-17 16:08:18.191 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#13**22*17*07*01*000*05*17*01*2025##`
homeassistant  | 2025-01-17 16:08:18.191 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Gateway's internal datetime is: 2025-01-17 17:07:01+00:00.
homeassistant  | 2025-01-17 16:08:48.252 DEBUG (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Message received: `*#13**22*17*07*31*000*05*17*01*2025##`
homeassistant  | 2025-01-17 16:08:48.252 INFO (MainThread) [custom_components.myhome] [MH202 gateway - 192.168.1.40] Gateway's internal datetime is: 2025-01-17 17:07:31+00:00.

See how messages that query heat zones *#4*3## get multiple responses (none of which is ACK or NACK) ? The OWNd is not handling this well. It will read 2 replies until separator, then just stop. Then the main loop takes over.

But check the log for Zone 3 and Zone 4. For whatever reason zone 4 probe command *#4*4## gets the ACK back as a 2nd reply. Then follow replies for main sensor temp, target tem, local temp, mode, ... and so on.

Whereas zone 3 got as the 2nd reply *#4*3*13*00## instead of ACK -> this is th emessage about main sensor temp. So this is "consumed" and never processed by main loop.

So not sure if this is related to our issue, but certainly the SEND function needs to be modified to support more than one reply from gateway for WHO=4. Or actually -> to not expect any reply, as the sensor updates are handled by the main loop, should not be handled here at all

[gdluck]

*#4*3*13*00## -> 13 means "device answer its ID"

Maybe this helps you -> open_type = 1 means you make the request and 0 = server responds

[N-Soares]

I'm not totally familiarized on how the OWNd manages the different WHO, but one way to go may be to manage the different WHO messages in different buffers, because it seems like the behavior is not the same.

There are some strange behaviour on SCS, for example, i have a installation where 3 actuators are constantly sending their status unprompted, not sure why.