Why is this light turning on?

Nope… and that may be because I have “Disable MQTT Gateway” selected.

If I enable it, I do in fact see those settings, auth, etc., but after setting up a test username/password and saving, I’m unable to connect:

EDIT: …but I’m wondering, if I’ve run with the MQTT Gateway disabled all this time… is the plugin even using MQTT? That is, are there any topics even being sent via MQTT if that’s off?

Ah, ok - in that case then yes, you may not be using MQTT at all. I have no experience of using the zwave integrations in that state, unfortunately.

It would still be worth having a look at your zwave log as it should show the commands being sent via zwave, but unfortunately I don’t know where to find the log with this integration.

I can look at the Zwave log. The node in question is 89. I turned it off, and luckily/unluckily, it turned off again within two minutes. Here’s the log (with a space where the log scrolled and I couldn’t capture it all via copy/paste)… asterisks added by me:

**2021-06-16 17:56:40.134 INFO ZWAVE: Node 89: value updated: 38-0-currentValue 99 => 0**
**2021-06-16 17:56:45.244 INFO ZWAVE: Node 89: value updated: 38-0-currentValue 0 => 0**

2021-06-16 17:57:09.939 INFO ZWAVE: Node 52: value updated: 112-0-8-255 0 => 0
2021-06-16 17:57:09.941 INFO ZWAVE: Node 52: value updated: 112-0-8-65280 10 => 10
2021-06-16 17:57:09.943 INFO ZWAVE: Node 52: value updated: 112-0-8-16711680 -1 => -1
2021-06-16 17:57:09.945 INFO ZWAVE: Node 52: value updated: 112-0-8-2130706432 0 => 0
2021-06-16 17:57:10.037 INFO ZWAVE: Node 77: value updated: 112-0-24-2130706432 0 => 0
2021-06-16 17:57:10.039 INFO ZWAVE: Node 77: value updated: 112-0-24-16711680 255 => 255
2021-06-16 17:57:10.041 INFO ZWAVE: Node 77: value updated: 112-0-24-65280 10 => 10
2021-06-16 17:57:10.043 INFO ZWAVE: Node 77: value updated: 112-0-24-255 0 => 0
2021-06-16 17:57:10.195 INFO ZWAVE: Node 49: value updated: 112-0-24-2130706432 0 => 0
2021-06-16 17:57:10.197 INFO ZWAVE: Node 49: value updated: 112-0-24-16711680 255 => 255
2021-06-16 17:57:10.199 INFO ZWAVE: Node 49: value updated: 112-0-24-65280 10 => 10
2021-06-16 17:57:10.201 INFO ZWAVE: Node 49: value updated: 112-0-24-255 0 => 0
2021-06-16 17:57:10.398 INFO ZWAVE: Node 61: value updated: 112-0-16-255 0 => 0
2021-06-16 17:57:10.400 INFO ZWAVE: Node 61: value updated: 112-0-16-65280 10 => 10
2021-06-16 17:57:10.401 INFO ZWAVE: Node 61: value updated: 112-0-16-16711680 -1 => -1
2021-06-16 17:57:10.403 INFO ZWAVE: Node 61: value updated: 112-0-16-2130706432 0 => 0
2021-06-16 17:57:10.621 INFO ZWAVE: Node 64: value updated: 112-0-16-255 0 => 0
2021-06-16 17:57:10.623 INFO ZWAVE: Node 64: value updated: 112-0-16-65280 10 => 10
2021-06-16 17:57:10.624 INFO ZWAVE: Node 64: value updated: 112-0-16-16711680 -1 => -1
2021-06-16 17:57:10.625 INFO ZWAVE: Node 64: value updated: 112-0-16-2130706432 0 => 0
2021-06-16 17:57:10.849 INFO ZWAVE: Node 69: value updated: 112-0-16-255 0 => 0
2021-06-16 17:57:10.850 INFO ZWAVE: Node 69: value updated: 112-0-16-65280 10 => 10
2021-06-16 17:57:10.852 INFO ZWAVE: Node 69: value updated: 112-0-16-16711680 -1 => -1
2021-06-16 17:57:10.853 INFO ZWAVE: Node 69: value updated: 112-0-16-2130706432 0 => 0
2021-06-16 17:57:11.046 INFO ZWAVE: Node 70: value updated: 112-0-16-255 0 => 0
2021-06-16 17:57:11.047 INFO ZWAVE: Node 70: value updated: 112-0-16-65280 10 => 10
2021-06-16 17:57:11.048 INFO ZWAVE: Node 70: value updated: 112-0-16-16711680 -1 => -1
2021-06-16 17:57:11.049 INFO ZWAVE: Node 70: value updated: 112-0-16-2130706432 0 => 0
2021-06-16 17:57:11.298 INFO ZWAVE: Node 85: value updated: 112-0-16-255 0 => 0
2021-06-16 17:57:11.299 INFO ZWAVE: Node 85: value updated: 112-0-16-65280 10 => 10
2021-06-16 17:57:11.300 INFO ZWAVE: Node 85: value updated: 112-0-16-16711680 -1 => -1
2021-06-16 17:57:11.301 INFO ZWAVE: Node 85: value updated: 112-0-16-2130706432 0 => 0
2021-06-16 17:57:11.405 INFO ZWAVE: Node 77: value updated: 112-0-25-2130706432 0 => 0
2021-06-16 17:57:11.406 INFO ZWAVE: Node 77: value updated: 112-0-25-16711680 255 => 255
2021-06-16 17:57:11.407 INFO ZWAVE: Node 77: value updated: 112-0-25-65280 10 => 10
2021-06-16 17:57:11.407 INFO ZWAVE: Node 77: value updated: 112-0-25-255 0 => 0
2021-06-16 17:57:11.559 INFO ZWAVE: Node 49: value updated: 112-0-25-2130706432 0 => 0
2021-06-16 17:57:11.560 INFO ZWAVE: Node 49: value updated: 112-0-25-16711680 255 => 255
2021-06-16 17:57:11.561 INFO ZWAVE: Node 49: value updated: 112-0-25-65280 10 => 10
2021-06-16 17:57:11.562 INFO ZWAVE: Node 49: value updated: 112-0-25-255 0 => 0
2021-06-16 17:57:11.794 INFO ZWAVE: Node 67: value updated: 112-0-16-255 0 => 0
2021-06-16 17:57:11.796 INFO ZWAVE: Node 67: value updated: 112-0-16-65280 10 => 10
2021-06-16 17:57:11.798 INFO ZWAVE: Node 67: value updated: 112-0-16-16711680 -1 => -1
2021-06-16 17:57:11.799 INFO ZWAVE: Node 67: value updated: 112-0-16-2130706432 1 => 1
2021-06-16 17:57:11.986 INFO ZWAVE: Node 50: value updated: 112-0-8-255 0 => 0
2021-06-16 17:57:11.988 INFO ZWAVE: Node 50: value updated: 112-0-8-65280 10 => 10
2021-06-16 17:57:11.989 INFO ZWAVE: Node 50: value updated: 112-0-8-16711680 -1 => -1
2021-06-16 17:57:11.990 INFO ZWAVE: Node 50: value updated: 112-0-8-2130706432 1 => 1
2021-06-16 17:57:13.710 INFO ZWAVE: Node 84: value updated: 64-0-mode 0 => 0
2021-06-16 17:57:18.877 INFO APP: GET /health/zwave 200 1.503 ms - 1875
2021-06-16 17:58:09.928 INFO ZWAVE: Node 52: value updated: 112-0-8-255 0 => 0
2021-06-16 17:58:09.930 INFO ZWAVE: Node 52: value updated: 112-0-8-65280 10 => 10
2021-06-16 17:58:09.932 INFO ZWAVE: Node 52: value updated: 112-0-8-16711680 -1 => -1
2021-06-16 17:58:09.934 INFO ZWAVE: Node 52: value updated: 112-0-8-2130706432 0 => 0
2021-06-16 17:58:10.025 INFO ZWAVE: Node 77: value updated: 112-0-24-2130706432 0 => 0
2021-06-16 17:58:10.027 INFO ZWAVE: Node 77: value updated: 112-0-24-16711680 255 => 255
2021-06-16 17:58:10.028 INFO ZWAVE: Node 77: value updated: 112-0-24-65280 10 => 10
2021-06-16 17:58:10.029 INFO ZWAVE: Node 77: value updated: 112-0-24-255 0 => 0
2021-06-16 17:58:10.184 INFO ZWAVE: Node 49: value updated: 112-0-24-2130706432 0 => 0
2021-06-16 17:58:10.185 INFO ZWAVE: Node 49: value updated: 112-0-24-16711680 255 => 255
2021-06-16 17:58:10.186 INFO ZWAVE: Node 49: value updated: 112-0-24-65280 10 => 10
2021-06-16 17:58:10.187 INFO ZWAVE: Node 49: value updated: 112-0-24-255 0 => 0
2021-06-16 17:58:10.388 INFO ZWAVE: Node 61: value updated: 112-0-16-255 0 => 0
2021-06-16 17:58:10.389 INFO ZWAVE: Node 61: value updated: 112-0-16-65280 10 => 10
2021-06-16 17:58:10.390 INFO ZWAVE: Node 61: value updated: 112-0-16-16711680 -1 => -1
2021-06-16 17:58:10.391 INFO ZWAVE: Node 61: value updated: 112-0-16-2130706432 0 => 0
2021-06-16 17:58:10.607 INFO ZWAVE: Node 64: value updated: 112-0-16-255 0 => 0
2021-06-16 17:58:10.609 INFO ZWAVE: Node 64: value updated: 112-0-16-65280 10 => 10
2021-06-16 17:58:10.610 INFO ZWAVE: Node 64: value updated: 112-0-16-16711680 -1 => -1
2021-06-16 17:58:10.612 INFO ZWAVE: Node 64: value updated: 112-0-16-2130706432 0 => 0
2021-06-16 17:58:10.838 INFO ZWAVE: Node 69: value updated: 112-0-16-255 0 => 0
2021-06-16 17:58:10.840 INFO ZWAVE: Node 69: value updated: 112-0-16-65280 10 => 10
2021-06-16 17:58:10.841 INFO ZWAVE: Node 69: value updated: 112-0-16-16711680 -1 => -1
2021-06-16 17:58:10.843 INFO ZWAVE: Node 69: value updated: 112-0-16-2130706432 0 => 0
2021-06-16 17:58:11.036 INFO ZWAVE: Node 70: value updated: 112-0-16-255 0 => 0
2021-06-16 17:58:11.037 INFO ZWAVE: Node 70: value updated: 112-0-16-65280 10 => 10
2021-06-16 17:58:11.038 INFO ZWAVE: Node 70: value updated: 112-0-16-16711680 -1 => -1
2021-06-16 17:58:11.039 INFO ZWAVE: Node 70: value updated: 112-0-16-2130706432 0 => 0
2021-06-16 17:58:11.286 INFO ZWAVE: Node 85: value updated: 112-0-16-255 0 => 0
2021-06-16 17:58:11.288 INFO ZWAVE: Node 85: value updated: 112-0-16-65280 10 => 10
2021-06-16 17:58:11.289 INFO ZWAVE: Node 85: value updated: 112-0-16-16711680 -1 => -1
2021-06-16 17:58:11.290 INFO ZWAVE: Node 85: value updated: 112-0-16-2130706432 0 => 0
2021-06-16 17:58:11.384 INFO ZWAVE: Node 77: value updated: 112-0-25-2130706432 0 => 0
2021-06-16 17:58:11.385 INFO ZWAVE: Node 77: value updated: 112-0-25-16711680 255 => 255
2021-06-16 17:58:11.386 INFO ZWAVE: Node 77: value updated: 112-0-25-65280 10 => 10
2021-06-16 17:58:11.387 INFO ZWAVE: Node 77: value updated: 112-0-25-255 0 => 0
2021-06-16 17:58:11.538 INFO ZWAVE: Node 49: value updated: 112-0-25-2130706432 0 => 0
2021-06-16 17:58:11.540 INFO ZWAVE: Node 49: value updated: 112-0-25-16711680 255 => 255
2021-06-16 17:58:11.540 INFO ZWAVE: Node 49: value updated: 112-0-25-65280 10 => 10
2021-06-16 17:58:11.541 INFO ZWAVE: Node 49: value updated: 112-0-25-255 0 => 0
2021-06-16 17:58:11.771 INFO ZWAVE: Node 67: value updated: 112-0-16-255 0 => 0
2021-06-16 17:58:11.772 INFO ZWAVE: Node 67: value updated: 112-0-16-65280 10 => 10
2021-06-16 17:58:11.773 INFO ZWAVE: Node 67: value updated: 112-0-16-16711680 -1 => -1
2021-06-16 17:58:11.774 INFO ZWAVE: Node 67: value updated: 112-0-16-2130706432 1 => 1
2021-06-16 17:58:11.966 INFO ZWAVE: Node 50: value updated: 112-0-8-255 0 => 0
2021-06-16 17:58:11.967 INFO ZWAVE: Node 50: value updated: 112-0-8-65280 10 => 10
2021-06-16 17:58:11.967 INFO ZWAVE: Node 50: value updated: 112-0-8-16711680 -1 => -1
2021-06-16 17:58:11.968 INFO ZWAVE: Node 50: value updated: 112-0-8-2130706432 1 => 1
2021-06-16 17:58:13.702 INFO ZWAVE: Node 84: value updated: 64-0-mode 0 => 0
**2021-06-16 17:58:28.713 INFO ZWAVE: Node 89: value updated: 38-0-currentValue 0 => 99**

EDIT: I keep looking, and there doesn’t appear to be any activity on node 89 when the light is already on.

Did you ever confirm that the node is not associated with any other device, as suggested in post #2? I would check that just to be sure, maybe something got associated spontaneously. It has happened in the past with OZW, but I haven’t heard anything in regards to zwave-js. You would go to the groups tab of each node and verify that node 89 is not listed there.

An alternative would be to remove the device and add it again. Any potential associations targeting that node would be invalid as the device would have a new node ID.

If that doesn’t work, you could try excluding it and then factory resetting it, then adding it again.

Another thing to try to further debug would be to turn on zwave-js driver debug logging. If there is a MultilevelSwitch Set showing up in the logs at that time, then you know you have a rogue automation somewhere.

If none of those show any results, I’d start to suspect the device itself.

OK, I had logging enabled, but not to the “silly” level. I’ve done that now, and then dig into it to see what I see.

For a handful of your comments, I direct you to post #16 above… where I moved that module and added a new one with the same name, and the behavior switched to the new module! However, I’m pretty certain I left the old module off, and just found it on… so, I’ve turned it off and will keep watching. I properly added both of those modules by excluding first. At any rate, that should rule out inclusion/exclusion or a device issue unless it’s an issue with the entire model line.

I checked associations for each node, and none have either node 88 or 89. The only two associations that show up in any node are these two (mostly just the Group 1 USB hub):

OK… according to the HA history, the light turned itself on at 11:09:35 am today after being off for almost 30 minutes. Here’s the first instance of Node 89 in the ZwaveJS log for that approximate time:

2021-06-17T15:09:16.351Z DRIVER « [Node 085] [REQ] [ApplicationCommand]
                                  └─[ConfigurationCCReport]
                                      parameter #: 16
                                      value size:  4
                                      value:       16714240
2021-06-17T15:09:16.355Z SERIAL » 0x010a00134d03700519257c9d                                          (12 bytes)
2021-06-17T15:09:16.355Z DRIVER » [Node 077] [REQ] [SendData]
                                  │ transmit options: 0x25
                                  │ callback id:      124
                                  └─[ConfigurationCCGet]
                                      parameter #: 25
2021-06-17T15:09:16.358Z SERIAL « [ACK]                                                                   (0x06)
2021-06-17T15:09:16.363Z SERIAL « 0x0104011301e8                                                       (6 bytes)
2021-06-17T15:09:16.363Z SERIAL » [ACK]                                                                   (0x06)
2021-06-17T15:09:16.364Z DRIVER « [RES] [SendData]
                                    was sent: true
2021-06-17T15:09:16.377Z SERIAL « 0x010500137c0095                                                     (7 bytes)
2021-06-17T15:09:16.378Z SERIAL » [ACK]                                                                   (0x06)
2021-06-17T15:09:16.378Z DRIVER « [REQ] [SendData]
                                    callback id:     124
                                    transmit status: OK
2021-06-17T15:09:16.386Z SERIAL « 0x010e0004004d087006190400ff0a002e                                  (16 bytes)
2021-06-17T15:09:16.389Z CNTRLR   [Node 077] [~] [Configuration] 25[2130706432]: 0 => 0
2021-06-17T15:09:16.391Z CNTRLR   [Node 077] [~] [Configuration] 25[16711680]: 255 => 255
2021-06-17T15:09:16.393Z CNTRLR   [Node 077] [~] [Configuration] 25[65280]: 10 => 10
2021-06-17T15:09:16.394Z CNTRLR   [Node 077] [~] [Configuration] 25[255]: 0 => 0
2021-06-17T15:09:16.395Z SERIAL » [ACK]                                                                   (0x06)
2021-06-17T15:09:16.397Z DRIVER « [Node 077] [REQ] [ApplicationCommand]
                                  └─[ConfigurationCCReport]
                                      parameter #: 25
                                      value size:  4
                                      value:       16714240
2021-06-17T15:09:16.400Z SERIAL » 0x010a00133103700519257de0                                          (12 bytes)
2021-06-17T15:09:16.400Z DRIVER » [Node 049] [REQ] [SendData]
                                  │ transmit options: 0x25
                                  │ callback id:      125
                                  └─[ConfigurationCCGet]
                                      parameter #: 25
2021-06-17T15:09:16.403Z SERIAL « [ACK]                                                                   (0x06)
2021-06-17T15:09:16.407Z SERIAL « 0x0104011301e8                                                       (6 bytes)
2021-06-17T15:09:16.407Z SERIAL » [ACK]                                                                   (0x06)
2021-06-17T15:09:16.408Z DRIVER « [RES] [SendData]
                                    was sent: true
2021-06-17T15:09:16.625Z SERIAL « 0x010500137d0094                                                     (7 bytes)
2021-06-17T15:09:16.625Z SERIAL » [ACK]                                                                   (0x06)
2021-06-17T15:09:16.626Z DRIVER « [REQ] [SendData]
                                    callback id:     125
                                    transmit status: OK
2021-06-17T15:09:17.302Z SERIAL « 0x010e00040031087006190400ff0a0052                                  (16 bytes)
2021-06-17T15:09:17.303Z CNTRLR   [Node 049] [~] [Configuration] 25[2130706432]: 0 => 0
2021-06-17T15:09:17.306Z CNTRLR   [Node 049] [~] [Configuration] 25[16711680]: 255 => 255
2021-06-17T15:09:17.307Z CNTRLR   [Node 049] [~] [Configuration] 25[65280]: 10 => 10
2021-06-17T15:09:17.309Z CNTRLR   [Node 049] [~] [Configuration] 25[255]: 0 => 0
2021-06-17T15:09:17.310Z SERIAL » [ACK]                                                                   (0x06)
2021-06-17T15:09:17.312Z DRIVER « [Node 049] [REQ] [ApplicationCommand]
                                  └─[ConfigurationCCReport]
                                      parameter #: 25
                                      value size:  4
                                      value:       16714240
2021-06-17T15:09:18.404Z SERIAL « 0x01100004003b0a32022134000000da000025                              (18 bytes)
2021-06-17T15:09:18.407Z CNTRLR   [Node 059] [~] [Meter] value[66049]: 19.8 => 21.8                 [Endpoint 0]
2021-06-17T15:09:18.418Z SERIAL » [ACK]                                                                   (0x06)
2021-06-17T15:09:18.420Z DRIVER « [Node 059] [REQ] [ApplicationCommand]
                                  └─[MeterCCReport]
                                      type:       Electric
                                      scale:      W
                                      rate type:  Consumed
                                      value:      21.8
                                      time delta: 0 seconds
2021-06-17T15:09:29.047Z SERIAL « 0x01140004004d0e320221640000149600000000030850                      (22 bytes)
2021-06-17T15:09:29.048Z CNTRLR   [Node 077] [~] [Meter] value[65537]: 5.255 => 5.27                [Endpoint 0]
2021-06-17T15:09:29.050Z SERIAL » [ACK]                                                                   (0x06)
2021-06-17T15:09:29.052Z DRIVER « [Node 077] [REQ] [ApplicationCommand]
                                  └─[MeterCCReport]
                                      type:       Electric
                                      scale:      kWh
                                      rate type:  Consumed
                                      value:      5.27
                                      time delta: 0 seconds
2021-06-17T15:09:29.146Z SERIAL « 0x010e0004004d0832022134000000a035                                  (16 bytes)
2021-06-17T15:09:29.147Z CNTRLR   [Node 077] [~] [Meter] value[66049]: 15 => 16                     [Endpoint 0]
2021-06-17T15:09:29.153Z SERIAL » [ACK]                                                                   (0x06)
2021-06-17T15:09:29.155Z DRIVER « [Node 077] [REQ] [ApplicationCommand]
                                  └─[MeterCCReport]
                                      type:       Electric
                                      scale:      W
                                      rate type:  Consumed
                                      value:      16
                                      time delta: 0 seconds
2021-06-17T15:09:34.240Z SERIAL « 0x0115004984590f04110426272b2c857286917773ef82ef                    (23 bytes)
2021-06-17T15:09:34.241Z SERIAL » [ACK]                                                                   (0x06)

**********************************************************************************************
2021-06-17T15:09:34.243Z DRIVER « [Node 089] [REQ] [ApplicationUpdateRequest]
                                    payload: 0x84590f04110426272b2c857286917773ef82
2021-06-17T15:09:34.244Z CNTRLR « [Node 089] Received updated node info
2021-06-17T15:09:35.225Z SERIAL « 0x0108000400590282012b                                              (10 bytes)
2021-06-17T15:09:35.226Z SERIAL » [ACK]                                                                   (0x06)
2021-06-17T15:09:35.227Z DRIVER « [Node 089] [REQ] [ApplicationCommand]
                                  └─[HailCC]
2021-06-17T15:09:35.228Z CNTRLR   [Node 089] Hail received from node, refreshing actuator and sensor values...
2021-06-17T15:09:35.232Z CNTRLR » [Node 089] requesting current switch state...
2021-06-17T15:09:35.235Z SERIAL » 0x0109001359022602257ec1                                            (11 bytes)
2021-06-17T15:09:35.236Z DRIVER » [Node 089] [REQ] [SendData]
                                  │ transmit options: 0x25
                                  │ callback id:      126
                                  └─[MultilevelSwitchCCGet]
2021-06-17T15:09:35.239Z SERIAL « [ACK]                                                                   (0x06)
2021-06-17T15:09:35.243Z SERIAL « 0x0104011301e8                                                       (6 bytes)
2021-06-17T15:09:35.243Z SERIAL » [ACK]                                                                   (0x06)
2021-06-17T15:09:35.244Z DRIVER « [RES] [SendData]
                                    was sent: true
2021-06-17T15:09:35.344Z SERIAL « 0x010500137e0097                                                     (7 bytes)
2021-06-17T15:09:35.344Z SERIAL » [ACK]                                                                   (0x06)
2021-06-17T15:09:35.345Z DRIVER « [REQ] [SendData]
                                    callback id:     126
                                    transmit status: OK
2021-06-17T15:09:35.393Z SERIAL « 0x01090004005903260363ee                                            (11 bytes)
**2021-06-17T15:09:35.395Z CNTRLR   [Node 089] [~] [Multilevel Switch] currentValue: 0 => 99          [Endpoint 0]**
2021-06-17T15:09:35.397Z SERIAL » [ACK]                                                                   (0x06)
2021-06-17T15:09:35.400Z DRIVER « [Node 089] [REQ] [ApplicationCommand]
                                  └─[MultilevelSwitchCCReport]
                                      current value: 99

…so you can see where it turns on (see double asterisks). But why does it turn on?

EDIT: added more logs prior to the Node 089 stuff, and added an asterisk line as a separator.

Perhaps you can post more of the log before the first line?

Certainly… I’ll just edit the above. Thanks for looking.

Are those the complete logs at that time? Seems like something is missing between the ACK and the Node 89 message, where the asterisks are.

Oops, you’re right, I grabbed the wrong instance of “Node 089”. There are a few additional lines, updated above.

EDIT: Node 88, the older dimming module, has been off for several hours now.

Well, these additional logs make more sense than posted originally. At the time the dimmer turns on, there are two relevant messages.

The first message is a Node Information Frame (NIF):

2021-06-17T15:09:34.240Z SERIAL « 0x0115004984590f04110426272b2c857286917773ef82ef                    (23 bytes)
2021-06-17T15:09:34.241Z SERIAL » [ACK]                                                                   (0x06)
2021-06-17T15:09:34.243Z DRIVER « [Node 089] [REQ] [ApplicationUpdateRequest]
                                    payload: 0x84590f04110426272b2c857286917773ef82
2021-06-17T15:09:34.244Z CNTRLR « [Node 089] Received updated node info

The following message is a Hail Command:

2021-06-17T15:09:35.225Z SERIAL « 0x0108000400590282012b                                              (10 bytes)
2021-06-17T15:09:35.226Z SERIAL » [ACK]                                                                   (0x06)
2021-06-17T15:09:35.227Z DRIVER « [Node 089] [REQ] [ApplicationCommand]
                                  └─[HailCC]
2021-06-17T15:09:35.228Z CNTRLR   [Node 089] Hail received from node, refreshing actuator and sensor values...

Either of these messages (or both) are sent by older Z-Wave devices to signal to the controller that there was some change locally to the node, e.g. a physical button press that turned it on or off. It’s a hint that the controller should refresh the values. This was behavior prior to the “Instant Status” that modern Z-Wave devices support. In this case, when the driver (node-zwave-js) receives the Hail command message it refreshes the node’s values. That’s why after the Hail you see the Get:

2021-06-17T15:09:35.232Z CNTRLR » [Node 089] requesting current switch state...
2021-06-17T15:09:35.235Z SERIAL » 0x0109001359022602257ec1                                            (11 bytes)
2021-06-17T15:09:35.236Z DRIVER » [Node 089] [REQ] [SendData]
                                  │ transmit options: 0x25
                                  │ callback id:      126
                                  └─[MultilevelSwitchCCGet]

There is nothing in the logs to indicate any action from the driver (via HA or zwavejs2mqtt) that would turn it on. The device is telling you that it thinks someone/something turned it on physically. Maybe it’s a faulty device then?

Have you tried excluding the device and waiting to see if it turns on when it’s not part of a Z-Wave network? Is it only a problem when included?

Thanks for the analysis… no, I haven’t tried that, and as far as I can tell, yes, it’s only a problem when included. Furthermore…

I started with these two identical dimmer modules, let’s call them DMA and DMB. I included DMA and DMB, and named DMA “Basement Floor Lamp.” DMA started turning on randomly, and so I started this thread. At post #17, I renamed DMA as “module” and then named DMB as “Basement Floor Lamp.” DMB instantly started turning on by itself, and DMA has been staying off since that time (around post 17 in this thread).

I always assumed, then, that it was something HA was doing… but I haven’t been able to pinpoint it. I’ve disabled the only Node-RED flow related to that module, and I’ve also disabled the singular automation that I have with that module referenced. The module still turns on by itself.

I’m reasonably comfortable saying that this is happening because the modules are old and don’t behave predictably, and then just throw them in the trash… but I’d prefer to find out what’s going on and fix it. I can tell you with certainty that the modules aren’t being physically turned on.

EDIT: It might be worth mentioning, maybe, that I had a plug-in relay module of the same vintage (Leviton RF+) and the same entity name in HA plugged into the same location with the same light for at least a month, and it worked fine. I switched to the dimmer module because I wanted to use the relay module elsewhere. Just switched it out and changed names, and this fun began.

Back in post 15 I suggested powering off HA for a while and observing if the light still turned on. Seems like this is still an easy way for you to confirm that HA is not the source of the signal.

Ah, right. You did. I can try it… but the absence of an event is not proof of cause, unfortunately, due to the random nature of this issue. I’ve had the light off for the last half hour and it hasn’t turned on yet. I’d have to leave HA off for a day and, if the light didn’t turn on, still not be sure what’s causing it to turn on. And if it did turn on, it would just lead me to toss these modules out anyway.

Instant status is supposed to be supported with these Leviton RF+ devices, but from what I’m reading, not all hubs support it. I appreciate the input from everyone, but I think this will have to remain an unsolved mystery. So unless anyone has any other ideas, I’ll throw these modules in the trash and get some modern ones.

If HA or other application were directly turning on the switch, you would have seen a Set message in the zwave-js debug logs, something like:

2021-06-24T14:44:52.431Z SERIAL » 0x010f00a90102032601ff25000000004aee                                (17 bytes)
2021-06-24T14:44:52.432Z DRIVER » [Node 002] [REQ] [SendDataBridge]
                                  │ source node id:   1
                                  │ transmit options: 0x25
                                  │ route:            0, 0, 0, 0
                                  │ callback id:      74
                                  └─[MultilevelSwitchCCSet]
                                      target value: 255

Unless you omitted some logs from the post above, there’s no Set command at the time the switch turns on, so HA couldn’t have done it. Do you see that log? A BasicCCSet command would also do it, but HA doesn’t use that.

Aren’t these RF+ devices quite old? They don’t look like they are even Z-Wave Plus, which is usually a good indicator of support of instant status. The fact that it’s sending NIF and Hail messages when turned on would further indicate that. The hub has no involvement, it’s the devices. This is not to excuse the behavior at all, I’m not one to throw out perfectly good devices just because they’re old (hello Jasco switches)! The behavior is baffling though. :thinking:

Last option I could think of, before tossing the devices, would be to use a Zniffer to see if there’s anything else besides the controller on the network telling the device to turn on (e.g. via group associations, even though this is not configured). That may be more work than simply replacing them…

I see what you mean about the Set command.

The Leviton RF+ line is quite old, and the devices are not Z-wave Plus. But their specs indicate they support instant status, which if I recall correctly is why I started buying them to replace all of my Leviton RF (non-plus) devices. I’ve been using Z-wave for awhile.

I think it’s time to retire these.

Ah, now that you mention it, I think Leviton was the manufacturer that held the patent for instant status. :laughing: Other manufacturers were working around that with Hail, until the patent expired.

EDIT: Correction the patent was held by Lutron, but it sounds like Leviton was licensing it. I think your comment about hubs not supporting instant status might be related to that.