Zwave dimmer slow state report when using web sockets

Hello,

i recently started playing with ZWaveJS and noticed that my dimmers are very slow to report the correct state to the UI when turning on the light. I switched my ZWaveJS to use MQTT instead of web sockets and the issue goes away.

The logs show a 5 second delay when using web sockets, and the value is reported as 255 not 99.
When using MQTT the state is reflected instantly and the value is set to 99.

I did not find those differences discussed in the forums yet, and was wondering why web sockets is using 255 instead of 99. Could that cause the delay?

Web Sockets:

2022-04-15 20:53:33.504 INFO ZWAVE: Node 8: value updated: 38-0-targetValue 0 => 255
2022-04-15 20:53:38.660 INFO ZWAVE: Node 8: value updated: 38-0-targetValue 255 => 99
2022-04-15 20:53:38.665 INFO ZWAVE: Node 8: value updated: 38-0-duration 0s => 0s
2022-04-15 20:53:38.668 INFO ZWAVE: Node 8: value updated: 38-0-currentValue 0 => 99

MQTT:

2022-04-15 20:57:34.176 INFO MQTT: Message received on zwave/Office_Main_Light/38/0/targetValue/set: '99'
2022-04-15 20:57:34.178 INFO ZWAVE: Writing 99 to 8-38-0-targetValue
2022-04-15 20:57:34.368 INFO ZWAVE: Node 8: value updated: 38-0-currentValue 0 => 99
2022-04-15 20:57:34.373 INFO ZWAVE: Node 8: value updated: 38-0-targetValue 0 => 99

I played some more with the dimmer. When using the service “light: turn_on” without brightness, the state is updated after 5 seconds. When setting the brightness to 255, in the “light: turn_on” the state for the dimmer is showing instantly in the UI.

Is there a way to override default service behavior for all dimmers to always include brightness?

2022-04-15 21:32:39.992 INFO ZWAVE: Node 8: value updated: 38-0-currentValue 0 => 99
2022-04-15 21:32:39.996 INFO ZWAVE: Node 8: value updated: 38-0-targetValue 0 => 99

I saw a similar issue with a fan zwave switch. In that case zwavejs was cancelling the poll after set, I opened a bug report and it should be getting fixed.

Capture the zwavejs log files and post the excerpt here

I see the same behavior on my HeatIt Z-Wave dimmers.
Home Assistant do not report light on until 4-5 seconds has passed when brightness is not set.

Turn on without brightness

2022-05-12 09:01:12.078 INFO ZWAVE: Node 23: value updated: 38-0-targetValue 0 => 255
2022-05-12 09:01:13.608 INFO ZWAVE: Node 23: value updated: 50-0-value-66049 0 => 9.9
2022-05-12 09:01:17.133 INFO ZWAVE: Node 23: value updated: 38-0-targetValue 255 => 34
2022-05-12 09:01:17.137 INFO ZWAVE: Node 23: value updated: 38-0-duration 0s => 0s
2022-05-12 09:01:17.140 INFO ZWAVE: Node 23: value updated: 38-0-currentValue 0 => 34

Turn on with brightness set

2022-05-12 09:03:32.855 INFO ZWAVE: Node 23: value updated: 38-0-currentValue 0 => 50
2022-05-12 09:03:32.858 INFO ZWAVE: Node 23: value updated: 38-0-targetValue 0 => 50
2022-05-12 09:03:34.734 INFO ZWAVE: Node 23: value updated: 50-0-value-66049 0 => 12.9
2022-05-12 09:03:47.437 INFO ZWAVE: Node 23: value updated: 50-0-value-65537 2.98 => 2.98

Here are the Z-wave logs:

Without brightness set

2022-05-12T07:36:32.491Z DRIVER » [Node 023] [REQ] [SendData]
                                  │ transmit options: 0x25
                                  │ callback id:      9
                                  └─[SupervisionCCGet]
                                    │ session id:      27
                                    │ request updates: true
                                    └─[MultilevelSwitchCCSet]
                                        target value: 255
                                        duration:     default
2022-05-12T07:36:32.513Z SERIAL « [ACK]                                                                   (0x06)
2022-05-12T07:36:32.516Z SERIAL « 0x0104011301e8                                                       (6 bytes)
2022-05-12T07:36:32.516Z SERIAL » [ACK]                                                                   (0x06)
2022-05-12T07:36:32.517Z DRIVER « [RES] [SendData]
                                    was sent: true
2022-05-12T07:36:32.521Z SERIAL « 0x0107001309000003e1                                                 (9 bytes)
2022-05-12T07:36:32.522Z SERIAL » [ACK]                                                                   (0x06)
2022-05-12T07:36:32.523Z DRIVER « [REQ] [SendData]
                                    callback id:     9
                                    transmit status: OK
2022-05-12T07:36:32.531Z SERIAL « 0x010b00040017056c021bff0068                                        (13 bytes)
2022-05-12T07:36:32.533Z SERIAL » [ACK]                                                                   (0x06)
2022-05-12T07:36:32.535Z DRIVER « [Node 023] [REQ] [ApplicationCommand]
                                  └─[SupervisionCCReport]
                                      session id:          27
                                      more updates follow: false
                                      status:              Success
                                      duration:            0s
2022-05-12T07:36:32.716Z DRIVER   Usage statistics sent - next transmission scheduled in 23 hours.
2022-05-12T07:36:34.243Z SERIAL « 0x0110000400170a3202215201fe000000004a                              (18 bytes)
2022-05-12T07:36:34.246Z CNTRLR   [Node 023] [~] [Meter] value[66049]: 0 => 5.1                     [Endpoint 0]
2022-05-12T07:36:34.253Z SERIAL » [ACK]                                                                   (0x06)
2022-05-12T07:36:34.258Z DRIVER « [Node 023] [REQ] [ApplicationCommand]
                                  └─[MeterCCReport]
                                      type:       Electric
                                      scale:      W
                                      rate type:  Consumed
                                      value:      5.1
                                      time delta: 0 seconds
2022-05-12T07:36:37.563Z SERIAL » 0x0109001317022602250afb                                            (11 bytes)
2022-05-12T07:36:37.564Z DRIVER » [Node 023] [REQ] [SendData]
                                  │ transmit options: 0x25
                                  │ callback id:      10
                                  └─[MultilevelSwitchCCGet]
2022-05-12T07:36:37.567Z SERIAL « [ACK]                                                                   (0x06)
2022-05-12T07:36:37.572Z SERIAL « 0x0104011301e8                                                       (6 bytes)
2022-05-12T07:36:37.575Z SERIAL » [ACK]                                                                   (0x06)
2022-05-12T07:36:37.576Z DRIVER « [RES] [SendData]
                                    was sent: true
2022-05-12T07:36:37.588Z SERIAL « 0x010700130a000002e3                                                 (9 bytes)
2022-05-12T07:36:37.589Z SERIAL » [ACK]                                                                   (0x06)
2022-05-12T07:36:37.590Z DRIVER « [REQ] [SendData]
                                    callback id:     10
                                    transmit status: OK
2022-05-12T07:36:37.602Z SERIAL « 0x010b00040017052603080800c7                                        (13 bytes)
2022-05-12T07:36:37.605Z CNTRLR   [Node 023] [~] [Multilevel Switch] targetValue: 255 => 8          [Endpoint 0]
2022-05-12T07:36:37.608Z CNTRLR   [Node 023] [~] [Multilevel Switch] duration: {"value":0,"unit":"s [Endpoint 0]
                                  econds"} => {"value":0,"unit":"seconds"}
2022-05-12T07:36:37.612Z CNTRLR   [Node 023] [~] [Multilevel Switch] currentValue: 0 => 8           [Endpoint 0]
2022-05-12T07:36:37.614Z SERIAL » [ACK]                                                                   (0x06)
2022-05-12T07:36:37.620Z DRIVER « [Node 023] [REQ] [ApplicationCommand]
                                  └─[MultilevelSwitchCCReport]
                                      current value: 8
                                      target value:  8
                                      duration:      0s

With brightness set

2022-05-12T07:47:03.052Z SERIAL » 0x010f001317086c019d04260132ff2509ce                                (17 bytes)
2022-05-12T07:47:03.054Z DRIVER » [Node 023] [REQ] [SendData]
                                  │ transmit options: 0x25
                                  │ callback id:      9
                                  └─[SupervisionCCGet]
                                    │ session id:      29
                                    │ request updates: true
                                    └─[MultilevelSwitchCCSet]
                                        target value: 50
                                        duration:     default
2022-05-12T07:47:03.056Z SERIAL « [ACK]                                                                   (0x06)
2022-05-12T07:47:03.061Z SERIAL « 0x0104011301e8                                                       (6 bytes)
2022-05-12T07:47:03.064Z SERIAL » [ACK]                                                                   (0x06)
2022-05-12T07:47:03.066Z DRIVER « [RES] [SendData]
                                    was sent: true
2022-05-12T07:47:03.078Z SERIAL « 0x0107001309000002e0                                                 (9 bytes)
2022-05-12T07:47:03.079Z SERIAL » [ACK]                                                                   (0x06)
2022-05-12T07:47:03.080Z DRIVER « [REQ] [SendData]
                                    callback id:     9
                                    transmit status: OK
2022-05-12T07:47:03.093Z SERIAL « 0x010b00040017056c021dff006e                                        (13 bytes)
2022-05-12T07:47:03.095Z SERIAL » [ACK]                                                                   (0x06)
2022-05-12T07:47:03.097Z DRIVER « [Node 023] [REQ] [ApplicationCommand]
                                  └─[SupervisionCCReport]
                                      session id:          29
                                      more updates follow: false
                                      status:              Success
                                      duration:            0s
2022-05-12T07:47:03.102Z CNTRLR   [Node 023] [~] [Multilevel Switch] currentValue: 0 => 50          [Endpoint 0]
2022-05-12T07:47:04.986Z SERIAL « 0x0110000400170a32022152050a00000000ba                              (18 bytes)
2022-05-12T07:47:04.988Z CNTRLR   [Node 023] [~] [Meter] value[66049]: 0 => 12.9                    [Endpoint 0]
2022-05-12T07:47:04.996Z SERIAL » [ACK]                                                                   (0x06)
2022-05-12T07:47:05.000Z DRIVER « [Node 023] [REQ] [ApplicationCommand]
                                  └─[MeterCCReport]
                                      type:       Electric
                                      scale:      W
                                      rate type:  Consumed
                                      value:      12.9
                                      time delta: 0 seconds