2020-01-03 22:29:37.093 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - Creating ZWave discovery service for zwave:serial_zstick:4849599d with scan time of 60 2020-01-03 22:29:37.094 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Active zwave:serial_zstick:4849599d 2020-01-03 22:29:37.095 [INFO ] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null 2020-01-03 22:29:37.283 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller. 2020-01-03 22:29:37.287 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:4849599d. 2020-01-03 22:29:37.290 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 4 hours time. 2020-01-03 22:29:37.296 [INFO ] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0' 2020-01-03 22:29:37.339 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Starting receive thread 2020-01-03 22:29:37.344 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive 2020-01-03 22:29:37.346 [INFO ] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Serial port is initialized 2020-01-03 22:29:37.347 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller 2020-01-03 22:29:37.389 [INFO ] [ab.binding.zwave.internal.protocol.ZWaveController] - Starting ZWave controller 2020-01-03 22:29:37.389 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:37.390 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:29:37.390 [INFO ] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false. 2020-01-03 22:29:37.392 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event listener added. 2020-01-03 22:29:37.394 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event listener added. 2020-01-03 22:29:40.393 [DEBUG] [ernal.protocol.ZWaveController$InitializeDelayTask] - Initialising network 2020-01-03 22:29:40.590 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 0 to queue - size 1 2020-01-03 22:29:40.591 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:29:40.598 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9 2020-01-03 22:29:40.599 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9 2020-01-03 22:29:40.601 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 22:29:40.602 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 22:29:40.602 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.604 [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 22:29:40.605 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 22:29:40.607 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.607 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 22:29:40.607 [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 22:29:40.608 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:40.608 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 1 to queue - size 1 2020-01-03 22:29:40.609 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:29:40.610 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:29:40.611 [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 22:29:40.613 [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 22:29:40.614 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.615 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 2 to queue - size 2 2020-01-03 22:29:40.616 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:29:40.617 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 22:29:40.618 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.619 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 3 to queue - size 3 2020-01-03 22:29:40.619 [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 22:29:40.619 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:29:40.622 [DEBUG] [al.protocol.serialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID 2020-01-03 22:29:40.623 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 4 to queue - size 4 2020-01-03 22:29:40.624 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:29:40.643 [DEBUG] [rnal.protocol.serialmessage.GetVersionMessageClass] - Got MessageGetVersion response. Version=Z-Wave 4.61, Library Type=1 2020-01-03 22:29:40.644 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 0: Transaction COMPLETED 2020-01-03 22:29:40.645 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 43ms 2020-01-03 22:29:40.646 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 0: Transaction completed 2020-01-03 22:29:40.647 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:0 DONE 2020-01-03 22:29:40.653 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:40.654 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:29:40.655 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC 2020-01-03 22:29:40.656 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC 2020-01-03 22:29:40.657 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 22:29:40.658 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 22:29:40.658 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.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 22:29:40.660 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 22:29:40.661 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.661 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 22:29:40.661 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 01 20 E7 27 62 F2 01 87 2020-01-03 22:29:40.662 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:40.663 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:29:40.664 [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 22:29:40.665 [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 22:29:40.666 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.667 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 22:29:40.667 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 1: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.668 [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 22:29:40.669 [DEBUG] [nal.protocol.serialmessage.MemoryGetIdMessageClass] - Got MessageMemoryGetId response. Home id = 0xe72762f2, Controller Node id = 1 2020-01-03 22:29:40.670 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 1: Transaction COMPLETED 2020-01-03 22:29:40.671 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 14ms 2020-01-03 22:29:40.672 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 1: Transaction completed 2020-01-03 22:29:40.673 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:1 DONE 2020-01-03 22:29:40.675 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:40.676 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:29:40.677 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB 2020-01-03 22:29:40.678 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB 2020-01-03 22:29:40.679 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 22:29:40.680 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.681 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 22:29:40.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 22:29:40.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 22:29:40.685 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.685 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 22:29:40.686 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:40.687 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:29:40.688 [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 22:29:40.693 [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 22:29:40.695 [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 22:29:40.696 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.697 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 22:29:40.697 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 2: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.699 [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 22:29:40.700 [DEBUG] [serialmessage.SerialApiGetCapabilitiesMessageClass] - API Version = 5.27 2020-01-03 22:29:40.701 [DEBUG] [serialmessage.SerialApiGetCapabilitiesMessageClass] - Manufacture ID = 0x115 2020-01-03 22:29:40.701 [DEBUG] [serialmessage.SerialApiGetCapabilitiesMessageClass] - Device Type = 0x400 2020-01-03 22:29:40.702 [DEBUG] [serialmessage.SerialApiGetCapabilitiesMessageClass] - Device ID = 0x1 2020-01-03 22:29:40.703 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 2: Transaction COMPLETED 2020-01-03 22:29:40.705 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 5 to queue - size 3 2020-01-03 22:29:40.705 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:29:40.706 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 26ms 2020-01-03 22:29:40.706 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 2: Transaction completed 2020-01-03 22:29:40.707 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:2 DONE 2020-01-03 22:29:40.708 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:40.709 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:29:40.710 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65 2020-01-03 22:29:40.711 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65 2020-01-03 22:29:40.712 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 22:29:40.712 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.714 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 22:29:40.716 [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 22:29:40.716 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 22:29:40.717 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.717 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 01 06 96 0F 64 2020-01-03 22:29:40.717 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 22:29:40.718 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:40.719 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:29:40.719 [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 22:29:40.720 [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 22:29:40.721 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.722 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 22:29:40.722 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 3: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.723 [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 22:29:40.724 [DEBUG] [col.serialmessage.SerialApiSetTimeoutsMessageClass] - Got SerialApiSetTimeouts response. ACK=150, BYTE=15 2020-01-03 22:29:40.725 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 3: Transaction COMPLETED 2020-01-03 22:29:40.726 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 14ms 2020-01-03 22:29:40.726 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 3: Transaction completed 2020-01-03 22:29:40.727 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:3 DONE 2020-01-03 22:29:40.729 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:40.730 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:29:40.731 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA 2020-01-03 22:29:40.732 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA 2020-01-03 22:29:40.733 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 22:29:40.734 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.735 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 22:29:40.736 [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 22:29:40.737 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 22:29:40.738 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.738 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 56 01 AD 2020-01-03 22:29:40.738 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 22:29:40.739 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:40.740 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:29:40.740 [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 22:29:40.741 [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 22:29:40.741 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.742 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 22:29:40.743 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 4: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.743 [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 22:29:40.744 [DEBUG] [al.protocol.serialmessage.GetSucNodeIdMessageClass] - Got SUC NodeID response. 2020-01-03 22:29:40.745 [DEBUG] [al.protocol.serialmessage.GetSucNodeIdMessageClass] - NODE 1: Node is SUC. 2020-01-03 22:29:40.746 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 4: Transaction COMPLETED 2020-01-03 22:29:40.747 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Creating GET_CONTROLLER_CAPABILITIES message 2020-01-03 22:29:40.748 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 6 to queue - size 2 2020-01-03 22:29:40.749 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:29:40.749 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 15ms 2020-01-03 22:29:40.750 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 4: Transaction completed 2020-01-03 22:29:40.750 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:4 DONE 2020-01-03 22:29:40.751 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:40.753 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:29:40.754 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 02 FE 2020-01-03 22:29:40.755 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 02 FE 2020-01-03 22:29:40.755 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 22:29:40.756 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.757 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 22:29:40.759 [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 22:29:40.760 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 22:29:40.760 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.761 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 22:29:40.761 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:40.762 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:29:40.854 [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 22:29:40.858 [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 22:29:40.860 [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 22:29:40.861 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.862 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 22:29:40.862 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 5: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.864 [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 22:29:40.865 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - Got MessageSerialApiGetInitData response. 2020-01-03 22:29:40.866 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - NODE 1: Node found 2020-01-03 22:29:40.867 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API 2020-01-03 22:29:40.868 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller 2020-01-03 22:29:40.869 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------ 2020-01-03 22:29:40.869 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - # Nodes = 1 2020-01-03 22:29:40.870 [DEBUG] [col.serialmessage.SerialApiGetInitDataMessageClass] - ---------------------------------------------------------------------------- 2020-01-03 22:29:40.871 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 5: Transaction COMPLETED 2020-01-03 22:29:40.878 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 1: Init node thread start 2020-01-03 22:29:40.880 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 123ms 2020-01-03 22:29:40.880 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Starting waiting for init threads 2020-01-03 22:29:40.881 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 5: Transaction completed 2020-01-03 22:29:40.882 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Waiting for init thread Node_1_init 2020-01-03 22:29:40.882 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:5 DONE 2020-01-03 22:29:40.884 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:40.886 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:29:40.887 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 05 F9 2020-01-03 22:29:40.888 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 05 F9 2020-01-03 22:29:40.890 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 22:29:40.891 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.892 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 22:29:40.893 [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 22:29:40.894 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 22:29:40.898 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.898 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 05 3C C3 2020-01-03 22:29:40.898 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 22:29:40.899 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:40.900 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:29:40.900 [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 22:29:40.901 [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 22:29:40.902 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.903 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 22:29:40.904 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 6: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:40.905 [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 22:29:40.906 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Controller is secondary = false 2020-01-03 22:29:40.908 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Controller is on other network = false 2020-01-03 22:29:40.908 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Node ID Server is present = false 2020-01-03 22:29:40.909 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Controller is real primary = true 2020-01-03 22:29:40.910 [DEBUG] [erialmessage.GetControllerCapabilitiesMessageClass] - Controller is SUC = true 2020-01-03 22:29:40.911 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 6: Transaction COMPLETED 2020-01-03 22:29:40.912 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 21ms 2020-01-03 22:29:40.913 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 6: Transaction completed 2020-01-03 22:29:40.914 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:6 DONE 2020-01-03 22:29:40.915 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:40.919 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:29:41.179 [DEBUG] [ternal.protocol.initialization.ZWaveNodeSerializer] - NODE 1: Serializing from file /var/lib/openhab2/zwave/network_e72762f2__node_1.xml 2020-01-03 22:29:41.228 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 1: Restore from config: Ok. 2020-01-03 22:29:41.280 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-01-03 22:29:41.280 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-01-03 22:29:41.281 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Starting initialisation from EMPTYNODE 2020-01-03 22:29:41.293 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - NODE 1: Init node thread finished 2020-01-03 22:29:41.294 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to IDENTIFY_NODE 2020-01-03 22:29:41.294 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Init thread Node_1_init complete 2020-01-03 22:29:41.295 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: Initialisation starting 2020-01-03 22:29:41.295 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - All init threads complete 2020-01-03 22:29:41.296 [DEBUG] [enhab.binding.zwave.handler.ZWaveControllerHandler] - Controller: Incoming Network State Event true 2020-01-03 22:29:41.297 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@12cdce9 2020-01-03 22:29:41.314 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 7 to queue - size 1 2020-01-03 22:29:41.315 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:29:41.317 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 01 BB 2020-01-03 22:29:41.318 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 01 BB 2020-01-03 22:29:41.319 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 22:29:41.322 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:41.340 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 22:29:41.341 [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 22:29:41.343 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 16 01 02 02 01 73 2020-01-03 22:29:41.345 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 22:29:41.346 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:41.346 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 22:29:41.346 [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 22:29:41.347 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:41.348 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:29:41.350 [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 22:29:41.351 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:41.352 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 22:29:41.352 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:29:41.354 [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 22:29:41.355 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: ProtocolInfo 2020-01-03 22:29:41.356 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Listening = true 2020-01-03 22:29:41.356 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Routing = true 2020-01-03 22:29:41.357 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Beaming = true 2020-01-03 22:29:41.358 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Version = 4 2020-01-03 22:29:41.358 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: FLIRS = false 2020-01-03 22:29:41.359 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Security = false 2020-01-03 22:29:41.359 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Max Baud = 40000 2020-01-03 22:29:41.361 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Basic = BASIC_TYPE_STATIC_CONTROLLER 2020-01-03 22:29:41.362 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Generic = GENERIC_TYPE_STATIC_CONTROLLER 2020-01-03 22:29:41.363 [DEBUG] [al.protocol.serialmessage.IdentifyNodeMessageClass] - NODE 1: Specific = SPECIFIC_TYPE_PC_CONTROLLER 2020-01-03 22:29:41.365 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class COMMAND_CLASS_NO_OPERATION 2020-01-03 22:29:41.380 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-01-03 22:29:41.381 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Version = 1, version set. Enabling extra functionality. 2020-01-03 22:29:41.382 [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 22:29:41.383 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class COMMAND_CLASS_BASIC 2020-01-03 22:29:41.389 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-01-03 22:29:41.390 [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 22:29:41.391 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 7: Transaction COMPLETED 2020-01-03 22:29:41.392 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 69ms 2020-01-03 22:29:41.392 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 7: Transaction completed 2020-01-03 22:29:41.393 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:7 DONE 2020-01-03 22:29:41.394 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:41.395 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 7: Transaction event listener: DONE: DONE -> 2020-01-03 22:29:41.395 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:29:41.400 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@14e6e20 2020-01-03 22:29:41.401 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init transaction completed with response COMPLETE 2020-01-03 22:29:41.402 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: FAILED_CHECK - Controller - terminating initialisation 2020-01-03 22:29:41.403 [DEBUG] [protocol.initialization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to DONE 2020-01-03 22:29:41.404 [DEBUG] [ternal.protocol.initialization.ZWaveNodeSerializer] - NODE 1: Serializing to file /var/lib/openhab2/zwave/network_e72762f2__node_1.xml 2020-01-03 22:29:53.045 [DEBUG] [openhab.binding.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:device has no references! 2020-01-03 22:29:53.052 [DEBUG] [openhab.binding.zwave.internal.ZWaveConfigProvider] - ZWave product zwave:serial_zstick has no references! 2020-01-03 22:29:53.300 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:4849599d 2020-01-03 22:29:53.301 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do 2020-01-03 22:29:53.304 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:4849599d 2020-01-03 22:29:53.305 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 1 2020-01-03 22:29:53.310 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event listener added. 2020-01-03 22:29:53.312 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - ZWave controller start inclusion 2020-01-03 22:29:53.315 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:false. 2020-01-03 22:29:53.316 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 8 to queue - size 1 2020-01-03 22:29:53.317 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:29:53.318 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 81 01 30 2020-01-03 22:29:53.320 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 81 01 30 2020-01-03 22:29:53.321 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 22:29:53.322 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 22:29:53.323 [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 22:29:53.323 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 8: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 1 2020-01-03 22:29:53.324 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 22:29:53.324 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null 2020-01-03 22:29:53.325 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 22:29:53.326 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:53.326 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 01 01 00 00 B2 2020-01-03 22:29:53.327 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:29:53.328 [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 22:29:53.330 [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 22:29:53.331 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 8: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 1 2020-01-03 22:29:53.332 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 22:29:53.332 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 8: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 1 2020-01-03 22:29:53.333 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking TID 8: (Callback 1) 2020-01-03 22:29:53.334 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-01-03 22:29:53.335 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Correlated to TID 8: callback 1 2020-01-03 22:29:53.337 [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 22:29:53.338 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready. 2020-01-03 22:29:53.340 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart 2020-01-03 22:29:53.341 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 8: Transaction COMPLETED 2020-01-03 22:29:53.342 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 19ms 2020-01-03 22:29:53.343 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 8: Transaction completed 2020-01-03 22:29:53.343 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:8 DONE 2020-01-03 22:29:53.346 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:29:53.347 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:30:41.618 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:4849599d 2020-01-03 22:30:41.621 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeStart 2020-01-03 22:30:41.623 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode. 2020-01-03 22:30:41.626 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 9 to queue - size 1 2020-01-03 22:30:41.627 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:30:41.631 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 02 B7 2020-01-03 22:30:41.633 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 02 B7 2020-01-03 22:30:41.636 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 22:30:41.638 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 9: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 2 2020-01-03 22:30:41.639 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 22:30:41.640 [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 22:30:41.644 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 22:30:41.645 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:4849599d 2020-01-03 22:30:41.645 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 9: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 2 2020-01-03 22:30:41.646 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 22:30:41.646 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave inclusion process already running - aborted 2020-01-03 22:30:41.647 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:30:41.648 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:30:41.689 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 02 06 00 00 B6 2020-01-03 22:30:41.692 [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 22:30:41.693 [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 22:30:41.694 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 9: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 2 2020-01-03 22:30:41.694 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 22:30:41.695 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 9: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 2 2020-01-03 22:30:41.695 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking TID 9: (Callback 2) 2020-01-03 22:30:41.696 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-01-03 22:30:41.696 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Correlated to TID 9: callback 2 2020-01-03 22:30:41.697 [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 22:30:41.698 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Add Node: Done. 2020-01-03 22:30:41.699 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeDone, new event IncludeDone 2020-01-03 22:30:41.700 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode. 2020-01-03 22:30:41.700 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 10 to queue - size 1 2020-01-03 22:30:41.701 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:30:41.702 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - ZWave controller end exclusion 2020-01-03 22:30:41.703 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWaveController include done 2020-01-03 22:30:41.703 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 9: Advanced to DONE 2020-01-03 22:30:41.704 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 67ms 2020-01-03 22:30:41.705 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 9: Transaction completed 2020-01-03 22:30:41.706 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:9 DONE 2020-01-03 22:30:41.706 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:30:41.707 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:30:41.709 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5 2020-01-03 22:30:41.711 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5 2020-01-03 22:30:41.711 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 22:30:41.712 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 10: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:30:41.713 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 22:30:41.714 [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 22:30:41.715 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 22:30:41.716 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 10: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:30:41.717 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 22:30:41.717 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:30:41.718 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:30:43.697 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:4849599d 2020-01-03 22:30:43.702 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do 2020-01-03 22:30:43.704 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:4849599d 2020-01-03 22:30:43.704 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 1 2020-01-03 22:30:43.706 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Event listener added. 2020-01-03 22:30:43.707 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - ZWave controller start inclusion 2020-01-03 22:30:43.707 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:false. 2020-01-03 22:30:43.708 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 11 to queue - size 1 2020-01-03 22:30:43.709 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:30:46.713 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 255: TID 10: Timeout at state WAIT_REQUEST. 3 retries remaining. 2020-01-03 22:30:46.714 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - TID 10: Transaction is current transaction, so clearing!!!!! 2020-01-03 22:30:46.719 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 10: Transaction CANCELLED 2020-01-03 22:30:46.720 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:10 CANCELLED 2020-01-03 22:30:46.721 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:30:46.723 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 81 04 35 2020-01-03 22:30:46.724 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 81 04 35 2020-01-03 22:30:46.728 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 22:30:46.728 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 22:30:46.729 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 11: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4 2020-01-03 22:30:46.729 [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 22:30:46.730 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 22:30:46.730 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 11: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4 2020-01-03 22:30:46.731 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 04 01 00 00 B7 2020-01-03 22:30:46.733 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=4, payload=04 01 00 00 2020-01-03 22:30:46.731 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 22:30:46.740 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=4, payload=04 01 00 00 2020-01-03 22:30:46.741 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 11: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4 2020-01-03 22:30:46.741 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 22:30:46.742 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 11: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4 2020-01-03 22:30:46.743 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking TID 11: (Callback 4) 2020-01-03 22:30:46.743 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-01-03 22:30:46.744 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Correlated to TID 11: callback 4 2020-01-03 22:30:46.745 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=4, payload=04 01 00 00 2020-01-03 22:30:46.746 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready. 2020-01-03 22:30:46.746 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart 2020-01-03 22:30:46.747 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 11: Transaction COMPLETED 2020-01-03 22:30:46.748 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 20ms 2020-01-03 22:30:46.748 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 11: Transaction completed 2020-01-03 22:30:46.749 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:11 DONE 2020-01-03 22:30:46.751 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:30:46.751 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:31:11.021 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:4849599d 2020-01-03 22:31:11.023 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeStart 2020-01-03 22:31:11.025 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode. 2020-01-03 22:31:11.027 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 12 to queue - size 1 2020-01-03 22:31:11.028 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:31:11.031 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 05 B0 2020-01-03 22:31:11.033 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 05 B0 2020-01-03 22:31:11.035 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 22:31:11.036 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 12: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 5 2020-01-03 22:31:11.037 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 22:31:11.039 [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 22:31:11.040 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 22:31:11.045 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 5 2020-01-03 22:31:11.046 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:4849599d 2020-01-03 22:31:11.047 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 22:31:11.048 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:31:11.048 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave inclusion process already running - aborted 2020-01-03 22:31:11.049 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:31:11.089 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 05 06 00 00 B1 2020-01-03 22:31:11.093 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=5, payload=05 06 00 00 2020-01-03 22:31:11.095 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=5, payload=05 06 00 00 2020-01-03 22:31:11.096 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 5 2020-01-03 22:31:11.097 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-01-03 22:31:11.098 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Last transaction: TID 12: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 5 2020-01-03 22:31:11.100 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Checking TID 12: (Callback 5) 2020-01-03 22:31:11.101 [DEBUG] [ernal.protocol.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-01-03 22:31:11.103 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Correlated to TID 12: callback 5 2020-01-03 22:31:11.105 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=5, payload=05 06 00 00 2020-01-03 22:31:11.107 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Add Node: Done. 2020-01-03 22:31:11.108 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeDone, new event IncludeDone 2020-01-03 22:31:11.110 [DEBUG] [nternal.protocol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode. 2020-01-03 22:31:11.111 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Added 13 to queue - size 1 2020-01-03 22:31:11.113 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:31:11.114 [DEBUG] [g.zwave.internal.protocol.ZWaveInclusionController] - ZWave controller end exclusion 2020-01-03 22:31:11.116 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWaveController include done 2020-01-03 22:31:11.117 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - TID 12: Advanced to DONE 2020-01-03 22:31:11.119 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 83ms 2020-01-03 22:31:11.120 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: TID 12: Transaction completed 2020-01-03 22:31:11.122 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:12 DONE 2020-01-03 22:31:11.123 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:31:11.127 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:31:11.129 [DEBUG] [nhab.binding.zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5 2020-01-03 22:31:11.132 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5 2020-01-03 22:31:11.133 [DEBUG] [g.openhab.binding.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-01-03 22:31:11.135 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 13: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:31:11.135 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-01-03 22:31:11.137 [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 22:31:11.139 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-01-03 22:31:11.141 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction TID 13: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0 2020-01-03 22:31:11.143 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-01-03 22:31:11.145 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-01-03 22:31:11.147 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-01-03 22:31:16.137 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - NODE 255: TID 13: Timeout at state WAIT_REQUEST. 3 retries remaining. 2020-01-03 22:31:16.138 [DEBUG] [ocol.ZWaveTransactionManager$ZWaveTransactionTimer] - TID 13: Transaction is current transaction, so clearing!!!!! 2020-01-03 22:31:16.141 [DEBUG] [b.binding.zwave.internal.protocol.ZWaveTransaction] - TID 13: Transaction CANCELLED 2020-01-03 22:31:16.142 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:13 CANCELLED 2020-01-03 22:31:16.147 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-01-03 22:32:11.045 [DEBUG] [nhab.binding.zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:4849599d 2020-01-03 22:32:11.047 [DEBUG] [ab.binding.zwave.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do