tobof / openhab-addons

The next-generation open Home Automation Bus (openHAB)
Eclipse Public License 2.0
39 stars 30 forks source link

Binding doesn't always send (RGBW) updates to the node(s) #89

Open OliverHi opened 7 years ago

OliverHi commented 7 years ago

I am running openhab 2.1.0 and the version 2.2.0.201707241115 of the MySensors binding on a raspberry pi.

When trying to change values of my RGBW node the updates don't always get send to the node. I have enabled debug logging for the mysensors Binding so normal output looks something like this:

Sending to MySensors: 4;1;1;1;41;1d00ff00
12:23:00.513 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;255;3;0;9;663394 Nonce requested from 4. Waiting...
12:23:00.525 [INFO ] [marthome.event.ItemStateChangedEvent] - LichtKuecheUntenColor changed from 300,100,100 to 246.82355,100.0,100.0
// ... + all the signing messages 

I have activated signing for the nodes and requestAck=true for the openhab thing.

Sometimes when I change some settings for the node all I get in the openhab log is

12:32:45.036 [INFO ] [rsAbstractConnection$MySensorsWriter] - ACK received for message: 5;1;1;1;2;1

12:32:45.044 [INFO ] [smarthome.event.ItemCommandEvent    ] - Item 'LichtFensterOn' received command ON
12:32:45.136 [INFO ] [marthome.event.ItemStateChangedEvent] - LichtFensterOn changed from OFF to ON

no indication in either the openhab or the nodes log that any messages actually get send. I don't see any pattern about when this is happening but it seems to mostly occur when I change the state of the node more quickly.

OliverHi commented 7 years ago

I still have the same problem and it happens a lot more than I though earlier. About 40-50% of the time. This time I saw the log output below. As I have the log level set to debug for mysensors it normally shows all the (signing) messages. In this case it seems to have found the node but not send any actual messages.

22:09:18.990 [INFO ] [smarthome.event.ItemCommandEvent    ] - Item 'LichtKuecheObenOn' received command OFF
22:09:19.030 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Node 3 found in gateway
22:09:19.061 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Child 1 found in node 3
22:09:19.083 [INFO ] [rsAbstractConnection$MySensorsWriter] - ACK received for message: 3;1;1;1;2;0

22:09:19.145 [INFO ] [marthome.event.ItemStateChangedEvent] - LichtKuecheObenOn changed from ON to OFF

If there is any way I can help finding the error just tell me. It is kind of annoying when trying to use openhab + mysensors ;)

tobof commented 6 years ago

1) This only happens on RGBW nodes? 2) If you disble the request for ACK does the error remain? 3) The second log shows that a ACK was received from the node, indicating that the node has received the message OFF. Did LichtKuecheObenOn (the hardware) changed to off? Or was there no reaction at all?

OliverHi commented 6 years ago
  1. This happens only on RGBW nodes for now because those are the only MySensor actuators I own. The rest of them are just sensors that seem to work just fine (no ACK enabled).
  2. I just tried it and this really seems to help. I disabled the ACK on all rgbw things and now its working 95% of the time. The rest seem to be transmission errors where one of the many messages for signing gets lost. That is why I wanted ACK, to make sure all messages get to their nodes. In all cases I now see messages being send/received.
  3. No. In these cases no messages reached the node at all and I did not see any logs on the openhab side that indicate that any messages have been send. In normal/working cases I see lots of [rsAbstractConnection$MySensorsReader] - Message from gateway received: ... messages, in the error cases there are none at all. Only the MySensorsWriter message from the above log and an ItemStateChangedEvent