What’s happening is the switch is turning on, but then it turns off after a few seconds. The switch (Zen15) isn’t reporting overcurrent, and it’s not running a heavy load. Nothing in configuration that would shut it off, and most of the time is works as expected.
root@a0d7b954-zwavejs2mqtt:/data/store/logs$ cat z-ui_current.log | grep 067 | grep targetValue | grep 10:39:5
2025-04-21 10:39:50.965 INFO Z-WAVE: [Node 067] Value updated: 37-0-targetValue false => true
2025-04-21 10:39:51.036 INFO Z-WAVE: [Node 067] Value updated: 37-0-targetValue true => true
2025-04-21 10:39:57.400 INFO Z-WAVE: [Node 067] Value updated: 37-0-targetValue true => false
There’s a gap in time (about 6.8 seconds) and then the node just reports that the switch is off. That makes me think that the device is turning off for some unknown reason. Just out of the blue the node sends a BridgeApplicationCommand report saying the current value is false. I.e. there’s no BinarySwitchCCSet sent first to the node to turn the device off:
2025-04-21T17:39:56.411Z DRIVER all queues idle
2025-04-21T17:39:57.385Z SERIAL « 0x012300a80000010043159f03c80085418ad95eb07d020955aa139e9bd1f04800a (37 bytes)
d007f7f55
2025-04-21T17:39:57.391Z SERIAL » [ACK] (0x06)
2025-04-21T17:39:57.394Z CNTRLR [Node 067] [~] [Binary Switch] duration: {"value":0,"unit":"secon [Endpoint 0]
ds"} => {"value":0,"unit":"seconds"}
2025-04-21T17:39:57.398Z CNTRLR [Node 067] [~] [Binary Switch] targetValue: true => false [Endpoint 0]
2025-04-21T17:39:57.402Z CNTRLR [Node 067] [~] [Binary Switch] currentValue: true => false [Endpoint 0]
2025-04-21T17:39:57.404Z DRIVER « [Node 067] [REQ] [BridgeApplicationCommand]
│ RSSI: -83 dBm
└─[Security2CCMessageEncapsulation]
│ sequence number: 200
│ security class: S2_Authenticated
└─[SupervisionCCGet]
│ session id: 9
│ request updates: false
└─[BinarySwitchCCReport]
current value: false
target value: false
duration: 0s
Am I reading the correctly?
One thing of note (in the logs below) is that node 067 apparently sends a duplicate BridgeApplicationCommand message – or at least the driver reports a duplicate message. I think the node might do that if it didn’t receive and ACK from the first one. But, the duplicate message is reported only 0.049 later, which doesn’t seem long enough for the node to wait to send it again. Have to wonder if there really was a duplicate sent.
Here's all the logs, from initially turning it on until it turns off.
This shows the driver sending the command to the node to turn on the binary switch.
2025-04-21T17:39:50.907Z DRIVER » [Node 067] [REQ] [SendDataBridge]
│ source node id: 1
│ transmit options: 0x25
│ callback id: 174
└─[Security2CCMessageEncapsulation]
│ sequence number: 182
└─[SupervisionCCGet]
│ session id: 22
│ request updates: true
└─[BinarySwitchCCSet]
target value: true
(0x06)
2025-04-21T17:39:50.908Z SERIAL » 0x012200a900010043149f03b600bc058c95f6cf6a31c2b5ee68d48c9c702500000 (36 bytes)
000ae04
2025-04-21T17:39:50.916Z SERIAL « [ACK] (0x06)
2025-04-21T17:39:50.920Z SERIAL « 0x010401a90152 (6 bytes)
2025-04-21T17:39:50.921Z SERIAL » [ACK] (0x06)
2025-04-21T17:39:50.923Z DRIVER « [RES] [SendDataBridge]
was sent: true
The request was queued for transmission on the stick.
Then next the stick tells the driver that the transmission (for ID 174) was OK – successfully sent.
2025-04-21T17:39:50.939Z DRIVER « [REQ] [SendDataBridge]
callback id: 174
transmit status: OK, took 10 ms
routing attempts: 1
protocol & route speed: Z-Wave, 100 kbit/s
routing scheme: LWR
ACK RSSI: -83 dBm
ACK channel no.: 0
TX channel no.: 0
2025-04-21T17:39:50.957Z SERIAL « 0x011f00a80000010043119f03c400ffb816f23dae2ae0c93d0ffe8800ad007f7f9 (33 bytes)
9
2025-04-21T17:39:50.960Z SERIAL » [ACK]
And finally the node responds with a BridgeApplicationCommand, showing the RSSI and Success:
2025-04-21T17:39:50.962Z DRIVER « [Node 067] [REQ] [BridgeApplicationCommand]
│ RSSI: -83 dBm
└─[Security2CCMessageEncapsulation]
│ sequence number: 196
│ security class: S2_Authenticated
└─[SupervisionCCReport]
session id: 22
more updates follow: false
status: Success
duration: 0s
2025-04-21T17:39:50.968Z CNTRLR [Node 067] [~] [Binary Switch] currentValue: false => true [Endpoint 0]
2025-04-21T17:39:50.972Z DRIVER all queues idle
4
Now an error occurs. Looks like the DRIVER now receives a duplicate BridgeApplicationCommand from the device (sequence 196 was received already above).
I can’t really tell from the logs if the DRIVER ACK’d message 196, but it seems like the Zen15 resent the message 0.049 seconds later, which seems unlikely if it was waiting for an ACK.
2025-04-21T17:39:51.010Z DRIVER Dropping message with invalid payload
2025-04-21T17:39:51.011Z DRIVER « [Node 067] [REQ] [BridgeApplicationCommand]
│ RSSI: -80 dBm
└─[Security2CCMessageEncapsulation] [INVALID]
error: Duplicate command (sequence number 196)
2025-04-21T17:39:51.011Z SERIAL » [ACK] (0x06)
2025-04-21T17:39:51.025Z SERIAL « 0x012300a80000010043159f03c50062db411fa1dede8c7e9c80977da7c2a4c700a (37 bytes)
f007f7f91
2025-04-21T17:39:51.029Z SERIAL » [ACK]
I’m not sure what the follow represent CNTRLR message mean:
2025-04-21T17:39:51.031Z CNTRLR [Node 067] [~] [Binary Switch] duration: {"value":0,"unit":"secon [Endpoint 0]
ds"} => {"value":0,"unit":"seconds"}
2025-04-21T17:39:51.034Z CNTRLR [Node 067] [~] [Binary Switch] targetValue: true => true [Endpoint 0]
2025-04-21T17:39:51.037Z CNTRLR [Node 067] [~] [Binary Switch] currentValue: true => true [Endpoint 0]
Next the driver receives another BridgeApplicationCommand from the node with a new sequence number reporting the switch is on.
2025-04-21T17:39:51.041Z DRIVER « [Node 067] [REQ] [BridgeApplicationCommand]
│ RSSI: -81 dBm
└─[Security2CCMessageEncapsulation]
│ sequence number: 197
│ security class: S2_Authenticated
└─[SupervisionCCGet]
│ session id: 6
│ request updates: false
└─[BinarySwitchCCReport]
current value: true
target value: true
duration: 0s
Now the DRIVER asks the node for a report of the node’s status with callback ID = 175, and receives a response from the node.
2025-04-21T17:39:51.046Z DRIVER » [Node 067] [REQ] [SendDataBridge]
│ source node id: 1
│ transmit options: 0x00
│ callback id: 175
└─[Security2CCMessageEncapsulation]
│ sequence number: 183
└─[SupervisionCCReport]
session id: 6
more updates follow: false
status: Success
duration: 0s
2025-04-21T17:39:51.047Z SERIAL » 0x011f00a900010043119f03b700ad784015f3ce1e2c6d1928f0a70000000000af1 (33 bytes)
a
2025-04-21T17:39:51.055Z SERIAL « [ACK] (0x06)
2025-04-21T17:39:51.058Z SERIAL « 0x010401a90152 (6 bytes)
2025-04-21T17:39:51.059Z SERIAL » [ACK] (0x06)
2025-04-21T17:39:51.060Z DRIVER « [RES] [SendDataBridge]
was sent: true
2025-04-21T17:39:51.070Z SERIAL « 0x011d00a9af000001007f7f7f7f7f000003000000000301000000000000009b (31 bytes)
2025-04-21T17:39:51.071Z SERIAL » [ACK] (0x06)
2025-04-21T17:39:51.072Z DRIVER « [REQ] [SendDataBridge]
callback id: 175
transmit status: OK, took 10 ms
routing attempts: 1
protocol & route speed: Z-Wave, 100 kbit/s
routing scheme: LWR
ACK RSSI: N/A
ACK channel no.: 0
TX channel no.: 0
TX power: 0 dBm
measured noise floor: 0 dBm
ACK TX power by destination: 0 dBm
measured RSSI of ACK from destination: 0 dBm
measured noise floor by destination: 0 dBm
Now that the Zen15 switch is on, the node (067) starts sending power reports (Watts, Amps).
I’m curious why it seems like every time the node sends a report the driver then asks for a SupervisionCCReport. I’m not clear why that is needed after every report.
Anyway, here’s those power updates, although nothing very interesting.
2025-04-21T17:39:54.269Z CNTRLR [Node 067] [Meter] value[66049]: metadata updated [Endpoint 0]
2025-04-21T17:39:54.273Z CNTRLR [Node 067] [~] [Meter] value[66049]: 0 => 92.184 [Endpoint 0]
2025-04-21T17:39:54.280Z DRIVER « [Node 067] [REQ] [BridgeApplicationCommand]
│ RSSI: -81 dBm
└─[Security2CCMessageEncapsulation]
│ sequence number: 198
│ security class: S2_Authenticated
└─[SupervisionCCGet]
│ session id: 7
│ request updates: false
└─[MeterCCReport]
meter type: Electric
scale: W
rate type: Consumed
value: 92.184
time delta: 0 seconds
2025-04-21T17:39:54.284Z DRIVER one or more queues busy
2025-04-21T17:39:54.287Z DRIVER » [Node 067] [REQ] [SendDataBridge]
│ source node id: 1
│ transmit options: 0x00
│ callback id: 185
└─[Security2CCMessageEncapsulation]
│ sequence number: 184
└─[SupervisionCCReport]
session id: 7
more updates follow: false
status: Success
duration: 0s
2025-04-21T17:39:54.288Z SERIAL » 0x011f00a900010043119f03b8004cb96895238b76b9dd9205db3b0000000000b94 (33 bytes)
2
2025-04-21T17:39:54.299Z SERIAL « [ACK] (0x06)
2025-04-21T17:39:54.302Z SERIAL « 0x010401a90152 (6 bytes)
2025-04-21T17:39:54.304Z SERIAL » [ACK] (0x06)
2025-04-21T17:39:54.306Z DRIVER « [RES] [SendDataBridge]
was sent: true
2025-04-21T17:39:54.313Z SERIAL « 0x011d00a9b9000000007f7f7f7f7f000003000000000301000000000000008c (31 bytes)
2025-04-21T17:39:54.315Z SERIAL » [ACK] (0x06)
2025-04-21T17:39:54.316Z DRIVER « [REQ] [SendDataBridge]
callback id: 185
transmit status: OK, took 0 ms
routing attempts: 1
protocol & route speed: Z-Wave, 100 kbit/s
routing scheme: LWR
ACK RSSI: N/A
ACK channel no.: 0
TX channel no.: 0
TX power: 0 dBm
measured noise floor: 0 dBm
ACK TX power by destination: 0 dBm
measured RSSI of ACK from destination: 0 dBm
measured noise floor by destination: 0 dBm
2025-04-21T17:39:54.387Z SERIAL « 0x012800a800000100431a9f03c700866b45679c935b05bc0bf500bd241c4ed0e1b (42 bytes)
83799ef00af007f7f0c
2025-04-21T17:39:54.391Z SERIAL » [ACK] (0x06)
2025-04-21T17:39:54.394Z CNTRLR [Node 067] [Meter] value[66817]: metadata updated [Endpoint 0]
2025-04-21T17:39:54.399Z CNTRLR [Node 067] [~] [Meter] value[66817]: 0 => 0.754 [Endpoint 0]
2025-04-21T17:39:54.403Z DRIVER « [Node 067] [REQ] [BridgeApplicationCommand]
│ RSSI: -81 dBm
└─[Security2CCMessageEncapsulation]
│ sequence number: 199
│ security class: S2_Authenticated
└─[SupervisionCCGet]
│ session id: 8
│ request updates: false
└─[MeterCCReport]
meter type: Electric
scale: A
rate type: Consumed
value: 0.754
time delta: 0 seconds
2025-04-21T17:39:54.822Z DRIVER » [Node 067] [REQ] [SendDataBridge]
│ source node id: 1
│ transmit options: 0x00
│ callback id: 186
└─[Security2CCMessageEncapsulation]
│ sequence number: 185
└─[SupervisionCCReport]
session id: 8
more updates follow: false
status: Success
duration: 0s
2025-04-21T17:39:54.823Z SERIAL » 0x011f00a900010043119f03b90002b1b9a93066d3760942f5e1130000000000ba9 (33 bytes)
9
2025-04-21T17:39:54.832Z SERIAL « [ACK] (0x06)
2025-04-21T17:39:54.834Z SERIAL « 0x010401a90152 (6 bytes)
2025-04-21T17:39:54.836Z SERIAL » [ACK] (0x06)
2025-04-21T17:39:54.837Z DRIVER « [RES] [SendDataBridge]
was sent: true
2025-04-21T17:39:54.845Z SERIAL « 0x011d00a9ba000001007f7f7f7f7f000003000000000301000000000000008e (31 bytes)
2025-04-21T17:39:54.847Z SERIAL » [ACK] (0x06)
2025-04-21T17:39:54.848Z DRIVER « [REQ] [SendDataBridge]
callback id: 186
transmit status: OK, took 10 ms
routing attempts: 1
protocol & route speed: Z-Wave, 100 kbit/s
routing scheme: LWR
ACK RSSI: N/A
ACK channel no.: 0
TX channel no.: 0
TX power: 0 dBm
measured noise floor: 0 dBm
ACK TX power by destination: 0 dBm
measured RSSI of ACK from destination: 0 dBm
measured noise floor by destination: 0 dBm
2025-04-21T17:39:55.132Z SERIAL « 0x012800a800000100521a9f03760053f8528ea3cf56e3ed05a19773ee9b135ddc7 (42 bytes)
b11718500af007f7f09
2025-04-21T17:39:55.137Z SERIAL » [ACK]
Then, out of the blue, it appears the node sends a BridgeApplicationCommand saying that the node has turned off. The DRIVER follows with another SupervisionCCReport request:
2025-04-21T17:39:56.411Z DRIVER all queues idle
2025-04-21T17:39:57.385Z SERIAL « 0x012300a80000010043159f03c80085418ad95eb07d020955aa139e9bd1f04800a (37 bytes)
d007f7f55
2025-04-21T17:39:57.391Z SERIAL » [ACK] (0x06)
2025-04-21T17:39:57.394Z CNTRLR [Node 067] [~] [Binary Switch] duration: {"value":0,"unit":"secon [Endpoint 0]
ds"} => {"value":0,"unit":"seconds"}
2025-04-21T17:39:57.398Z CNTRLR [Node 067] [~] [Binary Switch] targetValue: true => false [Endpoint 0]
2025-04-21T17:39:57.402Z CNTRLR [Node 067] [~] [Binary Switch] currentValue: true => false [Endpoint 0]
2025-04-21T17:39:57.404Z DRIVER « [Node 067] [REQ] [BridgeApplicationCommand]
│ RSSI: -83 dBm
└─[Security2CCMessageEncapsulation]
│ sequence number: 200
│ security class: S2_Authenticated
└─[SupervisionCCGet]
│ session id: 9
│ request updates: false
└─[BinarySwitchCCReport]
current value: false
target value: false
duration: 0s
2025-04-21T17:39:57.407Z DRIVER one or more queues busy
2025-04-21T17:39:57.412Z DRIVER » [Node 067] [REQ] [SendDataBridge]
│ source node id: 1
│ transmit options: 0x00
│ callback id: 189
└─[Security2CCMessageEncapsulation]
│ sequence number: 186
└─[SupervisionCCReport]
session id: 9
more updates follow: false
status: Success
2025-04-21T17:39:57.413Z SERIAL » 0x011f00a900010043119f03ba00a3ae5fdddea494b06e877282c50000000000bd8 (33 bytes)
c
2025-04-21T17:39:57.421Z SERIAL « [ACK] (0x06)
2025-04-21T17:39:57.424Z SERIAL « 0x010401a90152 (6 bytes)
2025-04-21T17:39:57.426Z SERIAL » [ACK] (0x06)
2025-04-21T17:39:57.427Z DRIVER « [RES] [SendDataBridge]
was sent: true
2025-04-21T17:39:57.435Z SERIAL « 0x011d00a9bd000001007f7f7f7f7f0000030000000003010000000000000089 (31 bytes)
2025-04-21T17:39:57.437Z SERIAL » [ACK] (0x06)
2025-04-21T17:39:57.438Z DRIVER « [REQ] [SendDataBridge]
callback id: 189
transmit status: OK, took 10 ms
routing attempts: 1
protocol & route speed: Z-Wave, 100 kbit/s
routing scheme: LWR
ACK RSSI: N/A
ACK channel no.: 0
TX channel no.: 0
TX power: 0 dBm
measured noise floor: 0 dBm
ACK TX power by destination: 0 dBm
measured RSSI of ACK from destination: 0 dBm
measured noise floor by destination: 0 dBm
And that’s everything.