Closed nospam2k closed 1 year ago
marcus-j-davies
commented
1 year ago Hi @nospam2k
Please attach a driver log, set to debug (File)
The log file will be in /home/pi/.node-red
After turning on debug, recreate the bug, and attach the log file as is (please do not modify it)
nospam2k
commented
1 year ago OK so I will include the log file, but for completeness, what I did was start node on the command line. I let things settle a bit and then just move a node and deployed 3 times. Here is the dump from the command line of the whole thing including the final crash out.
pi@homectl:~/.node-red $ node-red
6 Jun 16:21:25 - [info]
Welcome to Node-RED
===================
6 Jun 16:21:25 - [info] Node-RED version: v3.0.2
6 Jun 16:21:25 - [info] Node.js version: v16.18.1
6 Jun 16:21:25 - [info] Linux 5.15.76-v8+ arm64 LE
6 Jun 16:21:28 - [info] Loading palette nodes
6 Jun 16:21:44 - [info] Settings file : /home/pi/.node-red/settings.js
6 Jun 16:21:44 - [info] HTTP Static : /home/pi/.node-red/public_html > /
6 Jun 16:21:44 - [info] Context store : 'default' [module=memory]
6 Jun 16:21:44 - [info] Context store : 'storeInFile' [module=localfilesystem]
6 Jun 16:21:44 - [info] User directory : /home/pi/.node-red
6 Jun 16:21:44 - [warn] Projects disabled : editorTheme.projects.enabled=false
6 Jun 16:21:44 - [info] Flows file : /home/pi/.node-red/homectl-flows.json
6 Jun 16:21:47 - [info] Server now running at https://127.0.0.1:8880/
6 Jun 16:21:47 - [info] Starting flows
16:21:48.863 DRIVER ███████╗ ██╗ ██╗ █████╗ ██╗ ██╗ ███████╗ ██╗ ███████╗
╚══███╔╝ ██║ ██║ ██╔══██╗ ██║ ██║ ██╔════╝ ██║ ██╔════╝
███╔╝ ██║ █╗ ██║ ███████║ ██║ ██║ █████╗ █████╗ ██║ ███████╗
███╔╝ ██║███╗██║ ██╔══██║ ╚██╗ ██╔╝ ██╔══╝ ╚════╝ ██ ██║ ╚════██║
███████╗ ╚███╔███╔╝ ██║ ██║ ╚████╔╝ ███████╗ ╚█████╔╝ ███████║
╚══════╝ ╚══╝╚══╝ ╚═╝ ╚═╝ ╚═══╝ ╚══════╝ ╚════╝ ╚══════╝
16:21:48.880 DRIVER version 10.23.1
16:21:48.887 DRIVER
16:21:48.892 DRIVER starting driver...
16:21:48.999 DRIVER opening serial port /dev/ttyACM0
6 Jun 16:21:49 - [info] Started flows
16:21:50.302 DRIVER serial port opened
16:21:50.309 SERIAL » 0x15 (1 bytes)
6 Jun 16:21:50 - [info] [mqtt-broker:Mqtt] Connected to broker: mqtt://localhost:1883
16:21:54.220 DRIVER loading configuration...
16:21:54.288 CONFIG version 10.23.0
6 Jun 16:21:59 - [info] [function:Send SyncState] Sync state ok
16:22:02.343 DRIVER beginning interview...
16:22:02.352 DRIVER added request handler for AddNodeToNetwork (0x4a)...
1 registered
16:22:02.358 DRIVER added request handler for RemoveNodeFromNetwork (0x4b)...
1 registered
16:22:02.361 DRIVER added request handler for ReplaceFailedNode (0x63)...
1 registered
16:22:02.366 CNTRLR querying controller IDs...
16:22:03.827 SERIAL » 0x01030020dc (5 bytes)
16:22:03.835 DRIVER » [REQ] [GetControllerId]
16:22:03.905 SERIAL « [ACK] (0x06)
16:22:03.971 SERIAL « 0x01080120e585b4ab01a8 (10 bytes)
16:22:03.991 SERIAL » [ACK] (0x06)
16:22:04.013 DRIVER « [RES] [GetControllerId]
home ID: 0xe585b4ab
own node ID: 1
16:22:04.119 CNTRLR received controller IDs:
home ID: 0xe585b4ab
own node ID: 1
16:22:04.126 CNTRLR querying API capabilities...
16:22:04.213 SERIAL » 0x01030007fb (5 bytes)
16:22:04.229 DRIVER » [REQ] [GetSerialApiCapabilities]
16:22:04.384 SERIAL « [ACK] (0x06)
16:22:04.407 SERIAL « 0x012b0107010000860101005afe81ff884f1f0000fb9f7da067000080008086000 (45 bytes)
000e87300000e0000600000fa
16:22:04.418 SERIAL » [ACK] (0x06)
16:22:04.427 DRIVER « [RES] [GetSerialApiCapabilities]
payload: 0x010000860101005afe81ff884f1f0000fb9f7da067000080008086000000e8730
0000e0000600000
16:22:04.470 CNTRLR received API capabilities:
firmware version: 1.0
manufacturer ID: 0x86
product type: 0x0101
product ID: 0x5a
supported functions:
· GetSerialApiInitData (0x02)
· SetApplicationNodeInformation (0x03)
· ApplicationCommand (0x04)
· GetControllerCapabilities (0x05)
· SetSerialApiTimeouts (0x06)
· GetSerialApiCapabilities (0x07)
· SoftReset (0x08)
· GetProtocolVersion (0x09)
· SetRFReceiveMode (0x10)
· UNKNOWN_FUNC_SET_SLEEP_MODE (0x11)
· FUNC_ID_ZW_SEND_NODE_INFORMATION (0x12)
· SendData (0x13)
· SendDataMulticast (0x14)
· GetControllerVersion (0x15)
· SendDataAbort (0x16)
· FUNC_ID_ZW_R_F_POWER_LEVEL_SET (0x17)
· UNKNOWN_FUNC_SEND_DATA_META (0x18)
· FUNC_ID_ZW_GET_RANDOM (0x1c)
· GetControllerId (0x20)
· UNKNOWN_FUNC_MEMORY_GET_BYTE (0x21)
· UNKNOWN_FUNC_MEMORY_PUT_BYTE (0x22)
· UNKNOWN_FUNC_MEMORY_GET_BUFFER (0x23)
· UNKNOWN_FUNC_MEMORY_PUT_BUFFER (0x24)
· EnterBootloader (0x27)
· GetNVMId (0x29)
· ExtNVMReadLongBuffer (0x2a)
· ExtNVMWriteLongBuffer (0x2b)
· ExtNVMReadLongByte (0x2c)
· ExtExtWriteLongByte (0x2d)
· GetNodeProtocolInfo (0x41)
· HardReset (0x42)
· FUNC_ID_ZW_REPLICATION_COMMAND_COMPLETE (0x44)
· FUNC_ID_ZW_REPLICATION_SEND_DATA (0x45)
· AssignReturnRoute (0x46)
· DeleteReturnRoute (0x47)
· RequestNodeNeighborUpdate (0x48)
· ApplicationUpdateRequest (0x49)
· AddNodeToNetwork (0x4a)
· RemoveNodeFromNetwork (0x4b)
· FUNC_ID_ZW_CREATE_NEW_PRIMARY (0x4c)
· FUNC_ID_ZW_CONTROLLER_CHANGE (0x4d)
· FUNC_ID_ZW_SET_LEARN_MODE (0x50)
· AssignSUCReturnRoute (0x51)
· FUNC_ID_ZW_REQUEST_NETWORK_UPDATE (0x53)
· SetSUCNodeId (0x54)
· DeleteSUCReturnRoute (0x55)
· GetSUCNodeId (0x56)
· UNKNOWN_FUNC_SEND_SUC_ID (0x57)
· FUNC_ID_ZW_EXPLORE_REQUEST_INCLUSION (0x5e)
· RequestNodeInfo (0x60)
· RemoveFailedNode (0x61)
· IsFailedNode (0x62)
· ReplaceFailedNode (0x63)
· UNKNOWN_FUNC_UNKNOWN_0x66 (0x66)
· UNKNOWN_FUNC_UNKNOWN_0x67 (0x67)
· GetRoutingInfo (0x80)
· UNKNOWN_FUNC_LOCK_ROUTE_RESPONSE (0x90)
· GetPriorityRoute (0x92)
· SetPriorityRoute (0x93)
· UNKNOWN_FUNC_UNKNOWN_0x98 (0x98)
· UNKNOWN_FUNC_UNKNOWN_0xB4 (0xb4)
· UNKNOWN_FUNC_WATCH_DOG_ENABLE (0xb6)
· UNKNOWN_FUNC_WATCH_DOG_DISABLE (0xb7)
· UNKNOWN_FUNC_WATCH_DOG_KICK (0xb8)
· UNKNOWN_FUNC_UNKNOWN_0xB9 (0xb9)
· UNKNOWN_FUNC_RF_POWERLEVEL_GET (0xba)
· UNKNOWN_FUNC_GET_LIBRARY_TYPE (0xbd)
· UNKNOWN_FUNC_SEND_TEST_FRAME (0xbe)
· UNKNOWN_FUNC_GET_PROTOCOL_STATUS (0xbf)
· UNKNOWN_FUNC_UNKNOWN_0xD2 (0xd2)
· UNKNOWN_FUNC_UNKNOWN_0xD3 (0xd3)
· UNKNOWN_FUNC_UNKNOWN_0xD4 (0xd4)
· undefined (0xee)
· UNKNOWN_FUNC_UNKNOWN_0xEF (0xef)
16:22:04.615 CNTRLR querying version info...
16:22:04.664 SERIAL » 0x01030015e9 (5 bytes)
16:22:04.668 DRIVER » [REQ] [GetControllerVersion]
16:22:04.680 SERIAL « [ACK] (0x06)
16:22:04.691 SERIAL « 0x011001155a2d5761766520332e3935000199 (18 bytes)
16:22:04.696 SERIAL » [ACK] (0x06)
16:22:04.702 DRIVER « [RES] [GetControllerVersion]
payload: 0x5a2d5761766520332e39350001
16:22:04.732 CNTRLR received version info:
controller type: Static Controller
library version: Z-Wave 3.95
16:22:04.735 CNTRLR querying protocol version info...
16:22:04.788 SERIAL » 0x01030009f5 (5 bytes)
16:22:04.792 DRIVER » [REQ] [GetProtocolVersion]
16:22:04.804 SERIAL « [ACK] (0x06)
16:22:04.813 SERIAL « 0x0107010900035f00ac (9 bytes)
16:22:04.820 SERIAL » [ACK] (0x06)
16:22:04.825 DRIVER « [RES] [GetProtocolVersion]
payload: 0x00035f00
16:22:04.864 CNTRLR received protocol version info:
protocol type: Z-Wave
protocol version: 3.95.0
16:22:04.872 CNTRLR supported Z-Wave features:
16:22:04.875 CNTRLR querying controller capabilities...
16:22:04.915 SERIAL » 0x01030005f9 (5 bytes)
16:22:04.918 DRIVER » [REQ] [GetControllerCapabilities]
16:22:04.930 SERIAL « [ACK] (0x06)
16:22:04.940 SERIAL « 0x010401051ce3 (6 bytes)
16:22:04.945 SERIAL » [ACK] (0x06)
16:22:04.952 DRIVER « [RES] [GetControllerCapabilities]
payload: 0x1c
16:22:05.006 CNTRLR received controller capabilities:
controller role: primary
is the SUC: true
started this network: true
SIS is present: true
was real primary: true
16:22:05.009 CNTRLR finding SUC...
16:22:05.063 SERIAL » 0x01030056aa (5 bytes)
16:22:05.067 DRIVER » [REQ] [GetSUCNodeId]
16:22:05.079 SERIAL « [ACK] (0x06)
16:22:05.093 SERIAL « 0x0104015601ad (6 bytes)
16:22:05.098 SERIAL » [ACK] (0x06)
16:22:05.104 DRIVER « [RES] [GetSUCNodeId]
payload: 0x01
16:22:05.148 CNTRLR This is the SUC
16:22:05.151 CNTRLR querying additional controller information...
16:22:05.194 SERIAL » 0x01030002fe (5 bytes)
16:22:05.199 DRIVER » [REQ] [GetSerialApiInitData]
16:22:05.211 SERIAL « [ACK] (0x06)
16:22:05.295 SERIAL « 0x0125010205081d030000000000000000000000000000000000000000000000000 (39 bytes)
00000000500cf
16:22:05.301 SERIAL » [ACK] (0x06)
16:22:05.309 DRIVER « [RES] [GetSerialApiInitData]
payload: 0x05081d03000000000000000000000000000000000000000000000000000000000
500
16:22:05.331 CNTRLR received additional controller information:
Z-Wave API version: 5 (legacy)
Z-Wave chip type: ZW050x
node type Controller
controller role: primary
controller is the SIS: true
controller supports timers: false
nodes in the network: 1, 2
16:22:05.384 DRIVER Cache file for homeId 0xe585b4ab found, attempting to restore the network from
cache...
16:22:06.147 CNTRLR [Node 001] Embedded device config loaded
16:22:06.445 CNTRLR [Node 002] Embedded device config loaded
16:22:06.454 DRIVER Restoring the network from cache was successful!
16:22:06.478 CNTRLR [Node 001] [Manufacturer Specific] manufacturerId: metadata updated
16:22:06.484 CNTRLR [Node 001] [Manufacturer Specific] productType: metadata updated
16:22:06.489 CNTRLR [Node 001] [Manufacturer Specific] productId: metadata updated
16:22:06.499 CNTRLR [Node 001] [~] [Manufacturer Specific] manufacturerId: 134 => 134
16:22:06.508 CNTRLR [Node 001] [~] [Manufacturer Specific] productType: 257 => 257
16:22:06.513 CNTRLR [Node 001] [~] [Manufacturer Specific] productId: 90 => 90
16:22:06.520 CNTRLR [Node 001] [Version] firmwareVersions: metadata updated
16:22:06.527 CNTRLR [Node 001] [~] [Version] firmwareVersions: 1.0 => 1.0
16:22:06.535 CNTRLR [Node 001] [Version] zWaveProtocolVersion: metadata updated
16:22:06.540 CNTRLR [Node 001] [~] [Version] zWaveProtocolVersion: "3.95.0" => "3.95.0"
16:22:06.545 CNTRLR [Node 001] [Version] sdkVersion: metadata updated
16:22:06.551 CNTRLR [Node 001] [~] [Version] sdkVersion: "6.51.2" => "6.51.2"
16:22:06.554 CNTRLR setting serial API timeouts: ack = 1000 ms, byte = 150 ms
16:22:06.609 SERIAL » 0x01050006640f97 (7 bytes)
16:22:06.613 DRIVER » [REQ] [SetSerialApiTimeouts]
payload: 0x640f
16:22:06.635 SERIAL « [ACK] (0x06)
16:22:06.644 SERIAL « 0x01050106640f96 (7 bytes)
16:22:06.648 SERIAL » [ACK] (0x06)
16:22:06.655 DRIVER « [RES] [SetSerialApiTimeouts]
payload: 0x640f
16:22:06.677 CNTRLR serial API timeouts overwritten. The old values were: ack = 1000 ms, byte = 15
0 ms
16:22:06.679 CNTRLR Interview completed
16:22:06.682 DRIVER Network key for S0 configured, enabling S0 security manager...
16:22:06.690 DRIVER No network key for S2 configured, communication with secure (S2) devices won't
work!
16:22:06.692 DRIVER driver ready
16:22:06.711 CNTRLR [Node 001] The node is alive.
16:22:06.716 CNTRLR [Node 001] The node is ready to be used
16:22:06.722 CNTRLR » [Node 002] pinging the node...
16:22:07.344 SERIAL » 0x010800130201002501c3 (10 bytes)
16:22:07.353 DRIVER » [Node 002] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 1
└─[NoOperationCC]
16:22:07.376 SERIAL « [ACK] (0x06)
16:22:07.386 SERIAL « 0x0104011301e8 (6 bytes)
16:22:07.391 SERIAL » [ACK] (0x06)
16:22:07.398 DRIVER « [RES] [SendData]
was sent: true
16:22:09.814 SERIAL « 0x01070013010000f61c (9 bytes)
16:22:09.820 SERIAL » [ACK] (0x06)
16:22:09.826 DRIVER « [REQ] [SendData]
callback id: 1
transmit status: OK
16:22:09.851 CNTRLR [Node 002] The node is alive.
16:22:09.857 CNTRLR [Node 002] The node is ready to be used
16:22:09.861 CNTRLR All nodes are ready to be used
16:22:09.950 CNTRLR « [Node 002] ping successful
16:22:10.690 DRIVER Usage statistics sent - next transmission scheduled in 23 hours.
16:22:13.758 SERIAL » 0x010900130202984025021a (11 bytes)
16:22:13.762 DRIVER » [Node 002] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 2
└─[SecurityCCNonceGet]
16:22:13.907 SERIAL « [ACK] (0x06)
16:22:13.915 SERIAL « 0x0104011301e8 (6 bytes)
16:22:13.918 SERIAL » [ACK] (0x06)
16:22:13.923 DRIVER « [RES] [SendData]
was sent: true
16:22:16.153 SERIAL « 0x01070013020000ee07 (9 bytes)
16:22:16.157 SERIAL » [ACK] (0x06)
16:22:16.163 DRIVER « [REQ] [SendData]
callback id: 2
transmit status: OK
16:22:19.697 CNTRLR [Node 002] Timed out while waiting for a response from the node (ZW0201)
16:22:19.742 SERIAL » 0x010900130202984025031b (11 bytes)
16:22:19.748 DRIVER » [Node 002] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 3
└─[SecurityCCNonceGet]
16:22:19.756 SERIAL « [ACK] (0x06)
16:22:19.764 SERIAL « 0x0104011301e8 (6 bytes)
16:22:19.768 SERIAL » [ACK] (0x06)
16:22:19.772 DRIVER « [RES] [SendData]
was sent: true
16:22:21.046 SERIAL « 0x01070013030000826a (9 bytes)
16:22:21.050 SERIAL » [ACK] (0x06)
16:22:21.055 DRIVER « [REQ] [SendData]
callback id: 3
transmit status: OK
16:22:21.155 SERIAL « 0x0110000400020a988096facc2e0f0c876b9a (18 bytes)
16:22:21.168 SERIAL » [ACK] (0x06)
16:22:21.183 DRIVER « [Node 002] [REQ] [ApplicationCommand]
└─[SecurityCCNonceReport]
nonce: 0x96facc2e0f0c876b
16:22:21.221 SERIAL » 0x011d00130216988142463a19f5304e1b9736fd9688d70ef5d0ea237c250461 (31 bytes)
16:22:21.226 DRIVER » [Node 002] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 4
└─[SecurityCCCommandEncapsulation]
│ nonce id: 150
└─[BatteryCCGet]
16:22:21.241 SERIAL « [ACK] (0x06)
16:22:21.249 SERIAL « 0x0104011301e8 (6 bytes)
16:22:21.252 SERIAL » [ACK] (0x06)
16:22:21.257 DRIVER « [RES] [SendData]
was sent: true
16:22:22.483 SERIAL « 0x010700130400007d92 (9 bytes)
16:22:22.486 SERIAL » [ACK] (0x06)
16:22:22.492 DRIVER « [REQ] [SendData]
callback id: 4
transmit status: OK
16:22:26.172 CNTRLR [Node 002] Timed out while waiting for a response from the node (ZW0201)
16:22:26.197 SERIAL » 0x010900130202984025051d (11 bytes)
16:22:26.203 DRIVER » [Node 002] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 5
└─[SecurityCCNonceGet]
16:22:26.212 SERIAL « [ACK] (0x06)
16:22:26.221 SERIAL « 0x0104011301e8 (6 bytes)
16:22:26.225 SERIAL » [ACK] (0x06)
16:22:26.229 DRIVER « [RES] [SendData]
was sent: true
16:22:26.266 SERIAL « 0x0107001305000006e8 (9 bytes)
16:22:26.270 SERIAL » [ACK] (0x06)
16:22:26.275 DRIVER « [REQ] [SendData]
callback id: 5
transmit status: OK
16:22:26.828 SERIAL « 0x0108000400020298402b (10 bytes)
16:22:26.833 SERIAL » [ACK] (0x06)
16:22:26.840 DRIVER « [Node 002] [REQ] [ApplicationCommand]
└─[SecurityCCNonceGet]
16:22:27.015 SERIAL » 0x01110013020a98807ba07c9a2401b6f40506b4 (19 bytes)
16:22:27.019 DRIVER » [Node 002] [REQ] [SendData]
│ transmit options: 0x05
│ callback id: 6
└─[SecurityCCNonceReport]
nonce: 0x7ba07c9a2401b6f4
16:22:27.036 SERIAL « [ACK] (0x06)
16:22:27.044 SERIAL « 0x0104011301e8 (6 bytes)
16:22:27.047 SERIAL » [ACK] (0x06)
16:22:27.052 DRIVER « [RES] [SendData]
was sent: true
16:22:27.130 SERIAL « 0x010700130600000be6 (9 bytes)
16:22:27.134 SERIAL » [ACK] (0x06)
16:22:27.139 DRIVER « [REQ] [SendData]
callback id: 6
transmit status: OK
16:22:27.192 SERIAL « 0x0110000400020a98804b66787c4687670672 (18 bytes)
16:22:27.198 SERIAL » [ACK] (0x06)
16:22:27.204 DRIVER « [Node 002] [REQ] [ApplicationCommand]
└─[SecurityCCNonceReport]
nonce: 0x4b66787c46876706
16:22:27.239 SERIAL » 0x011d001302169881df7cee48a66bfe804c54274bfa06884addf7b994250725 (31 bytes)
16:22:27.255 DRIVER » [Node 002] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 7
└─[SecurityCCCommandEncapsulation]
│ nonce id: 75
└─[DoorLockCCOperationGet]
16:22:27.266 SERIAL « [ACK] (0x06)
16:22:27.275 SERIAL « 0x0104011301e8 (6 bytes)
16:22:27.279 SERIAL » [ACK] (0x06)
16:22:27.284 DRIVER « [RES] [SendData]
was sent: true
16:22:27.298 SERIAL « 0x0107001307000003ef (9 bytes)
16:22:27.302 SERIAL » [ACK] (0x06)
16:22:27.307 DRIVER « [REQ] [SendData]
callback id: 7
transmit status: OK
16:22:27.459 SERIAL « 0x011d0004000217988138d7429bc4e1a8c0766133cc7b5ea33fbca1fe00a98a (31 bytes)
16:22:27.468 SERIAL » [ACK] (0x06)
16:22:27.485 CNTRLR [Node 002] [~] [Battery] level: 60 => 60 [Endpoint 0]
16:22:27.497 CNTRLR [Node 002] [~] [Battery] isLow: false => false [Endpoint 0]
16:22:27.508 DRIVER « [Node 002] [REQ] [ApplicationCommand]
└─[SecurityCCCommandEncapsulation]
│ sequenced: false
└─[BatteryCCReport]
level: 60
is low: false
16:22:28.532 CNTRLR [Node 002] Timed out while waiting for a response from the node (ZW0201)
16:22:28.548 SERIAL » 0x0109001302029840250810 (11 bytes)
16:22:28.551 DRIVER » [Node 002] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 8
└─[SecurityCCNonceGet]
16:22:28.559 SERIAL « [ACK] (0x06)
16:22:28.566 SERIAL « 0x0104011301e8 (6 bytes)
16:22:28.569 SERIAL » [ACK] (0x06)
16:22:28.573 DRIVER « [RES] [SendData]
was sent: true
16:22:28.630 SERIAL « 0x0107001308000008eb (9 bytes)
16:22:28.633 SERIAL » [ACK] (0x06)
16:22:28.638 DRIVER « [REQ] [SendData]
callback id: 8
transmit status: OK
16:22:28.656 SERIAL « 0x0110000400020a9880522183f85822508b52 (18 bytes)
16:22:28.661 SERIAL » [ACK] (0x06)
16:22:28.671 DRIVER « [Node 002] [REQ] [ApplicationCommand]
└─[SecurityCCNonceReport]
nonce: 0x522183f85822508b
16:22:28.706 SERIAL » 0x011d00130216988153be7a887298ed1aba7ebe52aa5778b27025c6f92509a7 (31 bytes)
16:22:28.711 DRIVER » [Node 002] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 9
└─[SecurityCCCommandEncapsulation]
│ nonce id: 82
└─[BatteryCCGet]
16:22:28.719 SERIAL « [ACK] (0x06)
16:22:28.729 SERIAL « 0x0104011301e8 (6 bytes)
16:22:28.732 SERIAL » [ACK] (0x06)
16:22:28.736 DRIVER « [RES] [SendData]
was sent: true
16:22:28.795 SERIAL « 0x0107001309000008ea (9 bytes)
16:22:28.798 SERIAL » [ACK] (0x06)
16:22:28.802 DRIVER « [REQ] [SendData]
callback id: 9
transmit status: OK
16:22:30.094 CNTRLR [Node 002] Timed out while waiting for a response from the node (ZW0201)
16:22:30.122 SERIAL » 0x0109001302029840250a12 (11 bytes)
16:22:30.126 DRIVER » [Node 002] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 10
└─[SecurityCCNonceGet]
16:22:30.135 SERIAL « [ACK] (0x06)
16:22:30.143 SERIAL « 0x0104011301e8 (6 bytes)
16:22:30.146 SERIAL » [ACK] (0x06)
16:22:30.151 DRIVER « [RES] [SendData]
was sent: true
16:22:30.176 SERIAL « 0x010700130a000005e4 (9 bytes)
16:22:30.179 SERIAL » [ACK] (0x06)
16:22:30.183 DRIVER « [REQ] [SendData]
callback id: 10
transmit status: OK
16:22:30.585 SERIAL « 0x0110000400020a9880218c8050edf2239329 (18 bytes)
16:22:30.589 SERIAL » [ACK] (0x06)
16:22:30.594 DRIVER « [Node 002] [REQ] [ApplicationCommand]
└─[SecurityCCNonceReport]
nonce: 0x218c8050edf22393
16:22:30.620 SERIAL » 0x011d0013021698817ba3c2c3244bb616edb69121f082551d859aa040250bea (31 bytes)
16:22:30.623 DRIVER » [Node 002] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 11
└─[SecurityCCCommandEncapsulation]
│ nonce id: 33
└─[BatteryCCGet]
16:22:30.639 SERIAL « [ACK] (0x06)
16:22:30.646 SERIAL « 0x0104011301e8 (6 bytes)
16:22:30.649 SERIAL » [ACK] (0x06)
16:22:30.654 DRIVER « [RES] [SendData]
was sent: true
16:22:30.696 SERIAL « 0x0108000400020298402b (10 bytes)
16:22:30.700 SERIAL » [ACK] (0x06)
16:22:30.705 DRIVER « [Node 002] [REQ] [ApplicationCommand]
└─[SecurityCCNonceGet]
16:22:34.362 SERIAL « 0x010700130b00017594 (9 bytes)
16:22:34.365 SERIAL » [ACK] (0x06)
16:22:34.370 DRIVER « [REQ] [SendData]
callback id: 11
transmit status: OK
16:22:34.390 SERIAL » 0x01110013020a9880c65f4c3052ec7683050c4a (19 bytes)
16:22:34.393 DRIVER » [Node 002] [REQ] [SendData]
│ transmit options: 0x05
│ callback id: 12
└─[SecurityCCNonceReport]
nonce: 0xc65f4c3052ec7683
16:22:34.407 SERIAL « [ACK] (0x06)
16:22:34.415 SERIAL « 0x0104011301e8 (6 bytes)
16:22:34.418 SERIAL » [ACK] (0x06)
16:22:34.422 DRIVER « [RES] [SendData]
was sent: true
16:22:36.875 SERIAL « 0x010700130c0000f710 (9 bytes)
16:22:36.878 SERIAL » [ACK] (0x06)
16:22:36.882 DRIVER « [REQ] [SendData]
callback id: 12
transmit status: OK
16:22:36.960 SERIAL « 0x011d000400021798810a5c69d14e62a861e149be93c6fefc0a26487faab6a7 (31 bytes)
16:22:36.970 DRIVER Dropping message with invalid payload
16:22:36.974 DRIVER « [Node 002] [REQ] [ApplicationCommand]
└─[SecurityCCCommandEncapsulation] [INVALID]
error: Nonce 0xc6 expired, cannot decode security encapsulated command.
16:22:36.977 SERIAL » [ACK] (0x06)
16:22:39.279 CNTRLR [Node 002] Timed out while waiting for a response from the node (ZW0201)
16:22:39.325 SERIAL » 0x0109001302029840250d15 (11 bytes)
16:22:39.328 DRIVER » [Node 002] [REQ] [SendData]
│ transmit options: 0x25
│ callback id: 13
└─[SecurityCCNonceGet]
16:22:39.338 SERIAL « [ACK] (0x06)
16:22:39.347 SERIAL « 0x0104011301e8 (6 bytes)
16:22:39.350 SERIAL » [ACK] (0x06)
16:22:39.355 DRIVER « [RES] [SendData]
was sent: true
16:22:41.824 SERIAL « 0x010700130d0000fa1c (9 bytes)
16:22:41.828 SERIAL » [ACK] (0x06)
16:22:41.832 DRIVER « [REQ] [SendData]
callback id: 13
transmit status: OK
16:22:45.396 CNTRLR [Node 002] Timed out while waiting for a response from the node (ZW0201)
16:22:46.220 SERIAL « 0x0110000400020a988097926c5c058b1d3f62 (18 bytes)
16:22:46.224 SERIAL » [ACK] (0x06)
16:22:46.229 DRIVER « [Node 002] [REQ] [ApplicationCommand]
└─[SecurityCCNonceReport]
nonce: 0x97926c5c058b1d3f
16:22:46.530 SERIAL « 0x0110000400020a9880848e9a52cf1bc186aa (18 bytes)
16:22:46.535 SERIAL » [ACK] (0x06)
16:22:46.540 DRIVER « [Node 002] [REQ] [ApplicationCommand]
└─[SecurityCCNonceReport]
nonce: 0x848e9a52cf1bc186
6 Jun 16:23:00 - [info] Stopping flows
16:23:00.792 DRIVER destroying driver instance...
16:23:00.931 DRIVER driver instance destroyed
6 Jun 16:23:00 - [info] Stopped flows
6 Jun 16:23:00 - [info] Updated flows
6 Jun 16:23:01 - [info] Starting flows
16:23:01.120 DRIVER ███████╗ ██╗ ██╗ █████╗ ██╗ ██╗ ███████╗ ██╗ ███████╗
╚══███╔╝ ██║ ██║ ██╔══██╗ ██║ ██║ ██╔════╝ ██║ ██╔════╝
███╔╝ ██║ █╗ ██║ ███████║ ██║ ██║ █████╗ █████╗ ██║ ███████╗
███╔╝ ██║███╗██║ ██╔══██║ ╚██╗ ██╔╝ ██╔══╝ ╚════╝ ██ ██║ ╚════██║
███████╗ ╚███╔███╔╝ ██║ ██║ ╚████╔╝ ███████╗ ╚█████╔╝ ███████║
╚══════╝ ╚══╝╚══╝ ╚═╝ ╚═╝ ╚═══╝ ╚══════╝ ╚════╝ ╚══════╝
16:23:01.125 DRIVER version 10.23.1
16:23:01.127 DRIVER
16:23:01.129 DRIVER starting driver...
16:23:01.146 DRIVER opening serial port /dev/ttyACM0
6 Jun 16:23:01 - [info] Started flows
16:23:02.027 DRIVER serial port opened
16:23:02.030 SERIAL » 0x15 (1 bytes)
6 Jun 16:23:02 - [info] [mqtt-broker:Mqtt] Connected to broker: mqtt://localhost:1883
16:23:05.631 DRIVER loading configuration...
16:23:06.240 CONFIG version 10.23.0
6 Jun 16:23:11 - [info] Stopping flows
16:23:11.037 DRIVER destroying driver instance...
16:23:11.102 DRIVER driver instance destroyed
6 Jun 16:23:11 - [info] Stopped flows
6 Jun 16:23:11 - [info] Updated flows
6 Jun 16:23:11 - [info] Starting flows
16:23:11.275 DRIVER ███████╗ ██╗ ██╗ █████╗ ██╗ ██╗ ███████╗ ██╗ ███████╗
╚══███╔╝ ██║ ██║ ██╔══██╗ ██║ ██║ ██╔════╝ ██║ ██╔════╝
███╔╝ ██║ █╗ ██║ ███████║ ██║ ██║ █████╗ █████╗ ██║ ███████╗
███╔╝ ██║███╗██║ ██╔══██║ ╚██╗ ██╔╝ ██╔══╝ ╚════╝ ██ ██║ ╚════██║
███████╗ ╚███╔███╔╝ ██║ ██║ ╚████╔╝ ███████╗ ╚█████╔╝ ███████║
╚══════╝ ╚══╝╚══╝ ╚═╝ ╚═╝ ╚═══╝ ╚══════╝ ╚════╝ ╚══════╝
16:23:11.283 DRIVER version 10.23.1
16:23:11.284 DRIVER
16:23:11.286 DRIVER starting driver...
16:23:11.300 DRIVER opening serial port /dev/ttyACM0
6 Jun 16:23:11 - [info] Started flows
16:23:12.076 DRIVER serial port opened
16:23:12.079 SERIAL » 0x15 (1 bytes)
6 Jun 16:23:12 - [info] [mqtt-broker:Mqtt] Connected to broker: mqtt://localhost:1883
16:23:15.588 DRIVER loading configuration...
16:23:16.046 CONFIG version 10.23.0
6 Jun 16:23:20 - [info] Stopping flows
16:23:20.847 DRIVER destroying driver instance...
16:23:20.893 DRIVER driver instance destroyed
6 Jun 16:23:20 - [info] Stopped flows
6 Jun 16:23:20 - [info] Updated flows
6 Jun 16:23:20 - [info] Starting flows
16:23:21.038 DRIVER ███████╗ ██╗ ██╗ █████╗ ██╗ ██╗ ███████╗ ██╗ ███████╗
╚══███╔╝ ██║ ██║ ██╔══██╗ ██║ ██║ ██╔════╝ ██║ ██╔════╝
███╔╝ ██║ █╗ ██║ ███████║ ██║ ██║ █████╗ █████╗ ██║ ███████╗
███╔╝ ██║███╗██║ ██╔══██║ ╚██╗ ██╔╝ ██╔══╝ ╚════╝ ██ ██║ ╚════██║
███████╗ ╚███╔███╔╝ ██║ ██║ ╚████╔╝ ███████╗ ╚█████╔╝ ███████║
╚══════╝ ╚══╝╚══╝ ╚═╝ ╚═╝ ╚═══╝ ╚══════╝ ╚════╝ ╚══════╝
16:23:21.040 DRIVER version 10.23.1
16:23:21.042 DRIVER
16:23:21.044 DRIVER starting driver...
16:23:21.063 DRIVER opening serial port /dev/ttyACM0
6 Jun 16:23:21 - [info] Started flows
16:23:21.837 DRIVER serial port opened
16:23:21.840 SERIAL » 0x15 (1 bytes)
6 Jun 16:23:21 - [info] [mqtt-broker:Mqtt] Connected to broker: mqtt://localhost:1883
16:23:25.416 DRIVER loading configuration...
16:23:26.202 CONFIG version 10.23.0
6 Jun 16:23:33 - [error] [zwave-js:ZWave Controller] ZWaveError: Failed to initialize the driver: ZWaveError: The driver is not ready or has been destroyed (ZW0103)
at Driver.ensureReady (/home/pi/.node-red/node_modules/zwave-js/src/lib/driver/Driver.ts:2718:10)
at Driver.sendMessage (/home/pi/.node-red/node_modules/zwave-js/src/lib/driver/Driver.ts:4242:8)
at ZWaveController.identify (/home/pi/.node-red/node_modules/zwave-js/src/lib/controller/Controller.ts:913:33)
at Driver.initializeControllerAndNodes (/home/pi/.node-red/node_modules/zwave-js/src/lib/driver/Driver.ts:1363:26)
at Immediate.<anonymous> (/home/pi/.node-red/node_modules/zwave-js/src/lib/driver/Driver.ts:1169:16) (ZW0100)
6 Jun 16:23:33 - [red] Uncaught Exception:
6 Jun 16:23:33 - [error] TypeError: Cannot read properties of undefined (reading 'Unregister')
at Driver.<anonymous> (/home/pi/.node-red/node_modules/node-red-contrib-zwave-js/zwave-js/zwave-js.js:1941:10)
at Driver.emit (node:events:513:28)
at Immediate.<anonymous> (/home/pi/.node-red/node_modules/zwave-js/src/lib/driver/Driver.ts:1184:10)
pi@homectl:~/.node-red $ Ok, this seems to be a bug in the way I am clearing up driver instances.
Its related to a recovery mechanism, this mechanism hasn't had a lot of testing (It was added to handle unexpected USB ZWave stick removals).
There maybe same race conditions I am not handling.
V9 of the module (still in the works), has had this recovery mechanism pulled, as its more trouble then its worth currently.
@AlCalzone, I think this is my end, as I cant see any fixes related to this post version 10.23.1. unless you see something In the logs that disproves otherwise?
AlCalzone
commented
1 year ago I followed the stack trace to see what's happening there. Either the serialport disconnected or the driver was destroyed (likely externally) in the time it took to read the configuration (roughly 8s it seems).
marcus-j-davies
commented
1 year ago @nospam2k
I think this is timing, a redeploy maybe happening as the driver is still be loaded, and I destroy the driver on a redeploy (as one should).
It shouldn't occur in normal running, but I'll look to improve this for V9.
stale[bot]
commented
1 year ago This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 7 days if no further activity occurs.
What happened?
I get this every now and then when I'm doing something that requires a deploy.
How to reproduce?
Usually only happens with multiple deploys.
Version
v8.1.0
Node-RED Version
v3.0.2
What hardware are you seeing the problem on?
Raspberry Pi
Relevant Z-Wave-JS log as a text file
No response