Hello everyone,
I have a problem with one of my Z-Wave switches. It’s Zooz Zen26 and what’s going on is when I switch it on in HASS, the toggle flips back to off almost immediately and stays off forever (while the light actually stays on).
Here’s the chunk of the OZW log that seems to be relevant:
2020-05-01 09:28:36.773 Info, Node008, Value::Set - COMMAND_CLASS_SWITCH_BINARY - Switch - 0 - 1 - True
2020-05-01 09:28:36.773 Info, Node008, SwitchBinary::Set - Setting node 8 to On
2020-05-01 09:28:36.773 Detail, Node008, Queuing (Send) SwitchBinaryCmd_Set (Node=8): 0x01, 0x0a, 0x00, 0x13, 0x08, 0x03, 0x25, 0x01, 0xff, 0x25, 0x41, 0x52
2020-05-01 09:28:36.774 Detail, Node008, Queuing (Send) SwitchBinaryCmd_Get (Node=8): 0x01, 0x09, 0x00, 0x13, 0x08, 0x02, 0x25, 0x02, 0x25, 0x42, 0xaf
2020-05-01 09:28:36.774 Detail,
2020-05-01 09:28:36.774 Info, Node008, Sending (Send) message (Callback ID=0x41, Expected Reply=0x13) - SwitchBinaryCmd_Set (Node=8): 0x01, 0x0a, 0x00, 0x13,
0x08, 0x03, 0x25, 0x01, 0xff, 0x25, 0x41, 0x52
2020-05-01 09:28:36.899 Detail, Node008, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2020-05-01 09:28:36.899 Detail, Node008, ZW_SEND_DATA delivered to Z-Wave stack
2020-05-01 09:28:36.943 Detail, Node008, Received: 0x01, 0x07, 0x00, 0x13, 0x41, 0x00, 0x00, 0x11, 0xbb
2020-05-01 09:28:36.943 Detail, Node008, ZW_SEND_DATA Request with callback ID 0x41 received (expected 0x41)
2020-05-01 09:28:36.943 Info, Node008, Request RTT 169 Average Request RTT 121
2020-05-01 09:28:36.943 Detail, Expected callbackId was received
2020-05-01 09:28:36.943 Detail, Expected reply was received
2020-05-01 09:28:36.943 Detail, Message transaction complete
2020-05-01 09:28:36.943 Detail,
2020-05-01 09:28:36.943 Detail, Node008, Removing current message
2020-05-01 09:28:36.943 Detail,
2020-05-01 09:28:36.943 Info, Node008, Sending (Send) message (Callback ID=0x42, Expected Reply=0x04) - SwitchBinaryCmd_Get (Node=8): 0x01, 0x09, 0x00, 0x13, 0x08, 0x02, 0x25, 0x02, 0x25, 0x42, 0xaf
2020-05-01 09:28:36.952 Detail, Node008, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2020-05-01 09:28:36.952 Detail, Node008, ZW_SEND_DATA delivered to Z-Wave stack
2020-05-01 09:28:37.017 Detail, Node008, Received: 0x01, 0x07, 0x00, 0x13, 0x42, 0x00, 0x00, 0x07, 0xae
2020-05-01 09:28:37.017 Detail, Node008, ZW_SEND_DATA Request with callback ID 0x42 received (expected 0x42)
2020-05-01 09:28:37.017 Info, Node008, Request RTT 74 Average Request RTT 97
2020-05-01 09:28:37.017 Detail, Expected callbackId was received
2020-05-01 09:28:37.088 Detail, Node008, Received: 0x01, 0x09, 0x00, 0x04, 0x00, 0x08, 0x03, 0x25, 0x03, 0xff, 0x20
2020-05-01 09:28:37.088 Detail,
2020-05-01 09:28:37.088 Info, Node008, Response RTT 145 Average Response RTT 164
2020-05-01 09:28:37.088 Info, Node008, Received SwitchBinary report from node 8: level=On
2020-05-01 09:28:37.088 Detail, Node008, Refreshed Value: old value=false, new value=true, type=bool
2020-05-01 09:28:37.088 Detail, Node008, Changes to this value are not verified
2020-05-01 09:28:37.088 Detail, Node008, Expected reply and command class was received
2020-05-01 09:28:37.088 Detail, Node008, Message transaction complete
2020-05-01 09:28:37.088 Detail,
2020-05-01 09:28:37.088 Detail, Node008, Removing current message
2020-05-01 09:28:37.088 Detail, Node008, Notification: ValueChanged
2020-05-01 09:28:37.138 Detail, Node008, Received: 0x01, 0x09, 0x00, 0x04, 0x00, 0x08, 0x03, 0x25, 0x03, 0x00, 0xdf
2020-05-01 09:28:37.138 Detail,
2020-05-01 09:28:37.138 Info, Node008, Received SwitchBinary report from node 8: level=Off
2020-05-01 09:28:37.138 Detail, Node008, Refreshed Value: old value=true, new value=false, type=bool
2020-05-01 09:28:37.138 Detail, Node008, Changes to this value are not verified
2020-05-01 09:28:37.138 Detail, Node008, Notification: ValueChanged
From what I can derive from it, there are two reports coming from the switch, the first with level=On and the second with level=Off in a short succession after the first one. Maybe this makes HASS think the switch is off.
Sometimes (rarely though) everything behaves as expected (i.e. the toggle sticks to On), here’s the relevant log as well:
2020-05-01 11:07:05.826 Info, Node008, Value::Set - COMMAND_CLASS_SWITCH_BINARY - Switch - 0 - 1 - True
2020-05-01 11:07:05.827 Info, Node008, SwitchBinary::Set - Setting node 8 to On
2020-05-01 11:07:05.827 Detail, Node008, Queuing (Send) SwitchBinaryCmd_Set (Node=8): 0x01, 0x0a, 0x00, 0x13, 0x08, 0x03, 0x25, 0x01, 0xff, 0x25, 0xa4, 0xb7
2020-05-01 11:07:05.827 Detail, Node008, Queuing (Send) SwitchBinaryCmd_Get (Node=8): 0x01, 0x09, 0x00, 0x13, 0x08, 0x02, 0x25, 0x02, 0x25, 0xa5, 0x48
2020-05-01 11:07:05.827 Detail,
2020-05-01 11:07:05.827 Info, Node008, Sending (Send) message (Callback ID=0xa4, Expected Reply=0x13) - SwitchBinaryCmd_Set (Node=8): 0x01, 0x0a, 0x00, 0x13,
0x08, 0x03, 0x25, 0x01, 0xff, 0x25, 0xa4, 0xb7
2020-05-01 11:07:05.835 Detail, Node008, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2020-05-01 11:07:05.835 Detail, Node008, ZW_SEND_DATA delivered to Z-Wave stack
2020-05-01 11:07:05.878 Detail, Node008, Received: 0x01, 0x07, 0x00, 0x13, 0xa4, 0x00, 0x00, 0x05, 0x4a
2020-05-01 11:07:05.878 Detail, Node008, ZW_SEND_DATA Request with callback ID 0xa4 received (expected 0xa4)
2020-05-01 11:07:05.879 Info, Node008, Request RTT 51 Average Request RTT 205
2020-05-01 11:07:05.879 Detail, Expected callbackId was received
2020-05-01 11:07:05.879 Detail, Expected reply was received
2020-05-01 11:07:05.879 Detail, Message transaction complete
2020-05-01 11:07:05.879 Detail,
2020-05-01 11:07:05.879 Detail, Node008, Removing current message
2020-05-01 11:07:05.879 Detail,
2020-05-01 11:07:05.879 Info, Node008, Sending (Send) message (Callback ID=0xa5, Expected Reply=0x04) - SwitchBinaryCmd_Get (Node=8): 0x01, 0x09, 0x00, 0x13,
0x08, 0x02, 0x25, 0x02, 0x25, 0xa5, 0x48
2020-05-01 11:07:05.888 Detail, Node008, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2020-05-01 11:07:05.888 Detail, Node008, ZW_SEND_DATA delivered to Z-Wave stack
2020-05-01 11:07:06.176 Detail, Node008, Received: 0x01, 0x09, 0x00, 0x04, 0x00, 0x08, 0x03, 0x25, 0x03, 0xff, 0x20
2020-05-01 11:07:06.176 Detail,
2020-05-01 11:07:06.176 Info, Node008, Response RTT 298 Average Response RTT 652
2020-05-01 11:07:06.176 Info, Node008, Received SwitchBinary report from node 8: level=On
2020-05-01 11:07:06.176 Detail, Node008, Refreshed Value: old value=false, new value=true, type=bool
2020-05-01 11:07:06.176 Detail, Node008, Changes to this value are not verified
2020-05-01 11:07:06.176 Detail, Node008, Notification: ValueChanged
2020-05-01 11:07:07.563 Detail, Node008, Received: 0x01, 0x09, 0x00, 0x04, 0x00, 0x08, 0x03, 0x25, 0x03, 0xff, 0x20
2020-05-01 11:07:07.563 Detail,
2020-05-01 11:07:07.563 Info, Node008, Response RTT 1685 Average Response RTT 1168
2020-05-01 11:07:07.563 Info, Node008, Received SwitchBinary report from node 8: level=On
2020-05-01 11:07:07.563 Detail, Node008, Refreshed Value: old value=true, new value=true, type=bool
2020-05-01 11:07:07.563 Detail, Node008, Changes to this value are not verified
2020-05-01 11:07:07.563 Detail, Node008, Notification: ValueChanged
2020-05-01 11:07:07.703 Detail, Node008, Received: 0x01, 0x07, 0x00, 0x13, 0xa5, 0x00, 0x00, 0xb6, 0xf8
2020-05-01 11:07:07.703 Detail, Node008, ZW_SEND_DATA Request with callback ID 0xa5 received (expected 0xa5)
2020-05-01 11:07:07.703 Info, Node008, Request RTT 1825 Average Request RTT 1015
2020-05-01 11:07:07.703 Detail, Expected callbackId was received
2020-05-01 11:07:07.822 Detail, Node008, Received: 0x01, 0x09, 0x00, 0x04, 0x00, 0x08, 0x03, 0x25, 0x03, 0xff, 0x20
2020-05-01 11:07:07.822 Detail,
2020-05-01 11:07:07.822 Info, Node008, Response RTT 1944 Average Response RTT 1556
2020-05-01 11:07:07.822 Info, Node008, Received SwitchBinary report from node 8: level=On
2020-05-01 11:07:07.822 Detail, Node008, Refreshed Value: old value=true, new value=true, type=bool
2020-05-01 11:07:07.822 Detail, Node008, Changes to this value are not verified
2020-05-01 11:07:07.822 Detail, Node008, Expected reply and command class was received
2020-05-01 11:07:07.822 Detail, Node008, Message transaction complete
2020-05-01 11:07:07.822 Detail,
2020-05-01 11:07:07.823 Detail, Node008, Removing current message
2020-05-01 11:07:07.823 Detail, Node008, Notification: ValueChanged
2020-05-01 11:07:07.898 Detail, Node008, Received: 0x01, 0x09, 0x00, 0x04, 0x00, 0x08, 0x03, 0x25, 0x03, 0xff, 0x20
2020-05-01 11:07:07.898 Detail,
2020-05-01 11:07:07.898 Info, Node008, Received SwitchBinary report from node 8: level=On
2020-05-01 11:07:07.898 Detail, Node008, Refreshed Value: old value=true, new value=true, type=bool
2020-05-01 11:07:07.898 Detail, Node008, Changes to this value are not verified
2020-05-01 11:07:07.898 Detail, Node008, Notification: ValueChanged
Here I can see 4 reports (why though?), all with level=On.
None of my other Z-Wave switches show such behavior. This one is the farthest from the hub though. Here’s my network topology:
The problematic node is the one at the bottom. RTT fluctuates wildly between 200 and 1800 ms. Could high RTT be a probable root cause? If so, is there anything (configuration-wise) that can be done to compensate it?