node-zwave-js: DoorLock re-interview fails
Describe the bug
The installation is working fine, I move the R-PI that hosts my Aeoteck Z-Stick and docker zwavejs2mqtt to a different location, which is 1/2 the distance from the BE469 lock and now it has issues getting the node info, after a restart.
Device information
Which device(s) is/are affected (make/model)?
What are the node IDs?
Node 020
Last Known Working Configuration
-
New device
-
Previously working device (node-zwave-js)
- Which library version/docker image/adapter version? same library same configuration
- Have you made any recent configuration changes to the device? Describe. Just moved the R-PI closer to the device - from my office where I have all the computers and monitors, on top of the fridge in the kitchen - which has direct access to the lock and it’s maybe 30 feet from the device
-
Previously working device (other platform)
- Which platform?
- Have you made any recent configuration changes to the device? Describe.
Installation information
How did you install node-zwave-js?
- Zwavejs2mqtt (latest) docker image
- Zwavejs2mqtt (dev) docker image
- ioBroker.zwave2 adapter
- Pkg
- Manual docker build
- Against which branch of
node-zwave-js? - With which branch of
zwavejs2mqtt?
- Against which branch of
- Other (describe)
- Manually built (
git clone-yarn install-yarn run build:full)
To Reproduce Steps to reproduce the behavior:
- Stop docker container
- Shutdown OS
- Move R-Pi to a central location
- Start the OK,
- Start docker container
- Interview start stuck at “RestartFromCache”, on “Re-Interview” request it changes to “NodeInfo”
Intersting stuff from the logs Dropping message with invalid data (Reason: Nonce 0x73 expired, cannot decode security encapsulated command.) but nothing changed other than the location. Anything that can be done? other than exclude and re-include?
Additional context Add any other context about the problem here. zwave-js logs while Re-Interviewing only node 020
02:28:41.886 CNTRLR [Node 020] Beginning interview - last completed stage: None
02:28:41.887 CNTRLR [Node 020] new node, doing a full interview...
02:28:41.887 CNTRLR » [Node 020] querying protocol info...
02:28:41.900 SERIAL » 0x0104004114ae (6 bytes)
02:28:41.901 DRIVER » [REQ] [GetNodeProtocolInfo]
payload: 0x14
02:28:41.907 SERIAL « [ACK] (0x06)
02:28:41.909 SERIAL « 0x0109014153dc000440037e (11 bytes)
02:28:41.910 SERIAL » [ACK] (0x06)
02:28:41.911 DRIVER « [RES] [GetNodeProtocolInfo]
payload: 0x53dc00044003
02:28:41.917 CNTRLR « [Node 020] received response for protocol info:
basic device class: Routing Slave
generic device class: Entry Control
specific device class: Secure Keypad Door Lock
is a listening device: false
is frequent listening: true
is a routing device: true
is a secure device: unknown
is a beaming device: true
maximum baud rate: 40000 kbps
version: 4
02:28:41.918 CNTRLR [Node 020] Interview stage completed: ProtocolInfo
02:28:41.918 CNTRLR » [Node 020] pinging the node...
02:28:41.931 SERIAL » 0x0108001314010025d105 (10 bytes)
02:28:41.932 DRIVER » [Node 020] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 209
└─[NoOperationCC]
02:28:41.935 SERIAL « [ACK] (0x06)
02:28:41.941 SERIAL « 0x0104011301e8 (6 bytes)
02:28:41.942 SERIAL » [ACK] (0x06)
02:28:41.943 DRIVER « [RES] [SendData]
was sent: true
02:28:43.598 SERIAL « 0x01180013d10000a602bc7f7f7f7f01010306040000020400003a (26 bytes)
02:28:43.599 SERIAL » [ACK] (0x06)
02:28:43.604 DRIVER « [REQ] [SendData]
callback id: 209
transmit status: OK
02:28:43.610 CNTRLR « [Node 020] ping successful
02:28:43.610 CNTRLR » [Node 020] querying node info...
02:28:43.619 SERIAL » 0x01040060148f (6 bytes)
02:28:43.619 DRIVER » [Node 020] [REQ] [RequestNodeInfo]
payload: 0x14
02:28:43.622 SERIAL « [ACK] (0x06)
02:28:43.627 SERIAL « 0x01040160019b (6 bytes)
02:28:43.628 SERIAL » [ACK] (0x06)
02:28:43.630 DRIVER « [RES] [RequestNodeInfo]
payload: 0x01
02:28:43.747 SERIAL « 0x010e004984140804400322727a988653 (16 bytes)
02:28:43.748 SERIAL » [ACK] (0x06)
02:28:43.749 DRIVER « [Node 020] [REQ] [ApplicationUpdateRequest]
payload: 0x84140804400322727a9886
02:28:43.754 CNTRLR « [Node 020] node info received
supported CCs:
· Application Status
· Manufacturer Specific
· Firmware Update Meta Data
· Security
· Version
controlled CCs:
02:28:43.763 CNTRLR [Node 020] Interview stage completed: NodeInfo
02:28:43.764 CNTRLR » [Node 020] querying securely supported commands...
02:28:43.781 SERIAL » 0x010900131402984025d2dc (11 bytes)
02:28:43.782 DRIVER » [Node 020] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 210
└─[SecurityCCNonceGet]
02:28:43.784 SERIAL « [ACK] (0x06)
02:28:43.790 SERIAL « 0x0104011301e8 (6 bytes)
02:28:43.791 SERIAL » [ACK] (0x06)
02:28:43.792 DRIVER « [RES] [SendData]
was sent: true
02:28:43.888 SERIAL « 0x01180013d200000a02be7f7f7f7f010103060400000201000092 (26 bytes)
02:28:43.889 SERIAL » [ACK] (0x06)
02:28:43.890 DRIVER « [REQ] [SendData]
callback id: 210
transmit status: OK
02:28:43.937 SERIAL « 0x0112000400140a988090c70ec7fb7e0194bf00de (20 bytes)
02:28:43.938 SERIAL » [ACK] (0x06)
02:28:43.939 DRIVER « [Node 020] [REQ] [ApplicationCommand]
└─[SecurityCCNonceReport]
nonce: 0x90c70ec7fb7e0194
02:28:43.945 SERIAL » 0x011d001314169881c36ee38b841f2199d70745900d8aac7eeae0ef0525d34a (31 bytes)
02:28:43.945 DRIVER » [Node 020] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 211
└─[SecurityCCCommandEncapsulation]
│ nonce id: 144
└─[SecurityCCCommandsSupportedGet]
02:28:43.949 SERIAL « [ACK] (0x06)
02:28:43.956 SERIAL « 0x0104011301e8 (6 bytes)
02:28:43.957 SERIAL » [ACK] (0x06)
02:28:43.958 DRIVER « [RES] [SendData]
was sent: true
02:28:44.112 SERIAL « 0x01180013d300000f02be7f7f7f7f010103060400000202000095 (26 bytes)
02:28:44.112 SERIAL » [ACK] (0x06)
02:28:44.113 DRIVER « [REQ] [SendData]
callback id: 211
transmit status: OK
02:28:44.157 SERIAL « 0x010a00040014029840bf0080 (12 bytes)
02:28:44.158 SERIAL » [ACK] (0x06)
02:28:44.160 DRIVER « [Node 020] [REQ] [ApplicationCommand]
└─[SecurityCCNonceGet]
02:28:44.178 SERIAL » 0x01110013140a988000e7c153274d6b5505d40b (19 bytes)
02:28:44.179 DRIVER » [Node 020] [REQ] [SendData]
│ transmit options: 0x05
│ callback id: 212
└─[SecurityCCNonceReport]
nonce: 0x00e7c153274d6b55
02:28:44.181 SERIAL « [ACK] (0x06)
02:28:44.187 SERIAL « 0x0104011301e8 (6 bytes)
02:28:44.188 SERIAL » [ACK] (0x06)
02:28:44.189 DRIVER « [RES] [SendData]
was sent: true
02:28:44.301 SERIAL « 0x01180013d400000b02bf7f7f7f7f010103060400000201000094 (26 bytes)
02:28:44.302 SERIAL » [ACK] (0x06)
02:28:44.303 DRIVER « [REQ] [SendData]
callback id: 212
transmit status: OK
02:28:44.348 SERIAL « 0x010a00040014029840bc0083 (12 bytes)
02:28:44.349 SERIAL » [ACK] (0x06)
02:28:44.350 DRIVER « [Node 020] [REQ] [ApplicationCommand]
└─[SecurityCCNonceGet]
02:28:44.366 SERIAL » 0x01110013140a9880416b0183379d1c7205d547 (19 bytes)
02:28:44.367 DRIVER » [Node 020] [REQ] [SendData]
│ transmit options: 0x05
│ callback id: 213
└─[SecurityCCNonceReport]
nonce: 0x416b0183379d1c72
02:28:44.370 SERIAL « [ACK] (0x06)
02:28:44.376 SERIAL « 0x0104011301e8 (6 bytes)
02:28:44.377 SERIAL » [ACK] (0x06)
02:28:44.378 DRIVER « [RES] [SendData]
was sent: true
02:28:44.396 SERIAL « 0x010a00040014029840be0081 (12 bytes)
02:28:44.397 SERIAL » [ACK] (0x06)
02:28:44.399 DRIVER « [Node 020] [REQ] [ApplicationCommand]
└─[SecurityCCNonceGet]
02:28:44.580 SERIAL « 0x01180013d500001402bc7f7f7f7f010103060400000201000089 (26 bytes)
02:28:44.581 SERIAL » [ACK] (0x06)
02:28:44.583 DRIVER « [REQ] [SendData]
callback id: 213
transmit status: OK
02:28:44.590 SERIAL » 0x01110013140a9880736546a79978a57f05d6e4 (19 bytes)
02:28:44.591 DRIVER » [Node 020] [REQ] [SendData]
│ transmit options: 0x05
│ callback id: 214
└─[SecurityCCNonceReport]
nonce: 0x736546a79978a57f
02:28:44.594 SERIAL « [ACK] (0x06)
02:28:44.600 SERIAL « 0x0104011301e8 (6 bytes)
02:28:44.601 SERIAL » [ACK] (0x06)
02:28:44.602 DRIVER « [RES] [SendData]
was sent: true
02:28:44.750 SERIAL « 0x01180013d600000f02bf7f7f7f7f010103060400000201000092 (26 bytes)
02:28:44.751 SERIAL » [ACK] (0x06)
02:28:44.752 DRIVER « [REQ] [SendData]
callback id: 214
transmit status: OK
02:28:44.824 SERIAL « 0x0128000400142098814275de04b84a51a7679204fce8d72f7bba77f6950673ad3 (42 bytes)
ebdd0eea2f133bc0066
02:28:44.825 DRIVER Dropping message with invalid data (Reason: Nonce 0x73 expired, cannot decode
security encapsulated command.):
0x0128000400142098814275de04b84a51a7679204fce8d72f7bba77f6950673ad3ebdd0eea2f1
33bc0066
02:28:44.826 SERIAL » [ACK] (0x06)
..............
02:28:54.120 CNTRLR [Node 020] The node is not included securely. Continuing interview non-securel
y.
02:28:54.123 CNTRLR [Node 020] ManufacturerSpecificCC: doing a complete interview...
02:28:54.123 CNTRLR » [Node 020] querying manufacturer information...
02:28:54.137 SERIAL » 0x010900131402720425d777 (11 bytes)
02:28:54.138 DRIVER » [Node 020] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 215
└─[ManufacturerSpecificCCGet]
02:28:54.141 SERIAL « [ACK] (0x06)
02:28:54.146 SERIAL « 0x0104011301e8 (6 bytes)
02:28:54.147 SERIAL » [ACK] (0x06)
02:28:54.149 DRIVER « [RES] [SendData]
was sent: true
02:28:55.622 SERIAL « 0x01180013d700009302bb7f7f7f7f010103060400000202041418 (26 bytes)
02:28:55.623 SERIAL » [ACK] (0x06)
02:28:55.624 DRIVER « [REQ] [SendData]
callback id: 215
transmit status: OK
02:29:05.631 CNTRLR [Node 020] Interview attempt 1/5 failed, retrying in 5000 ms...
02:29:10.650 CNTRLR [Node 020] Beginning interview - last completed stage: NodeInfo
02:29:10.652 CNTRLR [Node 020] ManufacturerSpecificCC: doing a complete interview...
02:29:10.653 CNTRLR » [Node 020] querying manufacturer information...
02:29:10.667 SERIAL » 0x010900131402720425d878 (11 bytes)
02:29:10.668 DRIVER » [Node 020] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 216
└─[ManufacturerSpecificCCGet]
02:29:10.671 SERIAL « [ACK] (0x06)
02:29:10.677 SERIAL « 0x0104011301e8 (6 bytes)
02:29:10.677 SERIAL » [ACK] (0x06)
02:29:10.679 DRIVER « [RES] [SendData]
was sent: true
02:29:12.082 SERIAL « 0x01180013d800008c02be7f7f7f7f01010306040000020204140d (26 bytes)
02:29:12.083 SERIAL » [ACK] (0x06)
02:29:12.084 DRIVER « [REQ] [SendData]
callback id: 216
transmit status: OK
02:29:22.092 CNTRLR [Node 020] Interview attempt 2/5 failed, retrying in 10000 ms...
02:29:32.110 CNTRLR [Node 020] Beginning interview - last completed stage: NodeInfo
02:29:32.112 CNTRLR [Node 020] ManufacturerSpecificCC: doing a complete interview...
02:29:32.113 CNTRLR » [Node 020] querying manufacturer information...
02:29:32.145 SERIAL » 0x010900131402720425d979 (11 bytes)
02:29:32.150 DRIVER » [Node 020] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 217
└─[ManufacturerSpecificCCGet]
02:29:32.153 SERIAL « [ACK] (0x06)
02:29:32.159 SERIAL « 0x0104011301e8 (6 bytes)
02:29:32.160 SERIAL » [ACK] (0x06)
02:29:32.162 DRIVER « [RES] [SendData]
was sent: true
02:29:33.653 SERIAL « 0x01180013d900009502be7f7f7f7f010103060400000202041415 (26 bytes)
02:29:33.653 SERIAL » [ACK] (0x06)
02:29:33.655 DRIVER « [REQ] [SendData]
callback id: 217
transmit status: OK
02:29:43.662 CNTRLR [Node 020] Interview attempt 3/5 failed, retrying in 15000 ms...
02:29:58.677 CNTRLR [Node 020] Beginning interview - last completed stage: NodeInfo
02:29:58.679 CNTRLR [Node 020] ManufacturerSpecificCC: doing a complete interview...
02:29:58.679 CNTRLR » [Node 020] querying manufacturer information...
02:29:58.690 SERIAL » 0x010900131402720425da7a (11 bytes)
02:29:58.691 DRIVER » [Node 020] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 218
└─[ManufacturerSpecificCCGet]
02:29:58.694 SERIAL « [ACK] (0x06)
02:29:58.700 SERIAL « 0x0104011301e8 (6 bytes)
02:29:58.701 SERIAL » [ACK] (0x06)
02:29:58.702 DRIVER « [RES] [SendData]
was sent: true
02:30:00.106 SERIAL « 0x01180013da00008d02bf7f7f7f7f01010306040000020204140f (26 bytes)
02:30:00.107 SERIAL » [ACK] (0x06)
02:30:00.108 DRIVER « [REQ] [SendData]
callback id: 218
transmit status: OK
02:30:10.115 CNTRLR [Node 020] Interview attempt 4/5 failed, retrying in 20000 ms...
02:30:30.131 CNTRLR [Node 020] Beginning interview - last completed stage: NodeInfo
02:30:30.133 CNTRLR [Node 020] ManufacturerSpecificCC: doing a complete interview...
02:30:30.133 CNTRLR » [Node 020] querying manufacturer information...
02:30:30.143 SERIAL » 0x010900131402720425db7b (11 bytes)
02:30:30.144 DRIVER » [Node 020] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 219
└─[ManufacturerSpecificCCGet]
02:30:30.149 SERIAL « [ACK] (0x06)
02:30:30.153 SERIAL « 0x0104011301e8 (6 bytes)
02:30:30.153 SERIAL » [ACK] (0x06)
02:30:30.154 DRIVER « [RES] [SendData]
was sent: true
02:30:31.628 SERIAL « 0x01180013db00009402be7f7f7f7f010103060400000202041416 (26 bytes)
02:30:31.629 SERIAL » [ACK] (0x06)
02:30:31.630 DRIVER « [REQ] [SendData]
callback id: 219
transmit status: OK
02:30:41.637 CNTRLR [Node 020] Failed all interview attempts, giving up.
About this issue
- Original URL
- State: closed
- Created 3 years ago
- Comments: 15 (8 by maintainers)
That pull seems to be more for ZWave+, this device id not ZWave+ compatible, since I used ZWavePcController v5.39.472.0 from Silicon Labs and zwave2mqtt, the openzwave version, with the same outcome I really suspect this is a door lock issue - it got stuck in a bad state - even the “How to Reset a Schlage Connect BE468 or BE469 Smart Lock” steps didn’t help - same steps are described in the lock manual.
No point in doing that. Try to re-interview and see if the problem goes away. If not, wait for me to fix it. If it does, don’t push the re-interview button again 😉