Need help debugging why my dimmer device will not respond to changes from homeassistant

Hi,
I have a z-wave wall dimmer ZDB5400 that is not working right. I can turn on and off or dim the light locally with the buttons on the dimmer, but when I try to turn it on or off or dim it from homeassistant, nothing happens. Communication seems to be ok both because I get updates in homeassistant for current state on/off and dim level when I dim using the buttons on the device and because I can make configuration changes from the z-wave js 2 mqtt ui that take effect immediately.

In an attempt to troubleshoot, I turned on logging and this is a part of the log for when changing the dimmer from homeassistant.

2022-09-13T09:20:00.686Z CNTRLR   [Node 013] [setValue] calling SET_VALUE API MultilevelSwitchCCAPI:
                                    property:     targetValue
                                    property key: undefined
                                    optimistic:   true
2022-09-13T09:20:00.703Z SERIAL » 0x011800a9010d0c600d00056c01a004260132ff25000000001535              (26 bytes)
2022-09-13T09:20:00.705Z DRIVER » [Node 013] [REQ] [SendDataBridge]
                                  │ source node id:   1
                                  │ transmit options: 0x25
                                  │ callback id:      21
                                  └─[MultiChannelCCCommandEncapsulation]
                                    │ source:      0
                                    │ destination: 5
                                    └─[SupervisionCCGet]
                                      │ session id:      32
                                      │ request updates: true
                                      └─[MultilevelSwitchCCSet]
                                          target value: 50
                                          duration:     default
2022-09-13T09:20:00.711Z SERIAL « [ACK]                                                                   (0x06)
2022-09-13T09:20:00.713Z SERIAL « 0x010401a90152                                                       (6 bytes)
2022-09-13T09:20:00.715Z SERIAL » [ACK]                                                                   (0x06)
2022-09-13T09:20:00.716Z DRIVER « [RES] [SendDataBridge]
                                    was sent: true
2022-09-13T09:20:00.865Z SERIAL « 0x011d00a91500000e01a07f7f7f7f02010309000000010100007f7f7f7f7f87    (31 bytes)
2022-09-13T09:20:00.866Z SERIAL » [ACK]                                                                   (0x06)
2022-09-13T09:20:00.867Z DRIVER « [REQ] [SendDataBridge]
                                    callback id:            21
                                    transmit status:        OK, took 140 ms
                                    repeater node IDs:      9
                                    routing attempts:       1
                                    protocol & route speed: Z-Wave, 9.6 kbit/s
                                    ACK RSSI:               -96 dBm
                                    ACK RSSI on repeaters:  N/A
                                    ACK channel no.:        2
                                    TX channel no.:         1
2022-09-13T09:20:02.050Z CNTRLR   [Node 013] Timed out while waiting for a response from the node (ZW0201)
2022-09-13T09:20:02.052Z CNTRLR   [Node 013] [translateValueEvent: value updated]
                                    commandClass: Multilevel Switch
                                    endpoint:     5
                                    property:     currentValue
                                    propertyKey:  undefined
                                    internal:     false
                                    secret:       false
                                    event source: undefined
2022-09-13T09:20:02.052Z CNTRLR   [Node 013] [~] [Multilevel Switch] currentValue: 99 => 50         [Endpoint 5]
2022-09-13T09:20:02.053Z CNTRLR   [Node 013] [translateValueEvent: value updated]
                                    is root endpoint:        false
                                    is application CC:       true
                                    should hide root values: true
2022-09-13T09:20:02.055Z CNTRLR   [Node 013] [setValue] result of SET_VALUE API call for MultilevelSwitchCCAPI: 
                                  undefined
2022-09-13T09:20:02.056Z CNTRLR   [Node 013] [setValue] updating value with event
2022-09-13T09:20:02.056Z CNTRLR   [Node 013] [translateValueEvent: value updated]
                                    commandClass: Multilevel Switch
                                    endpoint:     5
                                    property:     targetValue
                                    propertyKey:  undefined
                                    internal:     false
                                    secret:       false
                                    event source: driver
2022-09-13T09:20:02.057Z CNTRLR   [Node 013] [translateValueEvent: value updated]
                                    is root endpoint:        false
                                    is application CC:       true
                                    should hide root values: true
2022-09-13T09:20:07.064Z SERIAL » 0x011200a9010d06600d0005260225000000001631                          (20 bytes)
2022-09-13T09:20:07.065Z DRIVER » [Node 013] [REQ] [SendDataBridge]
                                  │ source node id:   1
                                  │ transmit options: 0x25
                                  │ callback id:      22
                                  └─[MultiChannelCCCommandEncapsulation]
                                    │ source:      0
                                    │ destination: 5
                                    └─[MultilevelSwitchCCGet]
2022-09-13T09:20:07.074Z SERIAL « [ACK]                                                                   (0x06)
2022-09-13T09:20:07.077Z SERIAL « 0x010401a90152                                                       (6 bytes)
2022-09-13T09:20:07.078Z SERIAL » [ACK]                                                                   (0x06)
2022-09-13T09:20:07.079Z DRIVER « [RES] [SendDataBridge]
                                    was sent: true
2022-09-13T09:20:07.215Z SERIAL « 0x011d00a91600000d01a07f7f7f7f02010309000000010100007f7f7f7f7f87    (31 bytes)
2022-09-13T09:20:07.216Z SERIAL » [ACK]                                                                   (0x06)
2022-09-13T09:20:07.217Z DRIVER « [REQ] [SendDataBridge]
                                    callback id:            22
                                    transmit status:        OK, took 130 ms
                                    repeater node IDs:      9
                                    routing attempts:       1
                                    protocol & route speed: Z-Wave, 9.6 kbit/s
                                    ACK RSSI:               -96 dBm
                                    ACK RSSI on repeaters:  N/A
                                    ACK channel no.:        2
                                    TX channel no.:         1
2022-09-13T09:20:08.383Z CNTRLR   [Node 013] Timed out while waiting for a response from the node (ZW0201)

When I instead go for changing a configuration parameter, things look ok:

2022-09-13T09:25:02.939Z CNTRLR   [Node 013] [setValue] calling SET_VALUE API ConfigurationCCAPI:
                                    property:     26
                                    property key: 16711680
                                    optimistic:   true
2022-09-13T09:25:03.125Z SERIAL » 0x012400a9010d189f033e00d2b616c65d2c061faa5c3ee4a54aeee2a6d21c37250 (38 bytes)
                                  000000019b4
2022-09-13T09:25:03.127Z DRIVER » [Node 013] [REQ] [SendDataBridge]
                                  │ source node id:   1
                                  │ transmit options: 0x25
                                  │ callback id:      25
                                  └─[Security2CCMessageEncapsulation]
                                    │ sequence number: 62
                                    └─[SupervisionCCGet]
                                      │ session id:      34
                                      │ request updates: true
                                      └─[ConfigurationCCSet]
                                          parameter #:      26
                                          reset to default: false
                                          value size:       4
                                          value format:     UnsignedInteger
                                          value:            17124096
2022-09-13T09:25:03.136Z SERIAL « [ACK]                                                                   (0x06)
2022-09-13T09:25:03.138Z SERIAL « 0x010401a90152                                                       (6 bytes)
2022-09-13T09:25:03.140Z SERIAL » [ACK]                                                                   (0x06)
2022-09-13T09:25:03.142Z DRIVER « [RES] [SendDataBridge]
                                    was sent: true
2022-09-13T09:25:03.336Z SERIAL « 0x011d00a91900001301a17f7f7f7f02010309000000010100007f7f7f7f7f97    (31 bytes)
2022-09-13T09:25:03.337Z SERIAL » [ACK]                                                                   (0x06)
2022-09-13T09:25:03.338Z DRIVER « [REQ] [SendDataBridge]
                                    callback id:            25
                                    transmit status:        OK, took 190 ms
                                    repeater node IDs:      9
                                    routing attempts:       1
                                    protocol & route speed: Z-Wave, 9.6 kbit/s
                                    ACK RSSI:               -95 dBm
                                    ACK RSSI on repeaters:  N/A
                                    ACK channel no.:        2
                                    TX channel no.:         1
2022-09-13T09:25:03.487Z SERIAL « 0x011a00a800010d119f03b60079c66de3a0c3ad10379d40ee2d00a01c          (28 bytes)
2022-09-13T09:25:03.491Z SERIAL » [ACK]                                                                   (0x06)
2022-09-13T09:25:03.492Z DRIVER « [Node 013] [REQ] [BridgeApplicationCommand]
                                  │ RSSI: -96 dBm
                                  └─[Security2CCMessageEncapsulation]
                                    │ sequence number: 182
                                    └─[SupervisionCCReport]
                                        session id:          34
                                        more updates follow: false
                                        status:              Success
                                        duration:            0s
2022-09-13T09:25:03.497Z CNTRLR   [Node 013] [setValue] result of SET_VALUE API call for ConfigurationCCAPI: (Su
                                  pervisionResult)
                                    status:   Success
2022-09-13T09:25:03.497Z CNTRLR   [Node 013] [setValue] updating value with event
2022-09-13T09:25:03.498Z CNTRLR   [Node 013] [translateValueEvent: value updated]
                                    commandClass: Configuration
                                    endpoint:     0
                                    property:     26
                                    propertyKey:  16711680
                                    internal:     false
                                    secret:       false
                                    event source: driver
2022-09-13T09:25:03.499Z CNTRLR   [Node 013] [translateValueEvent: value updated]
                                    is root endpoint:        true
                                    is application CC:       true
                                    should hide root values: true

I do not understand why communication works for configuration changes yet does not work for dimming commands. Any help solving this would be much appreciated!

Did this start recently?

Which version of HA and Z-wave JS are you running?

There was a big change recently to Z-wave JS that broke a few things. It was fixed in 0.1.70 and requires HA 9.x but you also need to do a re-interview of the devices.

1 Like

Thank you, another re-interview seems to have fixed it!

I only set this up about three weeks ago, so I do not know if it would have worked with older versions.

I am currently running Zwavejs2Mqtt 7.1.0, Z-Wave JS 10.0.4 and HomeAssistant 2022.9.2.
I just updated all of them today hoping that it might solve the problem. I was running some version from July or August when I set it up which might well have been a broken version? I am pretty sure that I did re-interview it on that older version without it working.

The log looks like the command is now (unlike before) being sent with Security2CCMessageEncapsulation. Was that the problem in the broken Z-Wave JS version?

2022-09-13T14:51:48.081Z CNTRLR   [Node 013] [setValue] calling SET_VALUE API MultilevelSwitchCCAPI:
                                    property:     targetValue
                                    property key: undefined
                                    optimistic:   true
2022-09-13T14:51:48.096Z SERIAL » 0x012400a9010d189f038f005abd6975b6d1c214b25a8cd5ffc90c0265928b70250 (38 bytes)
                                  000000071ee
2022-09-13T14:51:48.098Z DRIVER » [Node 013] [REQ] [SendDataBridge]
                                  │ source node id:   1
                                  │ transmit options: 0x25
                                  │ callback id:      113
                                  └─[Security2CCMessageEncapsulation]
                                    │ sequence number: 143
                                    └─[MultiChannelCCCommandEncapsulation]
                                      │ source:      0
                                      │ destination: 5
                                      └─[SupervisionCCGet]
                                        │ session id:      44
                                        │ request updates: true
                                        └─[MultilevelSwitchCCSet]
                                            target value: 78
                                            duration:     default
2022-09-13T14:51:48.107Z SERIAL « [ACK]                                                                   (0x06)
2022-09-13T14:51:48.109Z SERIAL « 0x010401a90152                                                       (6 bytes)
2022-09-13T14:51:48.111Z SERIAL » [ACK]                                                                   (0x06)
2022-09-13T14:51:48.112Z DRIVER « [RES] [SendDataBridge]
                                    was sent: true
2022-09-13T14:51:48.125Z SERIAL « 0x011d00a97100000100a37f7f7f7f00000300000000030100007f7f7f7f7fe6    (31 bytes)
2022-09-13T14:51:48.126Z SERIAL » [ACK]                                                                   (0x06)
2022-09-13T14:51:48.126Z DRIVER « [REQ] [SendDataBridge]
                                    callback id:            113
                                    transmit status:        OK, took 10 ms
                                    routing attempts:       1
                                    protocol & route speed: Z-Wave, 100 kbit/s
                                    ACK RSSI:               -93 dBm
                                    ACK channel no.:        0
                                    TX channel no.:         0
2022-09-13T14:51:48.149Z SERIAL « 0x011e00a800010d159f03ff00161ee202afe685a496e3e56bce74d2400f00a3cc  (32 bytes)
2022-09-13T14:51:48.159Z SERIAL » [ACK]                                                                   (0x06)
2022-09-13T14:51:48.161Z DRIVER « [Node 013] [REQ] [BridgeApplicationCommand]
                                  │ RSSI: -93 dBm
                                  └─[Security2CCMessageEncapsulation]
                                    │ sequence number: 255
                                    └─[MultiChannelCCCommandEncapsulation]
                                      │ source:      5
                                      │ destination: 0
                                      └─[SupervisionCCReport]
                                          session id:          44
                                          more updates follow: true
                                          status:              Working
                                          duration:            7s
2022-09-13T14:51:48.165Z CNTRLR   [Node 013] [setValue] result of SET_VALUE API call for MultilevelSwitchCCAPI: 
                                  (SupervisionResult)
                                    status:   Working
                                    duration: 7s
2022-09-13T14:51:48.165Z CNTRLR   [Node 013] [setValue] updating value with event
2022-09-13T14:51:48.166Z CNTRLR   [Node 013] [translateValueEvent: value updated]
                                    commandClass: Multilevel Switch
                                    endpoint:     5
                                    property:     targetValue
                                    propertyKey:  undefined
                                    internal:     false
                                    secret:       false
                                    event source: driver
2022-09-13T14:51:48.166Z CNTRLR   [Node 013] [translateValueEvent: value updated]
                                    is root endpoint:        false
                                    is application CC:       true
                                    should hide root values: true
2022-09-13T14:51:52.051Z SERIAL « 0x012200a800010d199f0300007ef4acade5a4c57c68a40d7e6c28475c661098b80 (36 bytes)
                                  b00a496
2022-09-13T14:51:52.057Z SERIAL » [ACK]                                                                   (0x06)
2022-09-13T14:51:52.060Z CNTRLR   [Node 013] [translateValueEvent: value updated]
                                    commandClass: Multilevel Switch
                                    endpoint:     5
                                    property:     targetValue
                                    propertyKey:  undefined
                                    internal:     false
                                    secret:       false
                                    event source: undefined
2022-09-13T14:51:52.060Z CNTRLR   [Node 013] [~] [Multilevel Switch] targetValue: 78 => 78          [Endpoint 5]
2022-09-13T14:51:52.061Z CNTRLR   [Node 013] [translateValueEvent: value updated]
                                    is root endpoint:        false
                                    is application CC:       true
                                    should hide root values: true
2022-09-13T14:51:52.065Z CNTRLR   [Node 013] [translateValueEvent: value updated]
                                    commandClass: Multilevel Switch
                                    endpoint:     5
                                    property:     duration
                                    propertyKey:  undefined
                                    internal:     false
                                    secret:       false
                                    event source: undefined
2022-09-13T14:51:52.065Z CNTRLR   [Node 013] [~] [Multilevel Switch] duration: {"value":0,"unit":"s [Endpoint 5]
                                  econds"} => {"value":0,"unit":"seconds"}
2022-09-13T14:51:52.065Z CNTRLR   [Node 013] [translateValueEvent: value updated]
                                    is root endpoint:        false
                                    is application CC:       true
                                    should hide root values: true
2022-09-13T14:51:52.067Z CNTRLR   [Node 013] [translateValueEvent: value updated]
                                    commandClass: Multilevel Switch
                                    endpoint:     5
                                    property:     currentValue
                                    propertyKey:  undefined
                                    internal:     false
                                    secret:       false
                                    event source: undefined
2022-09-13T14:51:52.067Z CNTRLR   [Node 013] [~] [Multilevel Switch] currentValue: 0 => 78          [Endpoint 5]
2022-09-13T14:51:52.068Z CNTRLR   [Node 013] [translateValueEvent: value updated]
                                    is root endpoint:        false
                                    is application CC:       true
                                    should hide root values: true
2022-09-13T14:51:52.070Z DRIVER « [Node 013] [REQ] [BridgeApplicationCommand]
                                  │ RSSI: -92 dBm
                                  └─[Security2CCMessageEncapsulation]
                                    │ sequence number: 0
                                    └─[MultiChannelCCCommandEncapsulation]
                                      │ source:      5
                                      │ destination: 0
                                      └─[SupervisionCCGet]
                                        │ session id:      36
                                        │ request updates: false
                                        └─[MultilevelSwitchCCReport]
                                            current value: 78
                                            target value:  78
                                            duration:      0s
2022-09-13T14:51:52.087Z SERIAL » 0x012100a9010d159f0390005d90f6c71d2713bbf0b7f10ed2153c3892240000000 (35 bytes)
                                  000c1
2022-09-13T14:51:52.088Z DRIVER » [Node 013] [REQ] [SendDataBridge]
                                  │ source node id:   1
                                  │ transmit options: 0x24
                                  │ callback id:      0
                                  └─[Security2CCMessageEncapsulation]
                                    │ sequence number: 144
                                    └─[MultiChannelCCCommandEncapsulation]
                                      │ source:      0
                                      │ destination: 5
                                      └─[SupervisionCCReport]
                                          session id:          36
                                          more updates follow: false
                                          status:              Success
                                          duration:            0s
2022-09-13T14:51:52.098Z SERIAL « [ACK]                                                                   (0x06)
2022-09-13T14:51:52.100Z SERIAL « 0x010401a90152                                                       (6 bytes)
2022-09-13T14:51:52.101Z SERIAL » [ACK]                                                                   (0x06)
2022-09-13T14:51:52.102Z DRIVER « [RES] [SendDataBridge]
                                    was sent: true
2022-09-13T14:51:52.110Z SERIAL « 0x012200a800010d199f0300007ef4acade5a4c57c68a40d7e6c28475c661098b80 (36 bytes)
                                  b00a391
2022-09-13T14:51:52.111Z DRIVER   Dropping message with invalid payload
2022-09-13T14:51:52.112Z DRIVER « [Node 013] [REQ] [BridgeApplicationCommand]
                                  │ RSSI: -93 dBm
                                  └─[Security2CCMessageEncapsulation] [INVALID]
                                      error: Duplicate command
2022-09-13T14:51:52.112Z SERIAL » [ACK]                                                                   (0x06)
2022-09-13T14:51:55.147Z SERIAL « 0x011e00a800010d159f0301007688c4c3f76ae1500ea794a3b4de46870700a389  (32 bytes)
2022-09-13T14:51:55.150Z SERIAL » [ACK]                                                                   (0x06)
2022-09-13T14:51:55.151Z DRIVER « [Node 013] [REQ] [BridgeApplicationCommand]
                                  │ RSSI: -93 dBm
                                  └─[Security2CCMessageEncapsulation]
                                    │ sequence number: 1
                                    └─[MultiChannelCCCommandEncapsulation]
                                      │ source:      5
                                      │ destination: 0
                                      └─[SupervisionCCReport]
                                          session id:          44
                                          more updates follow: false
                                          status:              Success
                                          duration:            0s
2022-09-13T14:51:55.154Z CNTRLR « [Node 013] Received update for a Supervision session
2022-09-13T14:51:55.154Z CNTRLR   [Node 013] [translateValueEvent: value updated]
                                    commandClass: Multilevel Switch
                                    endpoint:     5
                                    property:     currentValue
                                    propertyKey:  undefined
                                    internal:     false
                                    secret:       false
                                    event source: undefined
2022-09-13T14:51:55.155Z CNTRLR   [Node 013] [~] [Multilevel Switch] currentValue: 78 => 78         [Endpoint 5]
2022-09-13T14:51:55.155Z CNTRLR   [Node 013] [translateValueEvent: value updated]
                                    is root endpoint:        false
                                    is application CC:       true
                                    should hide root values: true

Yes, the issue was to do with a change in security encapsulation in Z-wave JS 10.x that required HA 9.x and a re-interview.

There were other changes that resulted in some of my devices having changed behaviour and changes to entities as a result of this. Fibaro door sensors and outlets specifically use different entities than before.

1 Like