node-zwave-js
node-zwave-js copied to clipboard
Published
20 hours ago •
zwave-js
zwave-js
S2: When a node does not understand an outgoing SupervisionReport, chaos ensues
We should wait for a "soft"-ACK (i.e. no response at all for a short amount of time) after sending out S2-encapsulated messages without ACK request. This should avoid mismatching the Security2CCNonceReport a node sends with the next message.
2022-09-07T14:03:31.837Z DRIVER » [Node 209] [REQ] [SendDataBridge]
│ source node id: 1
│ transmit options: 0x24
│ callback id: 0
└─[Security2CCMessageEncapsulation]
│ sequence number: 34
└─[SupervisionCCReport]
session id: 43
more updates follow: false
status: Success
duration: 0s
2022-09-07T14:03:31.844Z SERIAL « [ACK] (0x06)
2022-09-07T14:03:31.847Z SERIAL « 0x010401a90152 (6 bytes)
2022-09-07T14:03:31.849Z SERIAL » [ACK] (0x06)
2022-09-07T14:03:31.854Z DRIVER « [RES] [SendDataBridge]
was sent: true
2022-09-07T14:03:31.876Z SERIAL » 0x011a00a901d10e9f0323009467e7eae671f3237a2025000000005eb5 (28 bytes)
2022-09-07T14:03:31.878Z DRIVER » [Node 209] [REQ] [SendDataBridge]
│ source node id: 1
│ transmit options: 0x25
│ callback id: 94
└─[Security2CCMessageEncapsulation]
│ sequence number: 35
└─[Security2CCCommandsSupportedGet]
2022-09-07T14:03:31.883Z SERIAL « 0x011d00a80001d1149f024c011571b1066e330fa0c46b145df50d5b7600c589 (31 bytes)
2022-09-07T14:03:31.886Z SERIAL » [ACK] (0x06)
2022-09-07T14:03:31.887Z SERIAL « [CAN] (0x18)
2022-09-07T14:03:31.891Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2022-09-07T14:03:31.901Z DRIVER « [Node 209] [REQ] [BridgeApplicationCommand]
│ RSSI: -59 dBm
└─[Security2CCNonceReport]
sequence number: 76
SOS: true
MOS: false
receiver entropy: 0x1571b1066e330fa0c46b145df50d5b76
2022-09-07T14:03:31.906Z CNTRLR « [Node 209] received expected response prematurely, remembering it...
2022-09-07T14:03:31.993Z SERIAL » 0x011a00a901d10e9f0323009467e7eae671f3237a2025000000005eb5 (28 bytes)
2022-09-07T14:03:31.995Z DRIVER » [Node 209] [REQ] [SendDataBridge]
│ source node id: 1
│ transmit options: 0x25
│ callback id: 94
└─[Security2CCMessageEncapsulation]
│ sequence number: 35
└─[Security2CCCommandsSupportedGet]
2022-09-07T14:03:32.001Z SERIAL « [ACK] (0x06)
2022-09-07T14:03:32.005Z SERIAL « 0x010401a90152 (6 bytes)
2022-09-07T14:03:32.006Z SERIAL » [ACK] (0x06)
2022-09-07T14:03:32.012Z DRIVER « [RES] [SendDataBridge]
was sent: true
2022-09-07T14:03:32.019Z SERIAL « 0x011d00a95e00000100c57f7f7f7f00000300000000030100007f7f7f7f7faf (31 bytes)
2022-09-07T14:03:32.021Z SERIAL » [ACK] (0x06)
2022-09-07T14:03:32.024Z DRIVER « [REQ] [SendDataBridge]
callback id: 94
transmit status: OK, took 10 ms
routing attempts: 1
protocol & route speed: Z-Wave, 100 kbit/s
ACK RSSI: -59 dBm
ACK channel no.: 0
TX channel no.: 0
2022-09-07T14:03:32.043Z CNTRLR [Node 209] failed to decode the message, retrying with SPAN extension...
2022-09-07T14:03:32.051Z SERIAL » 0x012c00a901d1209f03240112415d68bc0b3595289f62af1a18f0319cc0e750b4d (46 bytes)
85734f22041a225000000005f54
2022-09-07T14:03:32.054Z DRIVER » [Node 209] [REQ] [SendDataBridge]
│ source node id: 1
│ transmit options: 0x25
│ callback id: 95
└─[Security2CCMessageEncapsulation]
│ sequence number: 36
│ extensions:
│ · type: SPAN
│ sender EI: 0x5d68bc0b3595289f62af1a18f0319cc0
└─[Security2CCCommandsSupportedGet]
2022-09-07T14:03:32.061Z SERIAL « 0x011d00a80001d1149f024d01cf92e87ec356de2f1f23a5a170f14b0800c5cf (31 bytes)
2022-09-07T14:03:32.065Z SERIAL » [ACK] (0x06)
2022-09-07T14:03:32.072Z DRIVER « [Node 209] [REQ] [BridgeApplicationCommand]
│ RSSI: -59 dBm
└─[Security2CCNonceReport]
sequence number: 77
SOS: true
MOS: false
receiver entropy: 0xcf92e87ec356de2f1f23a5a170f14b08
2022-09-07T14:03:32.076Z CNTRLR « [Node 209] received expected response prematurely, remembering it...
2022-09-07T14:03:32.079Z SERIAL « [CAN] (0x18)
2022-09-07T14:03:32.083Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2022-09-07T14:03:32.185Z SERIAL » 0x012c00a901d1209f03240112415d68bc0b3595289f62af1a18f0319cc0e750b4d (46 bytes)
85734f22041a225000000005f54
2022-09-07T14:03:32.191Z DRIVER » [Node 209] [REQ] [SendDataBridge]
│ source node id: 1
│ transmit options: 0x25
│ callback id: 95
└─[Security2CCMessageEncapsulation]
│ sequence number: 36
│ extensions:
│ · type: SPAN
│ sender EI: 0x5d68bc0b3595289f62af1a18f0319cc0
└─[Security2CCCommandsSupportedGet]
2022-09-07T14:03:32.198Z SERIAL « [ACK] (0x06)
2022-09-07T14:03:32.206Z SERIAL « 0x010401a90152 (6 bytes)
2022-09-07T14:03:32.208Z SERIAL » [ACK] (0x06)
2022-09-07T14:03:32.221Z DRIVER « [RES] [SendDataBridge]
was sent: true
2022-09-07T14:03:32.229Z SERIAL « 0x011d00a95f00000100c57f7f7f7f00000300000000030100007f7f7f7f7fae (31 bytes)
2022-09-07T14:03:32.234Z SERIAL » [ACK] (0x06)
2022-09-07T14:03:32.240Z DRIVER « [REQ] [SendDataBridge]
callback id: 95
transmit status: OK, took 10 ms
routing attempts: 1
protocol & route speed: Z-Wave, 100 kbit/s
ACK RSSI: -59 dBm
ACK channel no.: 0
TX channel no.: 0
2022-09-07T14:03:32.249Z CNTRLR [Node 209] failed to decode the message after re-transmission with SPAN extens
ion, dropping the message.
2022-09-07T14:03:32.255Z CNTRLR [Node 209] Querying securely supported commands (S2_Authenticated), attempt 1/
3 failed. Retrying in 500ms...
