2023-12-11 14:39:19.735 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:AeotecZStick7
2023-12-11 14:39:19.736 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
2023-12-11 14:39:19.738 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2023-12-11 14:39:19.739 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2023-12-11 14:39:19.741 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 5910 to queue - size 1
2023-12-11 14:39:19.742 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-12-11 14:39:19.744 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 06 77 
2023-12-11 14:39:19.748 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-12-11 14:39:19.749 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 5910: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 6
2023-12-11 14:39:19.752 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-12-11 14:39:19.753 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-12-11 14:39:19.755 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 4A 06 01 00 00 00 BA 
2023-12-11 14:39:19.762 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-12-11 14:39:19.763 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5910: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 6
2023-12-11 14:39:19.763 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-12-11 14:39:19.764 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-12-11 14:39:19.764 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-12-11 14:39:19.765 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=6, payload=06 01 00 00 00 
2023-12-11 14:39:19.766 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=6, payload=06 01 00 00 00 
2023-12-11 14:39:19.767 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5910: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 6
2023-12-11 14:39:19.767 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-12-11 14:39:19.768 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 5910: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 6
2023-12-11 14:39:19.768 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 5910: (Callback 6)
2023-12-11 14:39:19.769 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2023-12-11 14:39:19.769 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 5910: callback 6
2023-12-11 14:39:19.770 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=6, payload=06 01 00 00 00 
2023-12-11 14:39:19.771 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart
2023-12-11 14:39:19.772 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5910: Transaction COMPLETED
2023-12-11 14:39:19.773 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 25ms
2023-12-11 14:39:19.773 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 5910: Transaction completed
2023-12-11 14:39:19.774 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:5910 DONE
2023-12-11 14:39:19.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-12-11 14:39:19.776 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-12-11 14:39:21.750 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 1: Device discovery completed
2023-12-11 14:39:21.753 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 1: Device discovery could not resolve to a thingType! Manufacturer data not known.
2023-12-11 14:39:21.757 [INFO ] [openhab.event.InboxAddedEvent       ] - Discovery Result with UID 'zwave:device:AeotecZStick7:node1' has been added.
2023-12-11 14:39:21.756 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:AeotecZStick7:node1' to inbox.
2023-12-11 14:39:21.758 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery completed
2023-12-11 14:39:21.760 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery could not resolve to a thingType! Manufacturer data not known.
2023-12-11 14:39:21.762 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:AeotecZStick7:node2' to inbox.
2023-12-11 14:39:21.763 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovery completed
2023-12-11 14:39:21.765 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovery could not resolve to a thingType! Manufacturer data not known.
2023-12-11 14:39:21.768 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:AeotecZStick7:node4' to inbox.
2023-12-11 14:39:21.768 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery completed
2023-12-11 14:39:21.770 [INFO ] [openhab.event.InboxAddedEvent       ] - Discovery Result with UID 'zwave:device:AeotecZStick7:node2' has been added.
2023-12-11 14:39:21.771 [INFO ] [openhab.event.InboxAddedEvent       ] - Discovery Result with UID 'zwave:device:AeotecZStick7:node4' has been added.
2023-12-11 14:39:21.773 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery could not resolve to a thingType! Manufacturer data not known.
2023-12-11 14:39:21.779 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery completed
2023-12-11 14:39:21.780 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery could not resolve to a thingType! Manufacturer data not known.
2023-12-11 14:39:21.784 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:AeotecZStick7:node7' to inbox.
2023-12-11 14:39:21.784 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery completed
2023-12-11 14:39:21.786 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery could not resolve to a thingType! Manufacturer data not known.
2023-12-11 14:39:21.788 [INFO ] [openhab.event.InboxAddedEvent       ] - Discovery Result with UID 'zwave:device:AeotecZStick7:node7' has been added.
2023-12-11 14:39:21.791 [INFO ] [openhab.event.InboxAddedEvent       ] - Discovery Result with UID 'zwave:device:AeotecZStick7:node8' has been added.
2023-12-11 14:39:21.790 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:AeotecZStick7:node8' to inbox.
2023-12-11 14:40:19.736 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:AeotecZStick7
2023-12-11 14:40:19.737 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeStart
2023-12-11 14:40:19.741 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 5911 to queue - size 1
2023-12-11 14:40:19.742 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-12-11 14:40:19.743 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 07 B2 
2023-12-11 14:40:19.748 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-12-11 14:40:19.749 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 5911: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 7
2023-12-11 14:40:19.751 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-12-11 14:40:19.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-12-11 14:40:19.754 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 4A 07 06 00 0A 00 B6 
2023-12-11 14:40:19.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-12-11 14:40:19.755 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5911: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 7
2023-12-11 14:40:19.756 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-12-11 14:40:19.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-12-11 14:40:19.759 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-12-11 14:40:19.764 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=7, payload=07 06 00 0A 00 
2023-12-11 14:40:19.765 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=7, payload=07 06 00 0A 00 
2023-12-11 14:40:19.766 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5911: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 7
2023-12-11 14:40:19.768 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2023-12-11 14:40:19.769 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 5911: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 7
2023-12-11 14:40:19.770 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 5911: (Callback 7)
2023-12-11 14:40:19.771 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2023-12-11 14:40:19.772 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 5911: callback 7
2023-12-11 14:40:19.773 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=7, payload=07 06 00 0A 00 
2023-12-11 14:40:19.775 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeDone, new event IncludeDone
2023-12-11 14:40:19.776 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 5912 to queue - size 1
2023-12-11 14:40:19.777 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-12-11 14:40:19.778 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2023-12-11 14:40:19.779 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2023-12-11 14:40:19.779 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 5911: Advanced to DONE
2023-12-11 14:40:19.780 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 31ms
2023-12-11 14:40:19.781 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 5911: Transaction completed
2023-12-11 14:40:19.781 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:5911 DONE
2023-12-11 14:40:19.784 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-12-11 14:40:19.785 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2023-12-11 14:40:19.787 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5 
2023-12-11 14:40:19.792 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2023-12-11 14:40:19.793 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2023-12-11 14:40:19.794 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-12-11 14:40:19.795 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 5912: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2023-12-11 14:40:19.797 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2023-12-11 14:40:19.798 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5912: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2023-12-11 14:40:19.800 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2023-12-11 14:40:19.801 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2023-12-11 14:40:19.801 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2023-12-11 14:40:24.796 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 5912: Timeout at state WAIT_REQUEST. 3 retries remaining.
2023-12-11 14:40:24.797 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 5912: Transaction is current transaction, so clearing!!!!!
2023-12-11 14:40:24.797 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5912: Transaction CANCELLED
2023-12-11 14:40:24.797 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:5912 CANCELLED
2023-12-11 14:40:24.798 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.