2020-01-03 21:15:42.489 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Stopped ZWave thread: Receive 2020-01-03 21:15:45.500 [INFO ] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler 2020-01-03 21:15:45.512 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Interrupted taking message from recvQueue java.lang.InterruptedException: null at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) ~[?:1.8.0_222] at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2048) ~[?:1.8.0_222] at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:403) ~[?:1.8.0_222] at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager$ZWaveReceiveThread.run(ZWaveTransactionManager.java:440) [bundleFile:?] 2020-01-03 21:15:45.516 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:15:45.516 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:15:45.523 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Deactivate zwave:serial_zstick:4849599d 2020-01-03 21:17:24.184 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - Creating ZWave discovery service for zwave:serial_zstick:4849599d with scan time of 60 2020-01-03 21:17:24.186 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Active zwave:serial_zstick:4849599d 2020-01-03 21:17:24.188 [INFO ] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null 2020-01-03 21:17:24.460 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller. 2020-01-03 21:17:24.464 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:4849599d. 2020-01-03 21:17:24.467 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 5 hours time. 2020-01-03 21:17:24.472 [INFO ] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0' 2020-01-03 21:17:24.513 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Starting receive thread 2020-01-03 21:17:24.519 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive 2020-01-03 21:17:24.520 [INFO ] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Serial port is initialized 2020-01-03 21:17:24.521 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller 2020-01-03 21:17:24.565 [INFO ] [ab.binding.zwave.internal.protocol.ZWaveController] - Starting ZWave controller 2020-01-03 21:17:24.565 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:24.566 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:17:24.566 [INFO ] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false. 2020-01-03 21:17:24.568 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event listener added. 2020-01-03 21:17:24.570 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event listener added. 2020-01-03 21:17:27.569 [DEBUG] [ernal.protocol.ZWaveController$InitializeDelayTask] - Initialising network 2020-01-03 21:17:27.621 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 0 to queue - size 1 2020-01-03 21:17:27.625 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:17:27.637 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9 2020-01-03 21:17:27.640 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9 2020-01-03 21:17:27.655 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:17:27.657 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:17:27.659 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:27.659 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.661 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:27.663 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null 2020-01-03 21:17:27.664 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 01 15 5A 2D 57 61 76 65 20 34 2E 36 31 00 01 95 2020-01-03 21:17:27.664 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:17:27.665 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:27.666 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:27.669 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 34 2E 36 31 00 01 2020-01-03 21:17:27.669 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 1 to queue - size 1 2020-01-03 21:17:27.670 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:27.672 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 34 2E 36 31 00 01 2020-01-03 21:17:27.673 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.675 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:17:27.677 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.680 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 2 to queue - size 2 2020-01-03 21:17:27.680 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 34 2E 36 31 00 01 2020-01-03 21:17:27.681 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:27.684 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 3 to queue - size 3 2020-01-03 21:17:27.685 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:27.688 [DEBUG] [al.protocol.serialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID 2020-01-03 21:17:27.689 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 4 to queue - size 4 2020-01-03 21:17:27.690 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:27.706 [DEBUG] [rnal.protocol.serialmessage.GetVersionMessageClass] - Got MessageGetVersion response. Version=Z-Wave 4.61, Library Type=1 2020-01-03 21:17:27.707 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 0: Transaction COMPLETED 2020-01-03 21:17:27.710 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 51ms 2020-01-03 21:17:27.710 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 0: Transaction completed 2020-01-03 21:17:27.711 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:0 DONE 2020-01-03 21:17:27.718 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:27.719 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:17:27.720 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC 2020-01-03 21:17:27.722 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC 2020-01-03 21:17:27.723 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:17:27.724 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:17:27.724 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.725 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:27.725 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:27.727 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 01 20 E7 27 62 F2 01 87 2020-01-03 21:17:27.727 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.728 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:17:27.728 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=E7 27 62 F2 01 2020-01-03 21:17:27.729 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:27.737 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:27.738 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=E7 27 62 F2 01 2020-01-03 21:17:27.738 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.739 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:17:27.739 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.740 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=E7 27 62 F2 01 2020-01-03 21:17:27.741 [DEBUG] [nal.protocol.serialmessage.MemoryGetIdMessageClass] - Got MessageMemoryGetId response. Home id = 0xe72762f2, Controller Node id = 1 2020-01-03 21:17:27.742 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 1: Transaction COMPLETED 2020-01-03 21:17:27.742 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 18ms 2020-01-03 21:17:27.743 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 1: Transaction completed 2020-01-03 21:17:27.743 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:1 DONE 2020-01-03 21:17:27.745 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:27.747 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:17:27.748 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB 2020-01-03 21:17:27.749 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB 2020-01-03 21:17:27.750 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:17:27.750 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.750 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:17:27.751 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:27.752 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:27.753 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.754 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:17:27.754 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:27.755 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 2B 01 07 05 1B 01 15 04 00 00 01 FE 87 7F 88 CF 3F C0 47 FB DF FD E0 67 00 80 80 00 80 86 00 00 00 E8 73 00 80 0F 00 00 60 5A 00 52 2020-01-03 21:17:27.755 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:27.760 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=05 1B 01 15 04 00 00 01 FE 87 7F 88 CF 3F C0 47 FB DF FD E0 67 00 80 80 00 80 86 00 00 00 E8 73 00 80 0F 00 00 60 5A 00 2020-01-03 21:17:27.762 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=05 1B 01 15 04 00 00 01 FE 87 7F 88 CF 3F C0 47 FB DF FD E0 67 00 80 80 00 80 86 00 00 00 E8 73 00 80 0F 00 00 60 5A 00 2020-01-03 21:17:27.763 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.764 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:17:27.764 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.766 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=05 1B 01 15 04 00 00 01 FE 87 7F 88 CF 3F C0 47 FB DF FD E0 67 00 80 80 00 80 86 00 00 00 E8 73 00 80 0F 00 00 60 5A 00 2020-01-03 21:17:27.768 [DEBUG] [serialmessage.SerialApiGetCapabilitiesMessageClass] - API Version = 5.27 2020-01-03 21:17:27.769 [DEBUG] [serialmessage.SerialApiGetCapabilitiesMessageClass] - Manufacture ID = 0x115 2020-01-03 21:17:27.769 [DEBUG] [serialmessage.SerialApiGetCapabilitiesMessageClass] - Device Type = 0x400 2020-01-03 21:17:27.770 [DEBUG] [serialmessage.SerialApiGetCapabilitiesMessageClass] - Device ID = 0x1 2020-01-03 21:17:27.771 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 2: Transaction COMPLETED 2020-01-03 21:17:27.773 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 5 to queue - size 3 2020-01-03 21:17:27.774 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:27.775 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 25ms 2020-01-03 21:17:27.776 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 2: Transaction completed 2020-01-03 21:17:27.776 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:2 DONE 2020-01-03 21:17:27.778 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:27.779 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:17:27.780 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65 2020-01-03 21:17:27.781 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65 2020-01-03 21:17:27.782 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:17:27.783 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.784 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:17:27.785 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:27.785 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:27.786 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 01 06 96 0F 64 2020-01-03 21:17:27.786 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.787 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:17:27.788 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:27.788 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 2020-01-03 21:17:27.789 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:27.790 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 2020-01-03 21:17:27.791 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.792 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:17:27.793 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.793 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 2020-01-03 21:17:27.794 [DEBUG] [col.serialmessage.SerialApiSetTimeoutsMessageClass] - Got SerialApiSetTimeouts response. ACK=150, BYTE=15 2020-01-03 21:17:27.795 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 3: Transaction COMPLETED 2020-01-03 21:17:27.796 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 13ms 2020-01-03 21:17:27.797 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 3: Transaction completed 2020-01-03 21:17:27.797 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:3 DONE 2020-01-03 21:17:27.799 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:27.800 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:17:27.801 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA 2020-01-03 21:17:27.802 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA 2020-01-03 21:17:27.803 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:17:27.803 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.804 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:17:27.805 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:27.806 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:27.807 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 56 01 AD 2020-01-03 21:17:27.807 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.808 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:17:27.808 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:27.808 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 2020-01-03 21:17:27.809 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:27.810 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 2020-01-03 21:17:27.811 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.812 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:17:27.813 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.814 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 2020-01-03 21:17:27.815 [DEBUG] [al.protocol.serialmessage.GetSucNodeIdMessageClass] - Got SUC NodeID response. 2020-01-03 21:17:27.816 [DEBUG] [al.protocol.serialmessage.GetSucNodeIdMessageClass] - NODE 1: Node is SUC. 2020-01-03 21:17:27.817 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 4: Transaction COMPLETED 2020-01-03 21:17:27.818 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Creating GET_CONTROLLER_CAPABILITIES message 2020-01-03 21:17:27.819 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 6 to queue - size 2 2020-01-03 21:17:27.820 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:27.820 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 17ms 2020-01-03 21:17:27.821 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 4: Transaction completed 2020-01-03 21:17:27.822 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:4 DONE 2020-01-03 21:17:27.823 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:27.824 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:17:27.825 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 02 FE 2020-01-03 21:17:27.826 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 02 FE 2020-01-03 21:17:27.827 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:17:27.828 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.828 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:17:27.829 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:27.830 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:27.830 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.831 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:17:27.831 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:27.832 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:27.925 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 25 01 02 06 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 CE 2020-01-03 21:17:27.929 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=06 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 2020-01-03 21:17:27.931 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=06 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 2020-01-03 21:17:27.931 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.932 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:17:27.933 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:27.934 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=06 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 2020-01-03 21:17:27.935 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - Got MessageSerialApiGetInitData response. 2020-01-03 21:17:27.936 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - NODE 1: Node found 2020-01-03 21:17:27.938 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API 2020-01-03 21:17:27.938 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller 2020-01-03 21:17:27.939 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------ 2020-01-03 21:17:27.940 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - # Nodes = 1 2020-01-03 21:17:27.940 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - ---------------------------------------------------------------------------- 2020-01-03 21:17:27.941 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 5: Transaction COMPLETED 2020-01-03 21:17:27.948 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 1: Init node thread start 2020-01-03 21:17:27.950 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 121ms 2020-01-03 21:17:27.950 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Starting waiting for init threads 2020-01-03 21:17:27.951 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Waiting for init thread Node_1_init 2020-01-03 21:17:27.951 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 5: Transaction completed 2020-01-03 21:17:28.090 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:5 DONE 2020-01-03 21:17:28.099 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:28.100 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:17:28.101 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 05 F9 2020-01-03 21:17:28.102 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 05 F9 2020-01-03 21:17:28.103 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:17:28.105 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:17:28.105 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:28.106 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:28.107 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:28.108 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:28.109 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 05 3C C3 2020-01-03 21:17:28.109 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:17:28.110 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:28.110 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=3C 2020-01-03 21:17:28.113 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:28.114 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=3C 2020-01-03 21:17:28.115 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:28.116 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:17:28.117 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:28.117 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=3C 2020-01-03 21:17:28.118 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Controller is secondary = false 2020-01-03 21:17:28.119 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Controller is on other network = false 2020-01-03 21:17:28.120 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Node ID Server is present = false 2020-01-03 21:17:28.121 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Controller is real primary = true 2020-01-03 21:17:28.122 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Controller is SUC = true 2020-01-03 21:17:28.123 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 6: Transaction COMPLETED 2020-01-03 21:17:28.123 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 18ms 2020-01-03 21:17:28.124 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 6: Transaction completed 2020-01-03 21:17:28.125 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:6 DONE 2020-01-03 21:17:28.126 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:28.128 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:17:28.403 [DEBUG] [ternal.protocol.initialization.ZWaveNodeSerializer] - NODE 1: Serializing from file /var/lib/openhab2/zwave/network_e72762f2__node_1.xml 2020-01-03 21:17:28.455 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 1: Restore from config: Ok. 2020-01-03 21:17:28.501 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-01-03 21:17:28.503 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-01-03 21:17:28.504 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Starting initialisation from EMPTYNODE 2020-01-03 21:17:28.516 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 1: Init node thread finished 2020-01-03 21:17:28.517 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to IDENTIFY_NODE 2020-01-03 21:17:28.517 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Init thread Node_1_init complete 2020-01-03 21:17:28.518 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - All init threads complete 2020-01-03 21:17:28.518 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Controller: Incoming Network State Event true 2020-01-03 21:17:28.519 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: Initialisation starting 2020-01-03 21:17:28.521 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@5347c3 2020-01-03 21:17:28.526 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 7 to queue - size 1 2020-01-03 21:17:28.527 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:17:28.528 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 01 BB 2020-01-03 21:17:28.529 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 01 BB 2020-01-03 21:17:28.530 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:17:28.531 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:28.563 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:17:28.564 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:28.565 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:28.566 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 16 01 02 02 01 73 2020-01-03 21:17:28.566 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:28.567 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:17:28.568 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:28.572 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 2020-01-03 21:17:28.572 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:28.574 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 2020-01-03 21:17:28.574 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:28.575 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:17:28.576 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:28.577 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 2020-01-03 21:17:28.578 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: ProtocolInfo 2020-01-03 21:17:28.579 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Listening = true 2020-01-03 21:17:28.579 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Routing = true 2020-01-03 21:17:28.580 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Beaming = true 2020-01-03 21:17:28.581 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Version = 4 2020-01-03 21:17:28.581 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: FLIRS = false 2020-01-03 21:17:28.582 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Security = false 2020-01-03 21:17:28.582 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Max Baud = 40000 2020-01-03 21:17:28.583 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Basic = BASIC_TYPE_STATIC_CONTROLLER 2020-01-03 21:17:28.584 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Generic = GENERIC_TYPE_STATIC_CONTROLLER 2020-01-03 21:17:28.585 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Specific = SPECIFIC_TYPE_PC_CONTROLLER 2020-01-03 21:17:28.587 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class COMMAND_CLASS_NO_OPERATION 2020-01-03 21:17:28.588 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-01-03 21:17:28.589 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Version = 1, version set. Enabling extra functionality. 2020-01-03 21:17:28.590 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 1: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes. 2020-01-03 21:17:28.590 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class COMMAND_CLASS_BASIC 2020-01-03 21:17:28.591 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-01-03 21:17:28.592 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 1: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes. 2020-01-03 21:17:28.593 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 7: Transaction COMPLETED 2020-01-03 21:17:28.593 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 62ms 2020-01-03 21:17:28.594 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 7: Transaction completed 2020-01-03 21:17:28.594 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:7 DONE 2020-01-03 21:17:28.595 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:28.596 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 7: Transaction event listener: DONE: DONE -> 2020-01-03 21:17:28.596 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:17:28.602 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1ce98eb 2020-01-03 21:17:28.603 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init transaction completed with response COMPLETE 2020-01-03 21:17:28.604 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: FAILED_CHECK - Controller - terminating initialisation 2020-01-03 21:17:28.605 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to DONE 2020-01-03 21:17:28.606 [DEBUG] [ternal.protocol.initialization.ZWaveNodeSerializer] - NODE 1: Serializing to file /var/lib/openhab2/zwave/network_e72762f2__node_1.xml 2020-01-03 21:17:49.837 [DEBUG] [openhab.binding.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:device has no references! 2020-01-03 21:17:49.845 [DEBUG] [openhab.binding.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:serial_zstick has no references! 2020-01-03 21:17:49.901 [DEBUG] [openhab.binding.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:device has no references! 2020-01-03 21:17:49.905 [DEBUG] [openhab.binding.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:serial_zstick has no references! 2020-01-03 21:17:49.969 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:4849599d 2020-01-03 21:17:49.970 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do 2020-01-03 21:17:49.974 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:4849599d 2020-01-03 21:17:49.975 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 1 2020-01-03 21:17:49.989 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event listener added. 2020-01-03 21:17:49.990 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - ZWave controller start inclusion 2020-01-03 21:17:49.994 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:false. 2020-01-03 21:17:49.995 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 8 to queue - size 1 2020-01-03 21:17:49.997 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:17:49.999 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 81 01 30 2020-01-03 21:17:50.001 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 81 01 30 2020-01-03 21:17:50.003 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:17:50.004 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:17:50.004 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 8: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 1 2020-01-03 21:17:50.005 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:50.006 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:50.008 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 8: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 1 2020-01-03 21:17:50.008 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 01 01 00 00 B2 2020-01-03 21:17:50.008 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:17:50.009 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:50.010 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:50.011 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=1, payload=01 01 00 00 2020-01-03 21:17:50.013 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=1, payload=01 01 00 00 2020-01-03 21:17:50.014 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 8: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 1 2020-01-03 21:17:50.015 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:17:50.015 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 8: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 1 2020-01-03 21:17:50.017 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking TID 8: (Callback 1) 2020-01-03 21:17:50.019 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-01-03 21:17:50.020 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Correlated to TID 8: callback 1 2020-01-03 21:17:50.021 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=1, payload=01 01 00 00 2020-01-03 21:17:50.023 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready. 2020-01-03 21:17:50.025 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart 2020-01-03 21:17:50.027 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 8: Transaction COMPLETED 2020-01-03 21:17:50.028 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 23ms 2020-01-03 21:17:50.029 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 8: Transaction completed 2020-01-03 21:17:50.030 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:8 DONE 2020-01-03 21:17:50.031 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:50.033 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:17:50.585 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:4849599d 2020-01-03 21:17:50.586 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeStart 2020-01-03 21:17:50.588 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode. 2020-01-03 21:17:50.589 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 9 to queue - size 1 2020-01-03 21:17:50.590 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:17:50.592 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 02 B7 2020-01-03 21:17:50.594 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 02 B7 2020-01-03 21:17:50.595 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:17:50.597 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 9: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 2 2020-01-03 21:17:50.597 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:17:50.598 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:50.600 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:50.600 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:4849599d 2020-01-03 21:17:50.601 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 9: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 2 2020-01-03 21:17:50.601 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave inclusion process already running - aborted 2020-01-03 21:17:50.602 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:17:50.602 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:50.603 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:50.649 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 02 06 00 00 B6 2020-01-03 21:17:50.652 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=2, payload=02 06 00 00 2020-01-03 21:17:50.653 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=2, payload=02 06 00 00 2020-01-03 21:17:50.654 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 9: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 2 2020-01-03 21:17:50.654 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:17:50.655 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 9: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 2 2020-01-03 21:17:50.655 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking TID 9: (Callback 2) 2020-01-03 21:17:50.656 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-01-03 21:17:50.657 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Correlated to TID 9: callback 2 2020-01-03 21:17:50.658 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=2, payload=02 06 00 00 2020-01-03 21:17:50.658 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Add Node: Done. 2020-01-03 21:17:50.659 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeDone, new event IncludeDone 2020-01-03 21:17:50.660 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode. 2020-01-03 21:17:50.660 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 10 to queue - size 1 2020-01-03 21:17:50.661 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:50.661 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - ZWave controller end exclusion 2020-01-03 21:17:50.662 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWaveController include done 2020-01-03 21:17:50.663 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 9: Advanced to DONE 2020-01-03 21:17:50.663 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 67ms 2020-01-03 21:17:50.664 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 9: Transaction completed 2020-01-03 21:17:50.664 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:9 DONE 2020-01-03 21:17:50.675 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:50.676 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:17:50.678 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5 2020-01-03 21:17:50.679 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5 2020-01-03 21:17:50.679 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:17:50.680 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 10: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:50.682 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:17:50.683 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:50.684 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:17:50.685 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 10: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:17:50.685 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:17:50.686 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:17:50.687 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:17:55.682 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 255: TID 10: Timeout at state WAIT_REQUEST. 3 retries remaining. 2020-01-03 21:17:55.684 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - TID 10: Transaction is current transaction, so clearing!!!!! 2020-01-03 21:17:55.685 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 10: Transaction CANCELLED 2020-01-03 21:17:55.686 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:10 CANCELLED 2020-01-03 21:17:55.692 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:18:50.600 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:4849599d 2020-01-03 21:18:50.602 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do 2020-01-03 21:19:39.565 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - ZWave inclusion controller finalised 2020-01-03 21:46:59.646 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - Creating ZWave discovery service for zwave:serial_zstick:4849599d with scan time of 60 2020-01-03 21:46:59.648 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Active zwave:serial_zstick:4849599d 2020-01-03 21:46:59.649 [INFO ] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null 2020-01-03 21:46:59.972 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller. 2020-01-03 21:46:59.975 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:4849599d. 2020-01-03 21:46:59.978 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 5 hours time. 2020-01-03 21:46:59.985 [INFO ] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0' 2020-01-03 21:47:00.027 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Starting receive thread 2020-01-03 21:47:00.034 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive 2020-01-03 21:47:00.035 [INFO ] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Serial port is initialized 2020-01-03 21:47:00.036 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller 2020-01-03 21:47:00.081 [INFO ] [ab.binding.zwave.internal.protocol.ZWaveController] - Starting ZWave controller 2020-01-03 21:47:00.081 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:47:00.082 [INFO ] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false. 2020-01-03 21:47:00.082 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:47:00.085 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event listener added. 2020-01-03 21:47:00.087 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event listener added. 2020-01-03 21:47:03.085 [DEBUG] [ernal.protocol.ZWaveController$InitializeDelayTask] - Initialising network 2020-01-03 21:47:03.108 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 0 to queue - size 1 2020-01-03 21:47:03.109 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:47:03.116 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9 2020-01-03 21:47:03.117 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9 2020-01-03 21:47:03.120 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:47:03.121 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:47:03.121 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.123 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:03.124 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:03.125 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.126 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 01 15 5A 2D 57 61 76 65 20 34 2E 36 31 00 01 95 2020-01-03 21:47:03.126 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 1 to queue - size 1 2020-01-03 21:47:03.126 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:47:03.127 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:47:03.127 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:47:03.128 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:47:03.129 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 34 2E 36 31 00 01 2020-01-03 21:47:03.130 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 2 to queue - size 2 2020-01-03 21:47:03.131 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 34 2E 36 31 00 01 2020-01-03 21:47:03.131 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:47:03.132 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.133 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:47:03.134 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.136 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 3 to queue - size 3 2020-01-03 21:47:03.136 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 34 2E 36 31 00 01 2020-01-03 21:47:03.136 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:47:03.139 [DEBUG] [al.protocol.serialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID 2020-01-03 21:47:03.140 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 4 to queue - size 4 2020-01-03 21:47:03.141 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:47:03.176 [DEBUG] [rnal.protocol.serialmessage.GetVersionMessageClass] - Got MessageGetVersion response. Version=Z-Wave 4.61, Library Type=1 2020-01-03 21:47:03.177 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 0: Transaction COMPLETED 2020-01-03 21:47:03.180 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 59ms 2020-01-03 21:47:03.181 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 0: Transaction completed 2020-01-03 21:47:03.182 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:0 DONE 2020-01-03 21:47:03.189 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:47:03.191 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:47:03.192 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC 2020-01-03 21:47:03.193 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC 2020-01-03 21:47:03.195 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:47:03.196 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.197 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:47:03.198 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:03.200 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 01 20 E7 27 62 F2 01 87 2020-01-03 21:47:03.202 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=E7 27 62 F2 01 2020-01-03 21:47:03.204 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (1): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:03.204 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.205 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:47:03.206 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=E7 27 62 F2 01 2020-01-03 21:47:03.207 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.207 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:47:03.208 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.209 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=E7 27 62 F2 01 2020-01-03 21:47:03.210 [DEBUG] [nal.protocol.serialmessage.MemoryGetIdMessageClass] - Got MessageMemoryGetId response. Home id = 0xe72762f2, Controller Node id = 1 2020-01-03 21:47:03.211 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 1: Transaction COMPLETED 2020-01-03 21:47:03.211 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 15ms 2020-01-03 21:47:03.212 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 1: Transaction completed 2020-01-03 21:47:03.213 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:1 DONE 2020-01-03 21:47:03.215 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:47:03.217 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:47:03.218 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB 2020-01-03 21:47:03.219 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB 2020-01-03 21:47:03.220 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:47:03.220 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.221 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:47:03.222 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:03.226 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 2B 01 07 05 1B 01 15 04 00 00 01 FE 87 7F 88 CF 3F C0 47 FB DF FD E0 67 00 80 80 00 80 86 00 00 00 E8 73 00 80 0F 00 00 60 5A 00 52 2020-01-03 21:47:03.230 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:03.231 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.232 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:47:03.232 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:47:03.233 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=05 1B 01 15 04 00 00 01 FE 87 7F 88 CF 3F C0 47 FB DF FD E0 67 00 80 80 00 80 86 00 00 00 E8 73 00 80 0F 00 00 60 5A 00 2020-01-03 21:47:03.233 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:47:03.241 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=05 1B 01 15 04 00 00 01 FE 87 7F 88 CF 3F C0 47 FB DF FD E0 67 00 80 80 00 80 86 00 00 00 E8 73 00 80 0F 00 00 60 5A 00 2020-01-03 21:47:03.242 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.242 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:47:03.243 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.245 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=05 1B 01 15 04 00 00 01 FE 87 7F 88 CF 3F C0 47 FB DF FD E0 67 00 80 80 00 80 86 00 00 00 E8 73 00 80 0F 00 00 60 5A 00 2020-01-03 21:47:03.246 [DEBUG] [serialmessage.SerialApiGetCapabilitiesMessageClass] - API Version = 5.27 2020-01-03 21:47:03.247 [DEBUG] [serialmessage.SerialApiGetCapabilitiesMessageClass] - Manufacture ID = 0x115 2020-01-03 21:47:03.248 [DEBUG] [serialmessage.SerialApiGetCapabilitiesMessageClass] - Device Type = 0x400 2020-01-03 21:47:03.249 [DEBUG] [serialmessage.SerialApiGetCapabilitiesMessageClass] - Device ID = 0x1 2020-01-03 21:47:03.250 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 2: Transaction COMPLETED 2020-01-03 21:47:03.252 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 5 to queue - size 3 2020-01-03 21:47:03.253 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:47:03.254 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 33ms 2020-01-03 21:47:03.254 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 2: Transaction completed 2020-01-03 21:47:03.255 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:2 DONE 2020-01-03 21:47:03.256 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:47:03.258 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:47:03.259 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65 2020-01-03 21:47:03.260 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65 2020-01-03 21:47:03.261 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:47:03.262 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.262 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:47:03.264 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:03.265 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:03.265 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.266 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 01 06 96 0F 64 2020-01-03 21:47:03.266 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:47:03.267 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:47:03.267 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:47:03.268 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 2020-01-03 21:47:03.269 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 2020-01-03 21:47:03.269 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.270 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:47:03.271 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.272 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 2020-01-03 21:47:03.273 [DEBUG] [col.serialmessage.SerialApiSetTimeoutsMessageClass] - Got SerialApiSetTimeouts response. ACK=150, BYTE=15 2020-01-03 21:47:03.274 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 3: Transaction COMPLETED 2020-01-03 21:47:03.275 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 14ms 2020-01-03 21:47:03.275 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 3: Transaction completed 2020-01-03 21:47:03.276 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:3 DONE 2020-01-03 21:47:03.278 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:47:03.279 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:47:03.280 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA 2020-01-03 21:47:03.282 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA 2020-01-03 21:47:03.283 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:47:03.284 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.284 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:47:03.285 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:03.286 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 56 01 AD 2020-01-03 21:47:03.288 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:03.288 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 2020-01-03 21:47:03.289 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.290 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:47:03.290 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 2020-01-03 21:47:03.291 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.292 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:47:03.292 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.293 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 2020-01-03 21:47:03.294 [DEBUG] [al.protocol.serialmessage.GetSucNodeIdMessageClass] - Got SUC NodeID response. 2020-01-03 21:47:03.295 [DEBUG] [al.protocol.serialmessage.GetSucNodeIdMessageClass] - NODE 1: Node is SUC. 2020-01-03 21:47:03.296 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 4: Transaction COMPLETED 2020-01-03 21:47:03.298 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Creating GET_CONTROLLER_CAPABILITIES message 2020-01-03 21:47:03.299 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 6 to queue - size 2 2020-01-03 21:47:03.300 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:47:03.301 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 17ms 2020-01-03 21:47:03.302 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 4: Transaction completed 2020-01-03 21:47:03.303 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:4 DONE 2020-01-03 21:47:03.305 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:47:03.306 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:47:03.308 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 02 FE 2020-01-03 21:47:03.309 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 02 FE 2020-01-03 21:47:03.310 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:47:03.310 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.312 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:47:03.313 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:03.313 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:03.314 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.315 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:47:03.316 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:47:03.316 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:47:03.408 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 25 01 02 06 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 CE 2020-01-03 21:47:03.413 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=06 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 2020-01-03 21:47:03.415 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=06 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 2020-01-03 21:47:03.416 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.417 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:47:03.418 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.420 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=06 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 2020-01-03 21:47:03.422 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - Got MessageSerialApiGetInitData response. 2020-01-03 21:47:03.423 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - NODE 1: Node found 2020-01-03 21:47:03.425 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API 2020-01-03 21:47:03.426 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller 2020-01-03 21:47:03.427 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------ 2020-01-03 21:47:03.428 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - # Nodes = 1 2020-01-03 21:47:03.429 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - ---------------------------------------------------------------------------- 2020-01-03 21:47:03.430 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 5: Transaction COMPLETED 2020-01-03 21:47:03.438 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 1: Init node thread start 2020-01-03 21:47:03.439 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 129ms 2020-01-03 21:47:03.439 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Starting waiting for init threads 2020-01-03 21:47:03.441 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Waiting for init thread Node_1_init 2020-01-03 21:47:03.456 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 5: Transaction completed 2020-01-03 21:47:03.457 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:5 DONE 2020-01-03 21:47:03.470 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:47:03.471 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:47:03.472 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 05 F9 2020-01-03 21:47:03.473 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 05 F9 2020-01-03 21:47:03.476 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:47:03.476 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:47:03.477 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.477 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:03.478 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 05 3C C3 2020-01-03 21:47:03.478 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:03.480 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=3C 2020-01-03 21:47:03.481 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.482 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:47:03.483 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=3C 2020-01-03 21:47:03.484 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.485 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:47:03.486 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.487 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=3C 2020-01-03 21:47:03.489 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Controller is secondary = false 2020-01-03 21:47:03.489 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Controller is on other network = false 2020-01-03 21:47:03.490 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Node ID Server is present = false 2020-01-03 21:47:03.491 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Controller is real primary = true 2020-01-03 21:47:03.492 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Controller is SUC = true 2020-01-03 21:47:03.493 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 6: Transaction COMPLETED 2020-01-03 21:47:03.494 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 18ms 2020-01-03 21:47:03.495 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 6: Transaction completed 2020-01-03 21:47:03.495 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:6 DONE 2020-01-03 21:47:03.497 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:47:03.500 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:47:03.796 [DEBUG] [ternal.protocol.initialization.ZWaveNodeSerializer] - NODE 1: Serializing from file /var/lib/openhab2/zwave/network_e72762f2__node_1.xml 2020-01-03 21:47:03.828 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 1: Restore from config: Ok. 2020-01-03 21:47:03.858 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-01-03 21:47:03.864 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-01-03 21:47:03.866 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Starting initialisation from EMPTYNODE 2020-01-03 21:47:03.886 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 1: Init node thread finished 2020-01-03 21:47:03.886 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to IDENTIFY_NODE 2020-01-03 21:47:03.887 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: Initialisation starting 2020-01-03 21:47:03.889 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Init thread Node_1_init complete 2020-01-03 21:47:03.890 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - All init threads complete 2020-01-03 21:47:03.891 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Controller: Incoming Network State Event true 2020-01-03 21:47:03.892 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@825064 2020-01-03 21:47:03.902 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 7 to queue - size 1 2020-01-03 21:47:03.904 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:47:03.905 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 01 BB 2020-01-03 21:47:03.906 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 01 BB 2020-01-03 21:47:03.907 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:47:03.908 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.931 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:47:03.933 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:03.936 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 16 01 02 02 01 73 2020-01-03 21:47:03.937 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:03.938 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.939 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:47:03.940 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:47:03.941 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:47:03.942 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 2020-01-03 21:47:03.943 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 2020-01-03 21:47:03.944 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.945 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:47:03.945 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:47:03.946 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 2020-01-03 21:47:03.947 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: ProtocolInfo 2020-01-03 21:47:03.948 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Listening = true 2020-01-03 21:47:03.949 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Routing = true 2020-01-03 21:47:03.950 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Beaming = true 2020-01-03 21:47:03.951 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Version = 4 2020-01-03 21:47:03.952 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: FLIRS = false 2020-01-03 21:47:03.953 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Security = false 2020-01-03 21:47:03.953 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Max Baud = 40000 2020-01-03 21:47:03.956 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Basic = BASIC_TYPE_STATIC_CONTROLLER 2020-01-03 21:47:03.957 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Generic = GENERIC_TYPE_STATIC_CONTROLLER 2020-01-03 21:47:03.958 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Specific = SPECIFIC_TYPE_PC_CONTROLLER 2020-01-03 21:47:03.960 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class COMMAND_CLASS_NO_OPERATION 2020-01-03 21:47:03.973 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-01-03 21:47:03.974 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Version = 1, version set. Enabling extra functionality. 2020-01-03 21:47:03.975 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 1: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes. 2020-01-03 21:47:03.976 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class COMMAND_CLASS_BASIC 2020-01-03 21:47:03.980 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-01-03 21:47:03.981 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 1: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes. 2020-01-03 21:47:03.982 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 7: Transaction COMPLETED 2020-01-03 21:47:03.983 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 75ms 2020-01-03 21:47:03.984 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 7: Transaction completed 2020-01-03 21:47:03.985 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:7 DONE 2020-01-03 21:47:03.986 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:47:03.986 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 7: Transaction event listener: DONE: DONE -> 2020-01-03 21:47:03.987 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:47:03.990 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1e5ccc4 2020-01-03 21:47:03.991 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init transaction completed with response COMPLETE 2020-01-03 21:47:03.992 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: FAILED_CHECK - Controller - terminating initialisation 2020-01-03 21:47:03.993 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to DONE 2020-01-03 21:47:03.994 [DEBUG] [ternal.protocol.initialization.ZWaveNodeSerializer] - NODE 1: Serializing to file /var/lib/openhab2/zwave/network_e72762f2__node_1.xml 2020-01-03 21:47:11.214 [DEBUG] [openhab.binding.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:device has no references! 2020-01-03 21:47:11.221 [DEBUG] [openhab.binding.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:serial_zstick has no references! 2020-01-03 21:47:11.558 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:4849599d 2020-01-03 21:47:11.558 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do 2020-01-03 21:47:11.561 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:4849599d 2020-01-03 21:47:11.562 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 1 2020-01-03 21:47:11.567 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event listener added. 2020-01-03 21:47:11.568 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - ZWave controller start inclusion 2020-01-03 21:47:11.571 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:false. 2020-01-03 21:47:11.572 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 8 to queue - size 1 2020-01-03 21:47:11.572 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:47:11.574 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 81 01 30 2020-01-03 21:47:11.575 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 81 01 30 2020-01-03 21:47:11.576 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:47:11.577 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:47:11.577 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 8: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 1 2020-01-03 21:47:11.578 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:11.579 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:47:11.580 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 8: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 1 2020-01-03 21:47:11.581 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 01 01 00 00 B2 2020-01-03 21:47:11.581 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:47:11.582 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:47:11.583 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:47:11.584 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=1, payload=01 01 00 00 2020-01-03 21:47:11.585 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=1, payload=01 01 00 00 2020-01-03 21:47:11.586 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 8: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 1 2020-01-03 21:47:11.587 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:47:11.588 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 8: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 1 2020-01-03 21:47:11.589 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking TID 8: (Callback 1) 2020-01-03 21:47:11.590 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-01-03 21:47:11.591 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Correlated to TID 8: callback 1 2020-01-03 21:47:11.592 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=1, payload=01 01 00 00 2020-01-03 21:47:11.593 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready. 2020-01-03 21:47:11.595 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart 2020-01-03 21:47:11.597 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 8: Transaction COMPLETED 2020-01-03 21:47:11.598 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 20ms 2020-01-03 21:47:11.598 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 8: Transaction completed 2020-01-03 21:47:11.599 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:8 DONE 2020-01-03 21:47:11.607 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:47:11.608 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:50:36.833 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - Creating ZWave discovery service for zwave:serial_zstick:4849599d with scan time of 60 2020-01-03 21:50:36.835 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Active zwave:serial_zstick:4849599d 2020-01-03 21:50:36.836 [INFO ] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null 2020-01-03 21:50:37.093 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller. 2020-01-03 21:50:37.096 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:4849599d. 2020-01-03 21:50:37.099 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 5 hours time. 2020-01-03 21:50:37.106 [INFO ] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0' 2020-01-03 21:50:37.148 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Starting receive thread 2020-01-03 21:50:37.153 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive 2020-01-03 21:50:37.155 [INFO ] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Serial port is initialized 2020-01-03 21:50:37.156 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller 2020-01-03 21:50:37.202 [INFO ] [ab.binding.zwave.internal.protocol.ZWaveController] - Starting ZWave controller 2020-01-03 21:50:37.202 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:50:37.203 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:50:37.204 [INFO ] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false. 2020-01-03 21:50:37.210 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event listener added. 2020-01-03 21:50:37.213 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event listener added. 2020-01-03 21:50:40.211 [DEBUG] [ernal.protocol.ZWaveController$InitializeDelayTask] - Initialising network 2020-01-03 21:50:40.256 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 0 to queue - size 1 2020-01-03 21:50:40.257 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:50:40.269 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9 2020-01-03 21:50:40.271 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9 2020-01-03 21:50:40.274 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:50:40.276 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:50:40.276 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.279 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:50:40.281 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:50:40.284 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.284 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 01 15 5A 2D 57 61 76 65 20 34 2E 36 31 00 01 95 2020-01-03 21:50:40.286 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 1 to queue - size 1 2020-01-03 21:50:40.286 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:50:40.287 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:50:40.288 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:50:40.290 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 34 2E 36 31 00 01 2020-01-03 21:50:40.290 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:50:40.293 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 34 2E 36 31 00 01 2020-01-03 21:50:40.295 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 2 to queue - size 2 2020-01-03 21:50:40.295 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.297 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:50:40.299 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.301 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:50:40.302 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 34 2E 36 31 00 01 2020-01-03 21:50:40.306 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 3 to queue - size 3 2020-01-03 21:50:40.307 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:50:40.313 [DEBUG] [al.protocol.serialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID 2020-01-03 21:50:40.315 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 4 to queue - size 4 2020-01-03 21:50:40.317 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:50:40.342 [DEBUG] [rnal.protocol.serialmessage.GetVersionMessageClass] - Got MessageGetVersion response. Version=Z-Wave 4.61, Library Type=1 2020-01-03 21:50:40.344 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 0: Transaction COMPLETED 2020-01-03 21:50:40.348 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 72ms 2020-01-03 21:50:40.348 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 0: Transaction completed 2020-01-03 21:50:40.350 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:0 DONE 2020-01-03 21:50:40.356 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:50:40.357 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:50:40.358 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC 2020-01-03 21:50:40.359 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC 2020-01-03 21:50:40.360 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:50:40.361 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.362 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:50:40.362 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:50:40.363 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:50:40.364 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.364 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 01 20 E7 27 62 F2 01 87 2020-01-03 21:50:40.365 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:50:40.366 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:50:40.366 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=E7 27 62 F2 01 2020-01-03 21:50:40.367 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:50:40.368 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=E7 27 62 F2 01 2020-01-03 21:50:40.369 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.370 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:50:40.371 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.372 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=E7 27 62 F2 01 2020-01-03 21:50:40.373 [DEBUG] [nal.protocol.serialmessage.MemoryGetIdMessageClass] - Got MessageMemoryGetId response. Home id = 0xe72762f2, Controller Node id = 1 2020-01-03 21:50:40.374 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 1: Transaction COMPLETED 2020-01-03 21:50:40.375 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 14ms 2020-01-03 21:50:40.376 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 1: Transaction completed 2020-01-03 21:50:40.376 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:1 DONE 2020-01-03 21:50:40.378 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:50:40.380 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:50:40.381 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB 2020-01-03 21:50:40.382 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB 2020-01-03 21:50:40.384 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:50:40.384 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.386 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:50:40.387 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:50:40.388 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:50:40.389 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.390 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:50:40.391 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:50:40.391 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 2B 01 07 05 1B 01 15 04 00 00 01 FE 87 7F 88 CF 3F C0 47 FB DF FD E0 67 00 80 80 00 80 86 00 00 00 E8 73 00 80 0F 00 00 60 5A 00 52 2020-01-03 21:50:40.392 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:50:40.397 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=05 1B 01 15 04 00 00 01 FE 87 7F 88 CF 3F C0 47 FB DF FD E0 67 00 80 80 00 80 86 00 00 00 E8 73 00 80 0F 00 00 60 5A 00 2020-01-03 21:50:40.399 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=05 1B 01 15 04 00 00 01 FE 87 7F 88 CF 3F C0 47 FB DF FD E0 67 00 80 80 00 80 86 00 00 00 E8 73 00 80 0F 00 00 60 5A 00 2020-01-03 21:50:40.400 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.400 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:50:40.401 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.403 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=05 1B 01 15 04 00 00 01 FE 87 7F 88 CF 3F C0 47 FB DF FD E0 67 00 80 80 00 80 86 00 00 00 E8 73 00 80 0F 00 00 60 5A 00 2020-01-03 21:50:40.404 [DEBUG] [serialmessage.SerialApiGetCapabilitiesMessageClass] - API Version = 5.27 2020-01-03 21:50:40.405 [DEBUG] [serialmessage.SerialApiGetCapabilitiesMessageClass] - Manufacture ID = 0x115 2020-01-03 21:50:40.405 [DEBUG] [serialmessage.SerialApiGetCapabilitiesMessageClass] - Device Type = 0x400 2020-01-03 21:50:40.406 [DEBUG] [serialmessage.SerialApiGetCapabilitiesMessageClass] - Device ID = 0x1 2020-01-03 21:50:40.407 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 2: Transaction COMPLETED 2020-01-03 21:50:40.409 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 5 to queue - size 3 2020-01-03 21:50:40.409 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:50:40.410 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 26ms 2020-01-03 21:50:40.411 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 2: Transaction completed 2020-01-03 21:50:40.411 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:2 DONE 2020-01-03 21:50:40.413 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:50:40.414 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:50:40.415 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65 2020-01-03 21:50:40.416 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65 2020-01-03 21:50:40.416 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:50:40.418 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:50:40.418 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.419 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:50:40.419 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:50:40.420 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 01 06 96 0F 64 2020-01-03 21:50:40.420 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.421 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:50:40.422 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 2020-01-03 21:50:40.422 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:50:40.423 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:50:40.424 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 2020-01-03 21:50:40.425 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.426 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:50:40.427 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.427 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 2020-01-03 21:50:40.429 [DEBUG] [col.serialmessage.SerialApiSetTimeoutsMessageClass] - Got SerialApiSetTimeouts response. ACK=150, BYTE=15 2020-01-03 21:50:40.430 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 3: Transaction COMPLETED 2020-01-03 21:50:40.431 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 14ms 2020-01-03 21:50:40.432 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 3: Transaction completed 2020-01-03 21:50:40.433 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:3 DONE 2020-01-03 21:50:40.436 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:50:40.437 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:50:40.438 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA 2020-01-03 21:50:40.440 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA 2020-01-03 21:50:40.441 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:50:40.442 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.443 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:50:40.444 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:50:40.444 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:50:40.445 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 56 01 AD 2020-01-03 21:50:40.446 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.447 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:50:40.447 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 2020-01-03 21:50:40.447 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:50:40.449 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:50:40.450 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 2020-01-03 21:50:40.451 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.451 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:50:40.452 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.453 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 2020-01-03 21:50:40.454 [DEBUG] [al.protocol.serialmessage.GetSucNodeIdMessageClass] - Got SUC NodeID response. 2020-01-03 21:50:40.455 [DEBUG] [al.protocol.serialmessage.GetSucNodeIdMessageClass] - NODE 1: Node is SUC. 2020-01-03 21:50:40.456 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 4: Transaction COMPLETED 2020-01-03 21:50:40.458 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Creating GET_CONTROLLER_CAPABILITIES message 2020-01-03 21:50:40.459 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 6 to queue - size 2 2020-01-03 21:50:40.460 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:50:40.461 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 19ms 2020-01-03 21:50:40.462 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 4: Transaction completed 2020-01-03 21:50:40.463 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:4 DONE 2020-01-03 21:50:40.463 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:50:40.466 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:50:40.466 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 02 FE 2020-01-03 21:50:40.468 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 02 FE 2020-01-03 21:50:40.469 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:50:40.470 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.471 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:50:40.471 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:50:40.472 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:50:40.473 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.474 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:50:40.475 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:50:40.476 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:50:40.567 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 25 01 02 06 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 CE 2020-01-03 21:50:40.571 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=06 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 2020-01-03 21:50:40.573 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=06 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 2020-01-03 21:50:40.574 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.575 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:50:40.576 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.578 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=06 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 2020-01-03 21:50:40.579 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - Got MessageSerialApiGetInitData response. 2020-01-03 21:50:40.581 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - NODE 1: Node found 2020-01-03 21:50:40.582 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API 2020-01-03 21:50:40.583 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller 2020-01-03 21:50:40.584 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------ 2020-01-03 21:50:40.585 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - # Nodes = 1 2020-01-03 21:50:40.586 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - ---------------------------------------------------------------------------- 2020-01-03 21:50:40.587 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 5: Transaction COMPLETED 2020-01-03 21:50:40.594 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 1: Init node thread start 2020-01-03 21:50:40.596 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 126ms 2020-01-03 21:50:40.596 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Starting waiting for init threads 2020-01-03 21:50:40.597 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Waiting for init thread Node_1_init 2020-01-03 21:50:40.597 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 5: Transaction completed 2020-01-03 21:50:40.599 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:5 DONE 2020-01-03 21:50:40.601 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:50:40.603 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:50:40.604 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 05 F9 2020-01-03 21:50:40.606 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 05 F9 2020-01-03 21:50:40.608 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:50:40.609 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:50:40.610 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.610 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:50:40.611 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:50:40.612 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 05 3C C3 2020-01-03 21:50:40.612 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.623 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=3C 2020-01-03 21:50:40.624 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:50:40.626 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=3C 2020-01-03 21:50:40.626 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.627 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:50:40.628 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:40.630 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=3C 2020-01-03 21:50:40.631 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Controller is secondary = false 2020-01-03 21:50:40.632 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Controller is on other network = false 2020-01-03 21:50:40.633 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Node ID Server is present = false 2020-01-03 21:50:40.634 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Controller is real primary = true 2020-01-03 21:50:40.635 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Controller is SUC = true 2020-01-03 21:50:40.636 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 6: Transaction COMPLETED 2020-01-03 21:50:40.637 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 28ms 2020-01-03 21:50:40.638 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 6: Transaction completed 2020-01-03 21:50:40.639 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:6 DONE 2020-01-03 21:50:40.640 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:50:40.644 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:50:40.902 [DEBUG] [ternal.protocol.initialization.ZWaveNodeSerializer] - NODE 1: Serializing from file /var/lib/openhab2/zwave/network_e72762f2__node_1.xml 2020-01-03 21:50:40.930 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 1: Restore from config: Ok. 2020-01-03 21:50:40.961 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-01-03 21:50:40.962 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-01-03 21:50:40.964 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Starting initialisation from EMPTYNODE 2020-01-03 21:50:40.975 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 1: Init node thread finished 2020-01-03 21:50:40.975 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to IDENTIFY_NODE 2020-01-03 21:50:40.976 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Init thread Node_1_init complete 2020-01-03 21:50:40.976 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: Initialisation starting 2020-01-03 21:50:40.977 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - All init threads complete 2020-01-03 21:50:40.978 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Controller: Incoming Network State Event true 2020-01-03 21:50:40.978 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@840096 2020-01-03 21:50:40.983 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 7 to queue - size 1 2020-01-03 21:50:40.985 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:50:40.987 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 01 BB 2020-01-03 21:50:40.988 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 01 BB 2020-01-03 21:50:40.990 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 21:50:40.991 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:41.023 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 21:50:41.024 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:50:41.026 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 16 01 02 02 01 73 2020-01-03 21:50:41.029 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 21:50:41.030 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:41.030 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 21:50:41.031 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:50:41.032 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 21:50:41.033 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 2020-01-03 21:50:41.035 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 2020-01-03 21:50:41.036 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:41.037 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 21:50:41.037 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 21:50:41.038 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 2020-01-03 21:50:41.039 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: ProtocolInfo 2020-01-03 21:50:41.040 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Listening = true 2020-01-03 21:50:41.041 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Routing = true 2020-01-03 21:50:41.041 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Beaming = true 2020-01-03 21:50:41.042 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Version = 4 2020-01-03 21:50:41.042 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: FLIRS = false 2020-01-03 21:50:41.043 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Security = false 2020-01-03 21:50:41.043 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Max Baud = 40000 2020-01-03 21:50:41.044 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Basic = BASIC_TYPE_STATIC_CONTROLLER 2020-01-03 21:50:41.045 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Generic = GENERIC_TYPE_STATIC_CONTROLLER 2020-01-03 21:50:41.046 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Specific = SPECIFIC_TYPE_PC_CONTROLLER 2020-01-03 21:50:41.047 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class COMMAND_CLASS_NO_OPERATION 2020-01-03 21:50:41.048 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-01-03 21:50:41.049 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Version = 1, version set. Enabling extra functionality. 2020-01-03 21:50:41.050 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 1: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes. 2020-01-03 21:50:41.051 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class COMMAND_CLASS_BASIC 2020-01-03 21:50:41.052 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-01-03 21:50:41.053 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 1: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes. 2020-01-03 21:50:41.054 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 7: Transaction COMPLETED 2020-01-03 21:50:41.055 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 64ms 2020-01-03 21:50:41.055 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 7: Transaction completed 2020-01-03 21:50:41.056 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:7 DONE 2020-01-03 21:50:41.057 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 21:50:41.057 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 7: Transaction event listener: DONE: DONE -> 2020-01-03 21:50:41.057 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 21:50:41.061 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1bcdd04 2020-01-03 21:50:41.061 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init transaction completed with response COMPLETE 2020-01-03 21:50:41.062 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: FAILED_CHECK - Controller - terminating initialisation 2020-01-03 21:50:41.063 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to DONE 2020-01-03 21:50:41.063 [DEBUG] [ternal.protocol.initialization.ZWaveNodeSerializer] - NODE 1: Serializing to file /var/lib/openhab2/zwave/network_e72762f2__node_1.xml