I’m trying to replace an old Z-Stick 5 that is failing with a Z-Stick 10. Openhab 4.3.3 is unable to discover devices that I’m trying to pair. I’m getting the warnings below.
2025-03-05 19:47:40.421 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 1: Device discovery could not resolve to a thingType! Manufacturer data not known.
2025-03-05 19:47:40.426 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery could not resolve to a thingType! Manufacturer data not known.
These devices are old Z-wave devices that discover just fine with my my Z-Stick 5. I’m curious if anyone else has got the Z-Stick 10 to work with Openhab. Any help would be appreciated. Below are the Full Z-wave logs. I tried a couple of times during the log period below. The first try the log level was set for DEBUG and the second try it was set for TRACE.
2025-03-05 19:52:33.941 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:64d7c7f7c4
2025-03-05 19:52:33.942 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeDone
2025-03-05 19:52:33.942 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2025-03-05 19:52:33.942 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2025-03-05 19:52:33.942 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:64d7c7f7c4
2025-03-05 19:52:33.942 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
2025-03-05 19:52:33.943 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2025-03-05 19:52:33.943 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2025-03-05 19:52:33.944 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:false.
2025-03-05 19:52:33.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 24 to queue - size 1
2025-03-05 19:52:33.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2025-03-05 19:52:33.944 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 81 09 38
2025-03-05 19:52:33.945 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 81 09 38
2025-03-05 19:52:33.958 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2025-03-05 19:52:33.958 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 24: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 9
2025-03-05 19:52:33.958 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:5767f857b9
2025-03-05 19:52:33.959 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do
2025-03-05 19:52:33.959 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:5767f857b9
2025-03-05 19:52:33.959 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
2025-03-05 19:52:33.959 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2025-03-05 19:52:33.960 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2025-03-05 19:52:33.960 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true.
2025-03-05 19:52:33.960 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 25 to queue - size 1
2025-03-05 19:52:33.960 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2025-03-05 19:52:33.960 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 0A 7B
2025-03-05 19:52:33.961 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 0A 7B
2025-03-05 19:52:33.963 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2025-03-05 19:52:33.963 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:52:33.963 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:52:33.963 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2025-03-05 19:52:33.963 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2025-03-05 19:52:33.964 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2025-03-05 19:52:33.966 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 4A 0A 07 00 00 00 B0
2025-03-05 19:52:33.970 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2025-03-05 19:52:33.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 25: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 10
2025-03-05 19:52:33.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:52:33.973 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=10, payload=0A 07 00 00 00
2025-03-05 19:52:33.973 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=10, payload=0A 07 00 00 00
2025-03-05 19:52:33.973 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 25: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 10
2025-03-05 19:52:33.973 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2025-03-05 19:52:33.973 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 25: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 10
2025-03-05 19:52:33.974 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 25: (Callback 10)
2025-03-05 19:52:33.974 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2025-03-05 19:52:33.974 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 25: callback 10
2025-03-05 19:52:33.974 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=10, payload=0A 07 00 00 00
2025-03-05 19:52:33.974 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Failed.
2025-03-05 19:52:33.974 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeFail
2025-03-05 19:52:33.974 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2025-03-05 19:52:33.974 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 26 to queue - size 1
2025-03-05 19:52:33.975 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:52:33.975 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 25: Transaction CANCELLED
2025-03-05 19:52:33.975 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: CANCEL while sending message. Requeueing - 2 attempts left!
2025-03-05 19:52:33.975 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 25: Transaction RESET with 2 retries remaining.
2025-03-05 19:52:33.975 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 25 to queue - size 2
2025-03-05 19:52:33.975 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2025-03-05 19:52:33.975 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 0B 7A
2025-03-05 19:52:33.975 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 0B 7A
2025-03-05 19:52:33.978 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2025-03-05 19:52:33.978 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:52:33.980 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 4A 0B 07 00 00 00 B1
2025-03-05 19:52:33.986 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2025-03-05 19:52:33.986 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 25: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 11
2025-03-05 19:52:33.986 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 25: Transaction not completed
2025-03-05 19:52:33.986 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:52:33.986 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 25: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 11
2025-03-05 19:52:33.986 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2025-03-05 19:52:33.987 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2025-03-05 19:52:33.987 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:52:33.989 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=11, payload=0B 07 00 00 00
2025-03-05 19:52:33.989 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=11, payload=0B 07 00 00 00
2025-03-05 19:52:33.989 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 25: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 11
2025-03-05 19:52:33.989 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2025-03-05 19:52:33.990 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 25: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 11
2025-03-05 19:52:33.990 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 25: (Callback 11)
2025-03-05 19:52:33.990 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2025-03-05 19:52:33.990 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 25: callback 11
2025-03-05 19:52:33.990 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=11, payload=0B 07 00 00 00
2025-03-05 19:52:33.990 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Failed.
2025-03-05 19:52:33.990 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeFail, new event IncludeFail
2025-03-05 19:52:33.990 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2025-03-05 19:52:33.990 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Transaction already in queue - removed original
2025-03-05 19:52:33.991 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 27 to queue - size 1
2025-03-05 19:52:33.991 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:52:33.991 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 25: Transaction CANCELLED
2025-03-05 19:52:33.991 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: CANCEL while sending message. Requeueing - 1 attempts left!
2025-03-05 19:52:33.991 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 25: Transaction RESET with 1 retries remaining.
2025-03-05 19:52:33.991 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 25 to queue - size 2
2025-03-05 19:52:33.991 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2025-03-05 19:52:33.991 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 0C 7D
2025-03-05 19:52:33.992 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 0C 7D
2025-03-05 19:52:33.994 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2025-03-05 19:52:33.994 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:52:33.996 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 4A 0C 07 00 00 00 B6
2025-03-05 19:52:34.002 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2025-03-05 19:52:34.002 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 25: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 12
2025-03-05 19:52:34.002 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 25: Transaction not completed
2025-03-05 19:52:34.002 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:52:34.002 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 25: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 12
2025-03-05 19:52:34.002 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2025-03-05 19:52:34.003 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2025-03-05 19:52:34.003 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:52:34.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=12, payload=0C 07 00 00 00
2025-03-05 19:52:34.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=12, payload=0C 07 00 00 00
2025-03-05 19:52:34.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 25: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 12
2025-03-05 19:52:34.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2025-03-05 19:52:34.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 25: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 12
2025-03-05 19:52:34.006 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 25: (Callback 12)
2025-03-05 19:52:34.006 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2025-03-05 19:52:34.006 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 25: callback 12
2025-03-05 19:52:34.006 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=12, payload=0C 07 00 00 00
2025-03-05 19:52:34.006 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Failed.
2025-03-05 19:52:34.006 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeFail, new event IncludeFail
2025-03-05 19:52:34.006 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2025-03-05 19:52:34.006 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Transaction already in queue - removed original
2025-03-05 19:52:34.007 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 28 to queue - size 1
2025-03-05 19:52:34.007 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:52:34.007 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 25: Transaction CANCELLED
2025-03-05 19:52:34.007 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Retry count exceeded. Discarding message: TID 25: [CANCELLED] priority=Controller, requiresResponse=true, callback: 12
2025-03-05 19:52:34.007 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 25: Transaction completed
2025-03-05 19:52:34.007 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:25 CANCELLED
2025-03-05 19:52:34.007 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2025-03-05 19:52:34.008 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2025-03-05 19:52:34.008 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 0D B8
2025-03-05 19:52:34.008 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 0D B8
2025-03-05 19:52:34.010 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2025-03-05 19:52:34.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:52:34.013 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 4A 0D 06 00 00 00 B6
2025-03-05 19:52:34.018 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2025-03-05 19:52:34.018 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 28: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 13
2025-03-05 19:52:34.018 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:52:34.019 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 28: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 13
2025-03-05 19:52:34.019 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2025-03-05 19:52:34.019 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2025-03-05 19:52:34.019 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:52:34.021 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=13, payload=0D 06 00 00 00
2025-03-05 19:52:34.021 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=13, payload=0D 06 00 00 00
2025-03-05 19:52:34.022 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 28: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 13
2025-03-05 19:52:34.022 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2025-03-05 19:52:34.022 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 28: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 13
2025-03-05 19:52:34.022 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 28: (Callback 13)
2025-03-05 19:52:34.022 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2025-03-05 19:52:34.022 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 28: callback 13
2025-03-05 19:52:34.022 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=13, payload=0D 06 00 00 00
2025-03-05 19:52:34.023 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
2025-03-05 19:52:34.023 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeFail, new event IncludeDone
2025-03-05 19:52:34.023 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2025-03-05 19:52:34.024 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 29 to queue - size 1
2025-03-05 19:52:34.024 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:52:34.024 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2025-03-05 19:52:34.024 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2025-03-05 19:52:34.024 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 28: Advanced to DONE
2025-03-05 19:52:34.024 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 6ms
2025-03-05 19:52:34.024 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 28: Transaction completed
2025-03-05 19:52:34.024 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:28 DONE
2025-03-05 19:52:34.025 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2025-03-05 19:52:34.025 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2025-03-05 19:52:34.025 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5
2025-03-05 19:52:34.025 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5
2025-03-05 19:52:34.027 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2025-03-05 19:52:34.027 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:52:34.039 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2025-03-05 19:52:34.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 29: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2025-03-05 19:52:34.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:52:34.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 29: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2025-03-05 19:52:34.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2025-03-05 19:52:34.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2025-03-05 19:52:34.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:52:34.451 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave inclusion controller finalised
2025-03-05 19:52:35.970 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 1: Device discovery completed
2025-03-05 19:52:35.973 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 1: Device discovery could not resolve to a thingType! Manufacturer data not known.
2025-03-05 19:52:35.974 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery completed
2025-03-05 19:52:35.977 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery could not resolve to a thingType! Manufacturer data not known.
2025-03-05 19:52:38.959 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 24: Timeout at state WAIT_REQUEST. 3 retries remaining.
2025-03-05 19:52:38.959 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 24: Transaction is current transaction, so clearing!!!!!
2025-03-05 19:52:38.959 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 24: Transaction CANCELLED
2025-03-05 19:52:38.959 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:24 CANCELLED
2025-03-05 19:52:38.959 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2025-03-05 19:52:39.040 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 29: Timeout at state WAIT_REQUEST. 3 retries remaining.
2025-03-05 19:52:39.040 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 29: Transaction is current transaction, so clearing!!!!!
2025-03-05 19:52:39.040 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 29: Transaction CANCELLED
2025-03-05 19:52:39.040 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:29 CANCELLED
2025-03-05 19:52:39.040 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2025-03-05 19:53:33.942 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:64d7c7f7c4
2025-03-05 19:53:33.943 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeSent
2025-03-05 19:53:33.943 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2025-03-05 19:53:33.943 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 30 to queue - size 1
2025-03-05 19:53:33.943 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2025-03-05 19:53:33.943 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 0F BA
2025-03-05 19:53:33.943 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 0F BA
2025-03-05 19:53:33.954 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2025-03-05 19:53:33.954 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 30: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 15
2025-03-05 19:53:33.959 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:5767f857b9
2025-03-05 19:53:33.959 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do
2025-03-05 19:53:38.954 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 30: Timeout at state WAIT_REQUEST. 3 retries remaining.
2025-03-05 19:53:38.954 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 30: Transaction is current transaction, so clearing!!!!!
2025-03-05 19:53:38.954 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 30: Transaction CANCELLED
2025-03-05 19:53:38.954 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:30 CANCELLED
2025-03-05 19:53:38.955 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2025-03-05 19:53:48.954 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion timer at IncludeDone
2025-03-05 19:55:12.503 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave inclusion controller finalised
2025-03-05 19:58:04.409 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:64d7c7f7c4
2025-03-05 19:58:04.410 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeDone
2025-03-05 19:58:04.410 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2025-03-05 19:58:04.410 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2025-03-05 19:58:04.410 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:64d7c7f7c4
2025-03-05 19:58:04.410 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
2025-03-05 19:58:04.410 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2025-03-05 19:58:04.411 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2025-03-05 19:58:04.411 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:false.
2025-03-05 19:58:04.411 [TRACE] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to priority controller queue
2025-03-05 19:58:04.411 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 31 to queue - size 1
2025-03-05 19:58:04.411 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2025-03-05 19:58:04.412 [TRACE] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
2025-03-05 19:58:04.412 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating empty message of class = AddNodeToNetwork (0x4a), type = Request
2025-03-05 19:58:04.412 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 33
2025-03-05 19:58:04.412 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 81 10 21
2025-03-05 19:58:04.412 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 81 10 21
2025-03-05 19:58:04.422 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2025-03-05 19:58:04.422 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 31: Transaction Start type AddNodeToNetwork
2025-03-05 19:58:04.422 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 31: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 16
2025-03-05 19:58:04.422 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null
2025-03-05 19:58:04.422 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: null
2025-03-05 19:58:04.422 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
2025-03-05 19:58:04.423 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 5000ms
2025-03-05 19:58:04.423 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 31: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 16
2025-03-05 19:58:04.423 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.423 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 4999ms
2025-03-05 19:58:04.423 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:5767f857b9
2025-03-05 19:58:04.424 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do
2025-03-05 19:58:04.424 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:5767f857b9
2025-03-05 19:58:04.424 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
2025-03-05 19:58:04.424 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2025-03-05 19:58:04.424 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2025-03-05 19:58:04.425 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true.
2025-03-05 19:58:04.425 [TRACE] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to priority controller queue
2025-03-05 19:58:04.425 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 32 to queue - size 1
2025-03-05 19:58:04.425 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2025-03-05 19:58:04.425 [TRACE] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
2025-03-05 19:58:04.425 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating empty message of class = AddNodeToNetwork (0x4a), type = Request
2025-03-05 19:58:04.425 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 96
2025-03-05 19:58:04.425 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 11 60
2025-03-05 19:58:04.426 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 11 60
2025-03-05 19:58:04.428 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2025-03-05 19:58:04.428 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 06
2025-03-05 19:58:04.428 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:58:04.428 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:58:04.428 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2025-03-05 19:58:04.428 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2025-03-05 19:58:04.428 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2025-03-05 19:58:04.430 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2025-03-05 19:58:04.430 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 4A 11 07 00 00 00 AB
2025-03-05 19:58:04.430 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 08 00 4A 11 07 00 00 00 AB
2025-03-05 19:58:04.430 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = -85
2025-03-05 19:58:04.430 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2025-03-05 19:58:04.431 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 7: Message payload = 11 07 00 00 00
2025-03-05 19:58:04.431 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2025-03-05 19:58:04.435 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2025-03-05 19:58:04.435 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 32: Transaction Start type AddNodeToNetwork
2025-03-05 19:58:04.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 32: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 17
2025-03-05 19:58:04.435 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null
2025-03-05 19:58:04.435 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: null
2025-03-05 19:58:04.435 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
2025-03-05 19:58:04.436 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 4999ms
2025-03-05 19:58:04.436 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 32: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 17
2025-03-05 19:58:04.436 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.436 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 4999ms
2025-03-05 19:58:04.436 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:58:04.436 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2025-03-05 19:58:04.436 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.436 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 4999ms
2025-03-05 19:58:04.438 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2025-03-05 19:58:04.438 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=17, payload=11 07 00 00 00
2025-03-05 19:58:04.438 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=17, payload=11 07 00 00 00
2025-03-05 19:58:04.438 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 32: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 17
2025-03-05 19:58:04.438 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2025-03-05 19:58:04.438 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 32: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 17
2025-03-05 19:58:04.438 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 32: (Callback 17)
2025-03-05 19:58:04.438 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2025-03-05 19:58:04.438 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 32: callback 17
2025-03-05 19:58:04.438 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=17, payload=11 07 00 00 00
2025-03-05 19:58:04.438 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
2025-03-05 19:58:04.439 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Failed.
2025-03-05 19:58:04.439 [TRACE] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInclusionEvent
2025-03-05 19:58:04.439 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeFail
2025-03-05 19:58:04.439 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2025-03-05 19:58:04.439 [TRACE] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to priority controller queue
2025-03-05 19:58:04.439 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 33 to queue - size 1
2025-03-05 19:58:04.439 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:58:04.439 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2025-03-05 19:58:04.439 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.439 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 4996ms
2025-03-05 19:58:04.439 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 32: Transaction CANCELLED
2025-03-05 19:58:04.439 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 32: TransactionAdvance ST: CANCELLED
2025-03-05 19:58:04.439 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 32: TransactionAdvance WT: null
2025-03-05 19:58:04.439 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 32: TransactionAdvance RX: Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=17, payload=11 07 00 00 00
2025-03-05 19:58:04.440 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 32: TransactionAdvance TO: CANCELLED
2025-03-05 19:58:04.440 [TRACE] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2025-03-05 19:58:04.440 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: CANCEL while sending message. Requeueing - 2 attempts left!
2025-03-05 19:58:04.440 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 32: Transaction RESET with 2 retries remaining.
2025-03-05 19:58:04.440 [TRACE] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to priority controller queue
2025-03-05 19:58:04.440 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 32 to queue - size 2
2025-03-05 19:58:04.440 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2025-03-05 19:58:04.440 [TRACE] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
2025-03-05 19:58:04.440 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating empty message of class = AddNodeToNetwork (0x4a), type = Request
2025-03-05 19:58:04.440 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 99
2025-03-05 19:58:04.440 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 12 63
2025-03-05 19:58:04.440 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 12 63
2025-03-05 19:58:04.443 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2025-03-05 19:58:04.443 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 06
2025-03-05 19:58:04.443 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:58:04.445 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2025-03-05 19:58:04.445 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 4A 12 07 00 00 00 A8
2025-03-05 19:58:04.445 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 08 00 4A 12 07 00 00 00 A8
2025-03-05 19:58:04.445 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = -88
2025-03-05 19:58:04.445 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2025-03-05 19:58:04.445 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 7: Message payload = 12 07 00 00 00
2025-03-05 19:58:04.445 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2025-03-05 19:58:04.451 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2025-03-05 19:58:04.451 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 32: Transaction Start type AddNodeToNetwork
2025-03-05 19:58:04.451 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 32: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 18
2025-03-05 19:58:04.451 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null
2025-03-05 19:58:04.451 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: null
2025-03-05 19:58:04.451 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
2025-03-05 19:58:04.451 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.451 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 5000ms
2025-03-05 19:58:04.451 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 32: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 18
2025-03-05 19:58:04.451 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.451 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 5000ms
2025-03-05 19:58:04.451 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 32: Transaction not completed
2025-03-05 19:58:04.451 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:58:04.452 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 32: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 18
2025-03-05 19:58:04.452 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2025-03-05 19:58:04.452 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2025-03-05 19:58:04.452 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:58:04.452 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2025-03-05 19:58:04.452 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.452 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 4999ms
2025-03-05 19:58:04.454 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2025-03-05 19:58:04.454 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=18, payload=12 07 00 00 00
2025-03-05 19:58:04.454 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=18, payload=12 07 00 00 00
2025-03-05 19:58:04.454 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 32: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 18
2025-03-05 19:58:04.454 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2025-03-05 19:58:04.454 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 32: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 18
2025-03-05 19:58:04.454 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 32: (Callback 18)
2025-03-05 19:58:04.454 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2025-03-05 19:58:04.454 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 32: callback 18
2025-03-05 19:58:04.454 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=18, payload=12 07 00 00 00
2025-03-05 19:58:04.454 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
2025-03-05 19:58:04.455 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Failed.
2025-03-05 19:58:04.455 [TRACE] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInclusionEvent
2025-03-05 19:58:04.455 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeFail, new event IncludeFail
2025-03-05 19:58:04.455 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2025-03-05 19:58:04.455 [TRACE] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to priority controller queue
2025-03-05 19:58:04.455 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Transaction already in queue - removed original
2025-03-05 19:58:04.455 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 34 to queue - size 1
2025-03-05 19:58:04.455 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:58:04.455 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2025-03-05 19:58:04.455 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.455 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 4996ms
2025-03-05 19:58:04.455 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 32: Transaction CANCELLED
2025-03-05 19:58:04.455 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 32: TransactionAdvance ST: CANCELLED
2025-03-05 19:58:04.456 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 32: TransactionAdvance WT: null
2025-03-05 19:58:04.456 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 32: TransactionAdvance RX: Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=18, payload=12 07 00 00 00
2025-03-05 19:58:04.456 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 32: TransactionAdvance TO: CANCELLED
2025-03-05 19:58:04.456 [TRACE] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2025-03-05 19:58:04.456 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: CANCEL while sending message. Requeueing - 1 attempts left!
2025-03-05 19:58:04.456 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 32: Transaction RESET with 1 retries remaining.
2025-03-05 19:58:04.456 [TRACE] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to priority controller queue
2025-03-05 19:58:04.456 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 32 to queue - size 2
2025-03-05 19:58:04.456 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2025-03-05 19:58:04.456 [TRACE] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
2025-03-05 19:58:04.456 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating empty message of class = AddNodeToNetwork (0x4a), type = Request
2025-03-05 19:58:04.456 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 98
2025-03-05 19:58:04.457 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 13 62
2025-03-05 19:58:04.457 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 13 62
2025-03-05 19:58:04.459 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2025-03-05 19:58:04.459 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 06
2025-03-05 19:58:04.459 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:58:04.461 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2025-03-05 19:58:04.462 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 4A 13 07 00 00 00 A9
2025-03-05 19:58:04.462 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 08 00 4A 13 07 00 00 00 A9
2025-03-05 19:58:04.462 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = -87
2025-03-05 19:58:04.462 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2025-03-05 19:58:04.462 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 7: Message payload = 13 07 00 00 00
2025-03-05 19:58:04.462 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2025-03-05 19:58:04.470 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2025-03-05 19:58:04.470 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 32: Transaction Start type AddNodeToNetwork
2025-03-05 19:58:04.470 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 32: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 19
2025-03-05 19:58:04.470 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null
2025-03-05 19:58:04.470 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: null
2025-03-05 19:58:04.470 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
2025-03-05 19:58:04.470 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.470 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 5000ms
2025-03-05 19:58:04.470 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 32: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 19
2025-03-05 19:58:04.470 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.470 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 5000ms
2025-03-05 19:58:04.471 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 32: Transaction not completed
2025-03-05 19:58:04.471 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:58:04.471 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 32: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 19
2025-03-05 19:58:04.471 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2025-03-05 19:58:04.471 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2025-03-05 19:58:04.471 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:58:04.471 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2025-03-05 19:58:04.471 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.471 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 4999ms
2025-03-05 19:58:04.473 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2025-03-05 19:58:04.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=19, payload=13 07 00 00 00
2025-03-05 19:58:04.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=19, payload=13 07 00 00 00
2025-03-05 19:58:04.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 32: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 19
2025-03-05 19:58:04.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2025-03-05 19:58:04.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 32: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 19
2025-03-05 19:58:04.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 32: (Callback 19)
2025-03-05 19:58:04.473 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2025-03-05 19:58:04.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 32: callback 19
2025-03-05 19:58:04.474 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=19, payload=13 07 00 00 00
2025-03-05 19:58:04.474 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
2025-03-05 19:58:04.474 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Failed.
2025-03-05 19:58:04.474 [TRACE] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInclusionEvent
2025-03-05 19:58:04.474 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeFail, new event IncludeFail
2025-03-05 19:58:04.474 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2025-03-05 19:58:04.474 [TRACE] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to priority controller queue
2025-03-05 19:58:04.474 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Transaction already in queue - removed original
2025-03-05 19:58:04.474 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 35 to queue - size 1
2025-03-05 19:58:04.474 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:58:04.474 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2025-03-05 19:58:04.474 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.475 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 4995ms
2025-03-05 19:58:04.475 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 32: Transaction CANCELLED
2025-03-05 19:58:04.475 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 32: TransactionAdvance ST: CANCELLED
2025-03-05 19:58:04.475 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 32: TransactionAdvance WT: null
2025-03-05 19:58:04.475 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 32: TransactionAdvance RX: Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=19, payload=13 07 00 00 00
2025-03-05 19:58:04.475 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 32: TransactionAdvance TO: CANCELLED
2025-03-05 19:58:04.475 [TRACE] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2025-03-05 19:58:04.475 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Retry count exceeded. Discarding message: TID 32: [CANCELLED] priority=Controller, requiresResponse=true, callback: 19
2025-03-05 19:58:04.475 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 32: Transaction completed
2025-03-05 19:58:04.475 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:32 CANCELLED
2025-03-05 19:58:04.476 [TRACE] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2025-03-05 19:58:04.476 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2025-03-05 19:58:04.476 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2025-03-05 19:58:04.476 [TRACE] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
2025-03-05 19:58:04.476 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating empty message of class = AddNodeToNetwork (0x4a), type = Request
2025-03-05 19:58:04.476 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = -95
2025-03-05 19:58:04.476 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 14 A1
2025-03-05 19:58:04.476 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 14 A1
2025-03-05 19:58:04.478 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2025-03-05 19:58:04.478 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 06
2025-03-05 19:58:04.478 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:58:04.481 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2025-03-05 19:58:04.481 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 4A 14 06 00 00 00 AF
2025-03-05 19:58:04.481 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 08 00 4A 14 06 00 00 00 AF
2025-03-05 19:58:04.481 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = -81
2025-03-05 19:58:04.481 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2025-03-05 19:58:04.481 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 6: Message payload = 14 06 00 00 00
2025-03-05 19:58:04.481 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2025-03-05 19:58:04.488 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2025-03-05 19:58:04.488 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 35: Transaction Start type AddNodeToNetwork
2025-03-05 19:58:04.488 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 35: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 20
2025-03-05 19:58:04.488 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null
2025-03-05 19:58:04.488 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: null
2025-03-05 19:58:04.488 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
2025-03-05 19:58:04.488 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.488 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 5000ms
2025-03-05 19:58:04.488 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 35: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 20
2025-03-05 19:58:04.488 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.488 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 5000ms
2025-03-05 19:58:04.488 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:58:04.488 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 35: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 20
2025-03-05 19:58:04.488 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2025-03-05 19:58:04.489 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2025-03-05 19:58:04.489 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:58:04.489 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2025-03-05 19:58:04.489 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.489 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 4999ms
2025-03-05 19:58:04.491 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2025-03-05 19:58:04.491 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=20, payload=14 06 00 00 00
2025-03-05 19:58:04.491 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=20, payload=14 06 00 00 00
2025-03-05 19:58:04.491 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 35: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 20
2025-03-05 19:58:04.491 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2025-03-05 19:58:04.491 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 35: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 20
2025-03-05 19:58:04.491 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 35: (Callback 20)
2025-03-05 19:58:04.491 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2025-03-05 19:58:04.491 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 35: callback 20
2025-03-05 19:58:04.491 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=20, payload=14 06 00 00 00
2025-03-05 19:58:04.491 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
2025-03-05 19:58:04.491 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
2025-03-05 19:58:04.491 [TRACE] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInclusionEvent
2025-03-05 19:58:04.491 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeFail, new event IncludeDone
2025-03-05 19:58:04.491 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2025-03-05 19:58:04.492 [TRACE] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to priority controller queue
2025-03-05 19:58:04.492 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 36 to queue - size 1
2025-03-05 19:58:04.492 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:58:04.492 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2025-03-05 19:58:04.492 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.492 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 4996ms
2025-03-05 19:58:04.492 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2025-03-05 19:58:04.492 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2025-03-05 19:58:04.492 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 35: TransactionAdvance ST: WAIT_REQUEST
2025-03-05 19:58:04.492 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 35: TransactionAdvance WT: null
2025-03-05 19:58:04.492 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 35: TransactionAdvance RX: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=20, payload=14 06 00 00 00
2025-03-05 19:58:04.492 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 35: TransactionAdvance RQ: RREQ=true, RCLS=null
2025-03-05 19:58:04.492 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 35: TransactionAdvance TO: DONE
2025-03-05 19:58:04.492 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 35: Advanced to DONE
2025-03-05 19:58:04.492 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 4ms
2025-03-05 19:58:04.492 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 35: Transaction completed
2025-03-05 19:58:04.492 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:35 DONE
2025-03-05 19:58:04.493 [TRACE] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2025-03-05 19:58:04.493 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2025-03-05 19:58:04.493 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2025-03-05 19:58:04.493 [TRACE] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
2025-03-05 19:58:04.493 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating empty message of class = AddNodeToNetwork (0x4a), type = Request
2025-03-05 19:58:04.493 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = -75
2025-03-05 19:58:04.493 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5
2025-03-05 19:58:04.493 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5
2025-03-05 19:58:04.495 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2025-03-05 19:58:04.495 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 06
2025-03-05 19:58:04.495 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:58:04.502 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2025-03-05 19:58:04.502 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 36: Transaction Start type AddNodeToNetwork
2025-03-05 19:58:04.502 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 36: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2025-03-05 19:58:04.502 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null
2025-03-05 19:58:04.502 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: null
2025-03-05 19:58:04.502 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
2025-03-05 19:58:04.502 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.502 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 5000ms
2025-03-05 19:58:04.502 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 36: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2025-03-05 19:58:04.502 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.502 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 5000ms
2025-03-05 19:58:04.502 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2025-03-05 19:58:04.502 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 36: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2025-03-05 19:58:04.502 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2025-03-05 19:58:04.502 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2025-03-05 19:58:04.502 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2025-03-05 19:58:04.503 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2025-03-05 19:58:04.503 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2025-03-05 19:58:04.503 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Mar 05 19:58:09 CST 2025 - 4999ms
2025-03-05 19:58:06.436 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 1: Device discovery completed