==> /var/log/openhab2/events.log <== 2020-02-11 14:01:23.138 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:cf541806' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR) 2020-02-11 14:01:27.678 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node10' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED) 2020-02-11 14:01:27.680 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node12' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED) ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:27.678 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - Creating ZWave discovery service for zwave:serial_zstick:cf541806 with scan time of 60 ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:27.685 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node13' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED) ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:27.684 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Active zwave:serial_zstick:cf541806 ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:27.686 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node15' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED) ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:27.686 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:27.736 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:cf541806' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:27.744 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller. 2020-02-11 14:01:27.745 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:cf541806. ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:27.762 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:cf541806' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline 2020-02-11 14:01:27.814 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node15' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING 2020-02-11 14:01:27.817 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node12' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:27.823 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:cf541806:node15. ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:27.827 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node15' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline 2020-02-11 14:01:27.836 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node13' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING 2020-02-11 14:01:27.838 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node10' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING 2020-02-11 14:01:27.840 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node2' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:27.843 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:cf541806:node12. ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:27.847 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node12' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline 2020-02-11 14:01:27.851 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node3' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:27.858 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:cf541806:node2. ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:27.862 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node2' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:27.864 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:cf541806:node2:sensor_temperature linked - polling started. 2020-02-11 14:01:27.864 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:cf541806:node2:sensor_relhumidity linked - polling started. 2020-02-11 14:01:27.864 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:cf541806:node2:sensor_luminance linked - polling started. 2020-02-11 14:01:27.865 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:cf541806:node2:battery-level linked - polling started. 2020-02-11 14:01:27.866 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:cf541806:node13. 2020-02-11 14:01:27.869 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:cf541806:node10. ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:27.869 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node13' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline 2020-02-11 14:01:27.960 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node10' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:27.963 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Channel zwave:device:cf541806:node10:battery-level linked - polling started. 2020-02-11 14:01:27.963 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Channel zwave:device:cf541806:node10:alarm_flood linked - polling started. 2020-02-11 14:01:27.965 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:cf541806:node3. ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:27.970 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node3' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:27.972 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:cf541806:node3:meter_voltage linked - polling started. 2020-02-11 14:01:32.763 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0' 2020-02-11 14:01:32.780 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Starting receive thread 2020-02-11 14:01:32.782 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized 2020-02-11 14:01:32.784 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive 2020-02-11 14:01:32.789 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller 2020-02-11 14:01:32.795 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller 2020-02-11 14:01:32.798 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false. 2020-02-11 14:01:32.803 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added. 2020-02-11 14:01:32.803 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:32.810 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added. 2020-02-11 14:01:32.812 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 12 hours time. 2020-02-11 14:01:32.811 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:35.804 [DEBUG] [.ZWaveController$InitializeDelayTask] - Initialising network 2020-02-11 14:01:35.810 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 306 to queue - size 1 2020-02-11 14:01:35.811 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:35.814 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9 2020-02-11 14:01:35.816 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9 2020-02-11 14:01:35.821 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:35.823 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:35.825 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:35.824 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 306: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.830 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:35.831 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 307 to queue - size 1 2020-02-11 14:01:35.832 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 01 15 5A 2D 57 61 76 65 20 34 2E 36 31 00 01 95 2020-02-11 14:01:35.832 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 306: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.834 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:35.836 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:35.838 [DEBUG] [nal.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-02-11 14:01:35.838 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 308 to queue - size 2 2020-02-11 14:01:35.840 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:35.843 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 309 to queue - size 3 2020-02-11 14:01:35.846 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:35.848 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID 2020-02-11 14:01:35.851 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 310 to queue - size 4 2020-02-11 14:01:35.838 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:35.853 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:35.856 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:35.859 [DEBUG] [nal.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-02-11 14:01:35.860 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 306: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.863 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:35.865 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 306: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.868 [DEBUG] [ve.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-02-11 14:01:35.870 [DEBUG] [serialmessage.GetVersionMessageClass] - Got MessageGetVersion response. Version=Z-Wave 4.61, Library Type=1 2020-02-11 14:01:35.872 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 306: Transaction COMPLETED 2020-02-11 14:01:35.874 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 50ms 2020-02-11 14:01:35.877 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 306: Transaction completed 2020-02-11 14:01:35.878 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:306 DONE 2020-02-11 14:01:35.881 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:35.882 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:35.883 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC 2020-02-11 14:01:35.884 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC 2020-02-11 14:01:35.885 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:35.886 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:35.886 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 307: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.887 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:35.889 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:35.889 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 01 20 E5 A7 B0 AC 01 89 2020-02-11 14:01:35.890 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 307: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.891 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=E5 A7 B0 AC 01 2020-02-11 14:01:35.891 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:35.892 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=E5 A7 B0 AC 01 2020-02-11 14:01:35.894 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 307: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.895 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:35.896 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 307: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.897 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=E5 A7 B0 AC 01 2020-02-11 14:01:35.899 [DEBUG] [erialmessage.MemoryGetIdMessageClass] - Got MessageMemoryGetId response. Home id = 0xe5a7b0ac, Controller Node id = 1 2020-02-11 14:01:35.900 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 307: Transaction COMPLETED 2020-02-11 14:01:35.901 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 15ms 2020-02-11 14:01:35.902 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 307: Transaction completed 2020-02-11 14:01:35.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:307 DONE 2020-02-11 14:01:35.905 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:35.906 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:35.907 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB 2020-02-11 14:01:35.909 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB 2020-02-11 14:01:35.910 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:35.911 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:35.911 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 308: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.913 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:35.915 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:35.916 [DEBUG] [WaveSerialHandler$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-02-11 14:01:35.916 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 308: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.917 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:35.919 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:35.919 [DEBUG] [nal.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-02-11 14:01:35.920 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:35.922 [DEBUG] [nal.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-02-11 14:01:35.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 308: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.925 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:35.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 308: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.928 [DEBUG] [ve.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-02-11 14:01:35.930 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - API Version = 5.27 2020-02-11 14:01:35.931 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Manufacture ID = 0x115 2020-02-11 14:01:35.932 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Device Type = 0x400 2020-02-11 14:01:35.934 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Device ID = 0x1 2020-02-11 14:01:35.935 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 308: Transaction COMPLETED 2020-02-11 14:01:35.936 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 311 to queue - size 3 2020-02-11 14:01:35.937 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:35.938 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 27ms 2020-02-11 14:01:35.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 308: Transaction completed 2020-02-11 14:01:35.940 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:308 DONE 2020-02-11 14:01:35.941 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:35.942 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:35.943 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65 2020-02-11 14:01:35.944 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65 2020-02-11 14:01:35.945 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:35.946 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:35.946 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 309: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.947 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:35.948 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:35.948 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 01 06 96 0F 64 2020-02-11 14:01:35.949 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 309: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.950 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:35.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:35.952 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:35.959 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 2020-02-11 14:01:35.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 2020-02-11 14:01:35.962 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 309: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.963 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:35.964 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 309: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.965 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F 2020-02-11 14:01:35.966 [DEBUG] [age.SerialApiSetTimeoutsMessageClass] - Got SerialApiSetTimeouts response. ACK=150, BYTE=15 2020-02-11 14:01:35.967 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 309: Transaction COMPLETED 2020-02-11 14:01:35.968 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 22ms 2020-02-11 14:01:35.969 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 309: Transaction completed 2020-02-11 14:01:35.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:309 DONE 2020-02-11 14:01:35.971 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:35.972 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:35.973 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA 2020-02-11 14:01:35.974 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA 2020-02-11 14:01:35.975 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:35.976 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:35.976 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 310: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.977 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:35.978 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 56 01 AD 2020-02-11 14:01:35.978 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:35.980 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 2020-02-11 14:01:35.980 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 310: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.981 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:35.982 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 2020-02-11 14:01:35.983 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 310: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.984 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:35.985 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 310: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:35.986 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01 2020-02-11 14:01:35.988 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Got SUC NodeID response. 2020-02-11 14:01:35.988 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - NODE 1: Node is SUC. 2020-02-11 14:01:35.990 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 310: Transaction COMPLETED 2020-02-11 14:01:35.991 [DEBUG] [etControllerCapabilitiesMessageClass] - Creating GET_CONTROLLER_CAPABILITIES message 2020-02-11 14:01:35.992 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 312 to queue - size 2 2020-02-11 14:01:35.993 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:35.994 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 18ms 2020-02-11 14:01:35.995 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 310: Transaction completed 2020-02-11 14:01:35.996 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:310 DONE 2020-02-11 14:01:35.997 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:35.998 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:36.000 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 02 FE 2020-02-11 14:01:36.001 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 02 FE 2020-02-11 14:01:36.002 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:36.003 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:36.003 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 311: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.003 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.004 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 311: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.006 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:36.007 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:36.008 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.099 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 25 01 02 06 08 1D 97 5A 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 02 2020-02-11 14:01:36.101 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=06 08 1D 97 5A 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-02-11 14:01:36.103 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=06 08 1D 97 5A 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-02-11 14:01:36.104 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 311: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:36.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 311: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.107 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=06 08 1D 97 5A 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-02-11 14:01:36.109 [DEBUG] [age.SerialApiGetInitDataMessageClass] - Got MessageSerialApiGetInitData response. 2020-02-11 14:01:36.109 [DEBUG] [age.SerialApiGetInitDataMessageClass] - NODE 1: Node found 2020-02-11 14:01:36.111 [DEBUG] [age.SerialApiGetInitDataMessageClass] - NODE 2: Node found 2020-02-11 14:01:36.111 [DEBUG] [age.SerialApiGetInitDataMessageClass] - NODE 3: Node found 2020-02-11 14:01:36.113 [DEBUG] [age.SerialApiGetInitDataMessageClass] - NODE 5: Node found 2020-02-11 14:01:36.113 [DEBUG] [age.SerialApiGetInitDataMessageClass] - NODE 8: Node found 2020-02-11 14:01:36.115 [DEBUG] [age.SerialApiGetInitDataMessageClass] - NODE 10: Node found 2020-02-11 14:01:36.116 [DEBUG] [age.SerialApiGetInitDataMessageClass] - NODE 12: Node found 2020-02-11 14:01:36.117 [DEBUG] [age.SerialApiGetInitDataMessageClass] - NODE 13: Node found 2020-02-11 14:01:36.118 [DEBUG] [age.SerialApiGetInitDataMessageClass] - NODE 15: Node found 2020-02-11 14:01:36.120 [DEBUG] [age.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API 2020-02-11 14:01:36.121 [DEBUG] [age.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller 2020-02-11 14:01:36.122 [DEBUG] [age.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------ 2020-02-11 14:01:36.123 [DEBUG] [age.SerialApiGetInitDataMessageClass] - # Nodes = 9 2020-02-11 14:01:36.124 [DEBUG] [age.SerialApiGetInitDataMessageClass] - ---------------------------------------------------------------------------- 2020-02-11 14:01:36.125 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 311: Transaction COMPLETED 2020-02-11 14:01:36.127 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Init node thread start 2020-02-11 14:01:36.128 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 2: Init node thread start 2020-02-11 14:01:36.128 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 3: Init node thread start 2020-02-11 14:01:36.129 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 5: Init node thread start 2020-02-11 14:01:36.134 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 8: Init node thread start 2020-02-11 14:01:36.141 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 1: Serializing from file /var/lib/openhab2/zwave/network_e5a7b0ac__node_1.xml 2020-02-11 14:01:36.144 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 3: Serializing from file /var/lib/openhab2/zwave/network_e5a7b0ac__node_3.xml 2020-02-11 14:01:36.145 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 10: Init node thread start 2020-02-11 14:01:36.149 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 2: Serializing from file /var/lib/openhab2/zwave/network_e5a7b0ac__node_2.xml 2020-02-11 14:01:36.155 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Restore from config: Ok. 2020-02-11 14:01:36.163 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-02-11 14:01:36.163 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 12: Init node thread start 2020-02-11 14:01:36.165 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-02-11 14:01:36.167 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Starting initialisation from EMPTYNODE 2020-02-11 14:01:36.162 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 10: Serializing from file /var/lib/openhab2/zwave/network_e5a7b0ac__node_10.xml 2020-02-11 14:01:36.171 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 8: Serializing from file /var/lib/openhab2/zwave/network_e5a7b0ac__node_8.xml 2020-02-11 14:01:36.172 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 8: Error serializing from file: file does not exist. 2020-02-11 14:01:36.172 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 13: Init node thread start 2020-02-11 14:01:36.177 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 5: Serializing from file /var/lib/openhab2/zwave/network_e5a7b0ac__node_5.xml 2020-02-11 14:01:36.179 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 5: Error serializing from file: file does not exist. 2020-02-11 14:01:36.183 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Starting initialisation from EMPTYNODE 2020-02-11 14:01:36.181 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 15: Init node thread start 2020-02-11 14:01:36.188 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Starting initialisation from EMPTYNODE 2020-02-11 14:01:36.190 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 12: Serializing from file /var/lib/openhab2/zwave/network_e5a7b0ac__node_12.xml 2020-02-11 14:01:36.202 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 2: Restore from config: Ok. 2020-02-11 14:01:36.203 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 200ms 2020-02-11 14:01:36.204 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 8: Init node thread finished 2020-02-11 14:01:36.204 [DEBUG] [ve.internal.protocol.ZWaveController] - Starting waiting for init threads 2020-02-11 14:01:36.206 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer - advancing to IDENTIFY_NODE 2020-02-11 14:01:36.208 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 13: Serializing from file /var/lib/openhab2/zwave/network_e5a7b0ac__node_13.xml 2020-02-11 14:01:36.208 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_ZWAVEPLUS_INFO, endpoint 0 created 2020-02-11 14:01:36.210 [DEBUG] [ve.internal.protocol.ZWaveController] - Waiting for init thread Node_1_init 2020-02-11 14:01:36.211 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Init node thread finished 2020-02-11 14:01:36.216 [DEBUG] [ve.internal.protocol.ZWaveController] - Init thread Node_1_init complete 2020-02-11 14:01:36.216 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: Initialisation starting 2020-02-11 14:01:36.217 [DEBUG] [ve.internal.protocol.ZWaveController] - Waiting for init thread Node_2_init 2020-02-11 14:01:36.215 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_SENSOR_BINARY, endpoint 0 created 2020-02-11 14:01:36.214 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 311: Transaction completed 2020-02-11 14:01:36.214 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 5: Init node thread finished 2020-02-11 14:01:36.216 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to IDENTIFY_NODE 2020-02-11 14:01:36.223 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_DEVICE_RESET_LOCALLY, endpoint 0 created 2020-02-11 14:01:36.214 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - advancing to IDENTIFY_NODE 2020-02-11 14:01:36.221 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@10d3bf7 2020-02-11 14:01:36.221 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:311 DONE 2020-02-11 14:01:36.237 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer: Initialisation starting 2020-02-11 14:01:36.237 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_ASSOCIATION_GRP_INFO, endpoint 0 created 2020-02-11 14:01:36.244 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@f80b8f 2020-02-11 14:01:36.220 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 15: Serializing from file /var/lib/openhab2/zwave/network_e5a7b0ac__node_15.xml 2020-02-11 14:01:36.241 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 3: Restore from config: Ok. 2020-02-11 14:01:36.223 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: Initialisation starting 2020-02-11 14:01:36.251 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_ZWAVEPLUS_INFO, endpoint 0 created 2020-02-11 14:01:36.251 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_BATTERY, endpoint 0 created 2020-02-11 14:01:36.252 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_METER, endpoint 0 created 2020-02-11 14:01:36.253 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_WAKE_UP, endpoint 0 created 2020-02-11 14:01:36.254 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_SWITCH_BINARY, endpoint 0 created 2020-02-11 14:01:36.254 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-02-11 14:01:36.255 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_DEVICE_RESET_LOCALLY, endpoint 0 created 2020-02-11 14:01:36.255 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_ALARM, endpoint 0 created 2020-02-11 14:01:36.256 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_ASSOCIATION_GRP_INFO, endpoint 0 created 2020-02-11 14:01:36.258 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1219e1e 2020-02-11 14:01:36.258 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-02-11 14:01:36.257 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_MANUFACTURER_SPECIFIC, endpoint 0 created 2020-02-11 14:01:36.259 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_ALARM, endpoint 0 created 2020-02-11 14:01:36.259 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_ASSOCIATION, endpoint 0 created 2020-02-11 14:01:36.260 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_MANUFACTURER_SPECIFIC, endpoint 0 created 2020-02-11 14:01:36.262 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 10: Restore from config: Ok. 2020-02-11 14:01:36.263 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_ASSOCIATION, endpoint 0 created 2020-02-11 14:01:36.261 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_VERSION, endpoint 0 created 2020-02-11 14:01:36.271 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0 created 2020-02-11 14:01:36.271 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0 created 2020-02-11 14:01:36.272 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-02-11 14:01:36.273 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_FIRMWARE_UPDATE_MD, endpoint 0 created 2020-02-11 14:01:36.274 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_CONFIGURATION, endpoint 0 created 2020-02-11 14:01:36.275 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_POWERLEVEL, endpoint 0 created 2020-02-11 14:01:36.276 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery completed 2020-02-11 14:01:36.277 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 15: Restore from config: Ok. 2020-02-11 14:01:36.278 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_ZWAVEPLUS_INFO, endpoint 0 created 2020-02-11 14:01:36.279 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery resolved to thingType zwave:aeon_zw100_01_010 2020-02-11 14:01:36.279 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_DEVICE_RESET_LOCALLY, endpoint 0 created 2020-02-11 14:01:36.269 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 313 to queue - size 1 2020-02-11 14:01:36.280 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:36.281 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_ASSOCIATION_GRP_INFO, endpoint 0 created 2020-02-11 14:01:36.281 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:36.282 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-02-11 14:01:36.270 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_ZWAVEPLUS_INFO, endpoint 0 created 2020-02-11 14:01:36.284 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 12: Restore from config: Ok. 2020-02-11 14:01:36.285 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_MANUFACTURER_SPECIFIC, endpoint 0 created 2020-02-11 14:01:36.285 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 05 BF 2020-02-11 14:01:36.286 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_ASSOCIATION, endpoint 0 created 2020-02-11 14:01:36.288 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_VERSION, endpoint 0 created 2020-02-11 14:01:36.289 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0 created 2020-02-11 14:01:36.285 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_ZWAVEPLUS_INFO, endpoint 0 created 2020-02-11 14:01:36.285 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION, endpoint 0 created 2020-02-11 14:01:36.291 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 05 BF 2020-02-11 14:01:36.291 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION, endpoint 0 created 2020-02-11 14:01:36.291 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_DEVICE_RESET_LOCALLY, endpoint 0 created 2020-02-11 14:01:36.292 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_DEVICE_RESET_LOCALLY, endpoint 0 created 2020-02-11 14:01:36.292 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_CRC_16_ENCAP, endpoint 0 created 2020-02-11 14:01:36.292 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:36.293 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:36.293 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_ASSOCIATION_GRP_INFO, endpoint 0 created 2020-02-11 14:01:36.294 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 313: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.294 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.295 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_CRC_16_ENCAP, endpoint 0 created 2020-02-11 14:01:36.297 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_BATTERY, endpoint 0 created 2020-02-11 14:01:36.297 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 53 9C 01 04 18 01 65 2020-02-11 14:01:36.297 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_CLOCK, endpoint 0 created 2020-02-11 14:01:36.297 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 314 to queue - size 1 2020-02-11 14:01:36.299 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.301 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 18 01 2020-02-11 14:01:36.301 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 315 to queue - size 2 2020-02-11 14:01:36.303 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.303 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_ASSOCIATION_GRP_INFO, endpoint 0 created 2020-02-11 14:01:36.304 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_APPLICATION_STATUS, endpoint 0 created 2020-02-11 14:01:36.304 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (1): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.305 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_PROTECTION, endpoint 0 created 2020-02-11 14:01:36.307 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Starting initialisation from EMPTYNODE 2020-02-11 14:01:36.308 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_VERSION, endpoint 0 created 2020-02-11 14:01:36.304 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_BATTERY, endpoint 0 created 2020-02-11 14:01:36.306 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.305 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-02-11 14:01:36.305 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 313: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.310 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:36.310 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_FIRMWARE_UPDATE_MD, endpoint 0 created 2020-02-11 14:01:36.309 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_WAKE_UP, endpoint 0 created 2020-02-11 14:01:36.312 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 18 01 2020-02-11 14:01:36.312 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-02-11 14:01:36.313 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 313: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.313 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-02-11 14:01:36.314 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:36.316 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 313: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.317 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 18 01 2020-02-11 14:01:36.302 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_WAKE_UP, endpoint 0 created 2020-02-11 14:01:36.319 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-02-11 14:01:36.319 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_SECURITY, endpoint 0 created 2020-02-11 14:01:36.320 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_ALARM, endpoint 0 created 2020-02-11 14:01:36.320 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_ALARM, endpoint 0 created 2020-02-11 14:01:36.321 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_CONFIGURATION, endpoint 0 created 2020-02-11 14:01:36.321 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_MANUFACTURER_SPECIFIC, endpoint 0 created 2020-02-11 14:01:36.322 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 5: ProtocolInfo 2020-02-11 14:01:36.322 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_POWERLEVEL, endpoint 0 created 2020-02-11 14:01:36.324 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_MANUFACTURER_SPECIFIC, endpoint 0 created 2020-02-11 14:01:36.325 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 15: Device discovery completed 2020-02-11 14:01:36.326 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_ASSOCIATION, endpoint 0 created 2020-02-11 14:01:36.326 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - advancing to IDENTIFY_NODE 2020-02-11 14:01:36.324 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 2: Init node thread finished 2020-02-11 14:01:36.328 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: Initialisation starting 2020-02-11 14:01:36.328 [DEBUG] [ve.internal.protocol.ZWaveController] - Init thread Node_2_init complete 2020-02-11 14:01:36.327 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 3: Updated networkKey 2020-02-11 14:01:36.324 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 5: Listening = false 2020-02-11 14:01:36.329 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 15: Device discovery resolved to thingType zwave:mcohome_a8co2_00_000 2020-02-11 14:01:36.331 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_ASSOCIATION, endpoint 0 created 2020-02-11 14:01:36.330 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 3: setupNetworkKey useSchemeZero=false 2020-02-11 14:01:36.329 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@587715 2020-02-11 14:01:36.336 [DEBUG] [ve.internal.protocol.ZWaveController] - Waiting for init thread Node_3_init 2020-02-11 14:01:36.327 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_SENSOR_ALARM, endpoint 0 created 2020-02-11 14:01:36.337 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_SWITCH_COLOR, endpoint 0 created 2020-02-11 14:01:36.338 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_SCENE_ACTIVATION, endpoint 0 created 2020-02-11 14:01:36.338 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_APPLICATION_STATUS, endpoint 0 created 2020-02-11 14:01:36.335 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Starting initialisation from EMPTYNODE 2020-02-11 14:01:36.344 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_FIRMWARE_UPDATE_MD, endpoint 0 created 2020-02-11 14:01:36.335 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 13: Restore from config: Ok. 2020-02-11 14:01:36.332 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_SENSOR_ALARM, endpoint 0 created 2020-02-11 14:01:36.345 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_CONFIGURATION, endpoint 0 created 2020-02-11 14:01:36.345 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0 created 2020-02-11 14:01:36.345 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_ZWAVEPLUS_INFO, endpoint 0 created 2020-02-11 14:01:36.345 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_SCENE_ACTUATOR_CONF, endpoint 0 created 2020-02-11 14:01:36.346 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_VERSION, endpoint 0 created 2020-02-11 14:01:36.346 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_MULTI_CHANNEL_ASSOCIATION, endpoint 0 created 2020-02-11 14:01:36.346 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_POWERLEVEL, endpoint 0 created 2020-02-11 14:01:36.346 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-02-11 14:01:36.347 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery completed 2020-02-11 14:01:36.347 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_CENTRAL_SCENE, endpoint 0 created 2020-02-11 14:01:36.348 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_SECURITY, endpoint 0 created 2020-02-11 14:01:36.348 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery resolved to thingType zwave:aeotec_zw175_00_000 2020-02-11 14:01:36.349 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 12: Updated networkKey 2020-02-11 14:01:36.350 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 12: setupNetworkKey useSchemeZero=false 2020-02-11 14:01:36.344 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 316 to queue - size 3 2020-02-11 14:01:36.334 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 5: Routing = true 2020-02-11 14:01:36.353 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.353 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_VERSION, endpoint 0 created 2020-02-11 14:01:36.353 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node advancer - advancing to IDENTIFY_NODE 2020-02-11 14:01:36.352 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_FIRMWARE_UPDATE_MD, endpoint 0 created 2020-02-11 14:01:36.355 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node advancer: Initialisation starting 2020-02-11 14:01:36.356 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@109428c 2020-02-11 14:01:36.353 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 15: Init node thread finished 2020-02-11 14:01:36.353 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 5: Beaming = true 2020-02-11 14:01:36.357 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_DEVICE_RESET_LOCALLY, endpoint 0 created 2020-02-11 14:01:36.358 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 5: Version = 4 2020-02-11 14:01:36.358 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_ASSOCIATION_GRP_INFO, endpoint 0 created 2020-02-11 14:01:36.359 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 5: FLIRS = false 2020-02-11 14:01:36.360 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_CRC_16_ENCAP, endpoint 0 created 2020-02-11 14:01:36.360 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 5: Security = false 2020-02-11 14:01:36.360 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Starting initialisation from EMPTYNODE 2020-02-11 14:01:36.361 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0 created 2020-02-11 14:01:36.361 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_BATTERY, endpoint 0 created 2020-02-11 14:01:36.361 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-02-11 14:01:36.362 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 5: Max Baud = 40000 2020-02-11 14:01:36.362 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_SECURITY, endpoint 0 created 2020-02-11 14:01:36.362 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_WAKE_UP, endpoint 0 created 2020-02-11 14:01:36.363 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 10: Updated networkKey 2020-02-11 14:01:36.356 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_CONFIGURATION, endpoint 0 created 2020-02-11 14:01:36.365 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 10: setupNetworkKey useSchemeZero=false 2020-02-11 14:01:36.364 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-02-11 14:01:36.366 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_FIRMWARE_UPDATE_MD, endpoint 0 created 2020-02-11 14:01:36.367 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_POWERLEVEL, endpoint 0 created 2020-02-11 14:01:36.367 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_ALARM, endpoint 0 created 2020-02-11 14:01:36.369 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 3: Init node thread finished 2020-02-11 14:01:36.369 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 12: Device discovery completed 2020-02-11 14:01:36.368 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 317 to queue - size 4 2020-02-11 14:01:36.368 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 5: Basic = BASIC_TYPE_ROUTING_SLAVE 2020-02-11 14:01:36.372 [DEBUG] [ve.internal.protocol.ZWaveController] - Init thread Node_3_init complete 2020-02-11 14:01:36.373 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 5: Generic = GENERIC_TYPE_WALL_CONTROLLER 2020-02-11 14:01:36.373 [DEBUG] [ve.internal.protocol.ZWaveController] - Waiting for init thread Node_5_init 2020-02-11 14:01:36.373 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.368 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_CONFIGURATION, endpoint 0 created 2020-02-11 14:01:36.374 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 5: Specific = SPECIFIC_TYPE_BASIC_WALL_CONTROLLER 2020-02-11 14:01:36.372 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_MANUFACTURER_SPECIFIC, endpoint 0 created 2020-02-11 14:01:36.375 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_POWERLEVEL, endpoint 0 created 2020-02-11 14:01:36.376 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_ASSOCIATION, endpoint 0 created 2020-02-11 14:01:36.376 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery completed 2020-02-11 14:01:36.377 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_SENSOR_ALARM, endpoint 0 created 2020-02-11 14:01:36.378 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery resolved to thingType zwave:fibaro_fgfs101_03_002 2020-02-11 14:01:36.374 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer - advancing to IDENTIFY_NODE 2020-02-11 14:01:36.380 [DEBUG] [ve.internal.protocol.ZWaveController] - Init thread Node_5_init complete 2020-02-11 14:01:36.379 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0 created 2020-02-11 14:01:36.380 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: Initialisation starting 2020-02-11 14:01:36.381 [DEBUG] [ve.internal.protocol.ZWaveController] - Waiting for init thread Node_8_init 2020-02-11 14:01:36.382 [DEBUG] [ve.internal.protocol.ZWaveController] - Init thread Node_8_init complete 2020-02-11 14:01:36.383 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Creating new instance of command class COMMAND_CLASS_NO_OPERATION 2020-02-11 14:01:36.383 [DEBUG] [ve.internal.protocol.ZWaveController] - Waiting for init thread Node_10_init 2020-02-11 14:01:36.384 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-02-11 14:01:36.387 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Version = 1, version set. Enabling extra functionality. 2020-02-11 14:01:36.387 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_VERSION, endpoint 0 created 2020-02-11 14:01:36.388 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes. 2020-02-11 14:01:36.389 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-02-11 14:01:36.389 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Creating new instance of command class COMMAND_CLASS_BASIC 2020-02-11 14:01:36.391 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_CENTRAL_SCENE, endpoint 0 created 2020-02-11 14:01:36.390 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-02-11 14:01:36.391 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_SECURITY, endpoint 0 created 2020-02-11 14:01:36.391 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes. 2020-02-11 14:01:36.392 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 313: Transaction COMPLETED 2020-02-11 14:01:36.394 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 13: Updated networkKey 2020-02-11 14:01:36.394 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 100ms 2020-02-11 14:01:36.395 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 13: setupNetworkKey useSchemeZero=false 2020-02-11 14:01:36.395 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1469272 2020-02-11 14:01:36.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 313: Transaction completed 2020-02-11 14:01:36.398 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_FIRMWARE_UPDATE_MD, endpoint 0 created 2020-02-11 14:01:36.399 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:313 DONE 2020-02-11 14:01:36.400 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_CONFIGURATION, endpoint 0 created 2020-02-11 14:01:36.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 318 to queue - size 5 2020-02-11 14:01:36.402 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_POWERLEVEL, endpoint 0 created 2020-02-11 14:01:36.402 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:36.404 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 01 BB 2020-02-11 14:01:36.405 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:36.404 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 13: Device discovery completed 2020-02-11 14:01:36.406 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 01 BB 2020-02-11 14:01:36.405 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 313: Transaction event listener: DONE: DONE -> 2020-02-11 14:01:36.409 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:36.411 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.410 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@60ff 2020-02-11 14:01:36.411 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:36.411 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Starting initialisation from EMPTYNODE 2020-02-11 14:01:36.412 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 16 01 02 02 01 73 2020-02-11 14:01:36.414 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node Init transaction completed with response COMPLETE 2020-02-11 14:01:36.414 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 12: Device discovery resolved to thingType zwave:fibaro_fgpb101_00_000 2020-02-11 14:01:36.417 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 13: Device discovery resolved to thingType zwave:fibaro_fgpb101_00_000 2020-02-11 14:01:36.417 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 5: Node advancer - advancing to REQUEST_NIF 2020-02-11 14:01:36.419 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@102f0db 2020-02-11 14:01:36.421 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 10: Init node thread finished 2020-02-11 14:01:36.421 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - advancing to IDENTIFY_NODE 2020-02-11 14:01:36.421 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Bump transaction 319 priority from Controller to Immediate 2020-02-11 14:01:36.423 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: Initialisation starting 2020-02-11 14:01:36.423 [DEBUG] [ve.internal.protocol.ZWaveController] - Init thread Node_10_init complete 2020-02-11 14:01:36.424 [DEBUG] [ve.internal.protocol.ZWaveController] - Waiting for init thread Node_12_init 2020-02-11 14:01:36.424 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@c36d05 2020-02-11 14:01:36.459 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 314: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.459 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 2020-02-11 14:01:36.462 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 13: Starting initialisation from EMPTYNODE 2020-02-11 14:01:36.462 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 320 to queue - size 5 2020-02-11 14:01:36.464 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.465 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Adding to device queue 2020-02-11 14:01:36.467 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Added 319 to queue - size 1 2020-02-11 14:01:36.468 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.469 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Starting initialisation from EMPTYNODE 2020-02-11 14:01:36.470 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 13: Init node thread finished 2020-02-11 14:01:36.470 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (1): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.474 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 13: Node advancer - advancing to IDENTIFY_NODE 2020-02-11 14:01:36.474 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 314: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.475 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:36.475 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 13: Node advancer: Initialisation starting 2020-02-11 14:01:36.477 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 2020-02-11 14:01:36.477 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@3cf18e 2020-02-11 14:01:36.478 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 314: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.479 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:36.480 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 314: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.482 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01 2020-02-11 14:01:36.483 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: ProtocolInfo 2020-02-11 14:01:36.483 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 12: Init node thread finished 2020-02-11 14:01:36.485 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Listening = true 2020-02-11 14:01:36.486 [DEBUG] [ve.internal.protocol.ZWaveController] - Init thread Node_12_init complete 2020-02-11 14:01:36.486 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Routing = true 2020-02-11 14:01:36.487 [DEBUG] [ve.internal.protocol.ZWaveController] - Waiting for init thread Node_13_init 2020-02-11 14:01:36.487 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Beaming = true 2020-02-11 14:01:36.486 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - advancing to IDENTIFY_NODE 2020-02-11 14:01:36.488 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 321 to queue - size 6 2020-02-11 14:01:36.488 [DEBUG] [ve.internal.protocol.ZWaveController] - Init thread Node_13_init complete 2020-02-11 14:01:36.489 [DEBUG] [ve.internal.protocol.ZWaveController] - Waiting for init thread Node_15_init 2020-02-11 14:01:36.489 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Version = 4 2020-02-11 14:01:36.489 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: Initialisation starting 2020-02-11 14:01:36.490 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.491 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: FLIRS = false 2020-02-11 14:01:36.492 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@135c982 2020-02-11 14:01:36.493 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Security = false 2020-02-11 14:01:36.490 [DEBUG] [ve.internal.protocol.ZWaveController] - Init thread Node_15_init complete 2020-02-11 14:01:36.495 [DEBUG] [ve.internal.protocol.ZWaveController] - All init threads complete 2020-02-11 14:01:36.495 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Max Baud = 40000 2020-02-11 14:01:36.496 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller: Incoming Network State Event true 2020-02-11 14:01:36.497 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Basic = BASIC_TYPE_STATIC_CONTROLLER 2020-02-11 14:01:36.498 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Generic = GENERIC_TYPE_STATIC_CONTROLLER 2020-02-11 14:01:36.499 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Controller status changed to ONLINE. 2020-02-11 14:01:36.499 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Controller status changed to ONLINE. 2020-02-11 14:01:36.500 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Controller status changed to ONLINE. 2020-02-11 14:01:36.501 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Controller status changed to ONLINE. 2020-02-11 14:01:36.503 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Controller is ONLINE. Starting device initialisation. 2020-02-11 14:01:36.503 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Controller is ONLINE. Starting device initialisation. 2020-02-11 14:01:36.502 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Controller is ONLINE. Starting device initialisation. 2020-02-11 14:01:36.505 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating node properties. 2020-02-11 14:01:36.505 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Updating node properties. 2020-02-11 14:01:36.506 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating node properties. MAN=271 2020-02-11 14:01:36.508 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Updating node properties. MAN=351 2020-02-11 14:01:36.508 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating node properties. MAN=271. SET. Was 271 2020-02-11 14:01:36.508 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Controller status changed to ONLINE. 2020-02-11 14:01:36.510 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Updating node properties. MAN=351. SET. Was 351 2020-02-11 14:01:36.510 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Controller is ONLINE. Starting device initialisation. 2020-02-11 14:01:36.501 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Controller is ONLINE. Starting device initialisation. 2020-02-11 14:01:36.509 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 322 to queue - size 7 2020-02-11 14:01:36.513 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Updating node properties. 2020-02-11 14:01:36.513 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Properties synchronised 2020-02-11 14:01:36.513 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.514 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Updating node properties. MAN=271 2020-02-11 14:01:36.515 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Specific = SPECIFIC_TYPE_PC_CONTROLLER ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:36.515 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:cf541806' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:36.516 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class COMMAND_CLASS_NO_OPERATION 2020-02-11 14:01:36.517 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties. 2020-02-11 14:01:36.517 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:36.518 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node10' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:36.518 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties. MAN=134 2020-02-11 14:01:36.520 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties. MAN=134. SET. Was 134 ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:36.521 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node15' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:36.529 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Properties synchronised ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:36.529 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node13' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:36.530 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Properties synchronised 2020-02-11 14:01:36.530 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Updating node properties. ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:36.533 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:cf541806' has been updated. 2020-02-11 14:01:36.535 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node2' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE 2020-02-11 14:01:36.537 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node12' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:36.539 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Update ASSOCIATION group_ZWaveAssociationGroup [index=1, name=null, profile1=null, profile2=null, associations=[node_1]]: Adding Controller (node_1) 2020-02-11 14:01:36.541 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Version = 1, version set. Enabling extra functionality. 2020-02-11 14:01:36.515 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Updating node properties. MAN=271. SET. Was 271 2020-02-11 14:01:36.547 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Update ASSOCIATION group_ZWaveAssociationGroup [index=1, name=Lifeline, profile1=0, profile2=1, associations=[node_1]]: Adding Controller (node_1) 2020-02-11 14:01:36.547 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Properties synchronised 2020-02-11 14:01:36.547 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Updating node properties. MAN=271 2020-02-11 14:01:36.549 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Updating node properties. MAN=271. SET. Was 271 2020-02-11 14:01:36.548 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Update ASSOCIATION group_ZWaveAssociationGroup [index=2, name=Flood Control, profile1=113, profile2=5, associations=[node_1]]: Adding Controller (node_1) 2020-02-11 14:01:36.553 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Properties synchronised 2020-02-11 14:01:36.549 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 1: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes. 2020-02-11 14:01:36.551 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Update ASSOCIATION group_ZWaveAssociationGroup [index=1, name=null, profile1=null, profile2=null, associations=[node_1]]: Adding Controller (node_1) 2020-02-11 14:01:36.551 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added. 2020-02-11 14:01:36.557 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Update ASSOCIATION group_ZWaveAssociationGroup [index=1, name=Lifeline, profile1=0, profile2=1, associations=[node_1]]: Adding Controller (node_1) 2020-02-11 14:01:36.558 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Initialising Thing Node... 2020-02-11 14:01:36.558 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class COMMAND_CLASS_BASIC 2020-02-11 14:01:36.559 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Update ASSOCIATION group_ZWaveAssociationGroup [index=2, name=On/Off, profile1=32, profile2=1, associations=[node_1]]: Adding Controller (node_1) 2020-02-11 14:01:36.559 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Initialising cmd channel zwave:device:cf541806:node15:alarm_smoke for DecimalType 2020-02-11 14:01:36.560 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added. 2020-02-11 14:01:36.561 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising Thing Node... 2020-02-11 14:01:36.561 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Update ASSOCIATION group_ZWaveAssociationGroup [index=4, name=Alarm, profile1=32, profile2=1, associations=[node_1]]: Adding Controller (node_1) 2020-02-11 14:01:36.563 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:cf541806:node2:sensor_temperature for QuantityType 2020-02-11 14:01:36.564 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:cf541806:node2:sensor_temperature for QuantityType 2020-02-11 14:01:36.566 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:cf541806:node2:sensor_ultraviolet for DecimalType 2020-02-11 14:01:36.568 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:cf541806:node2:sensor_ultraviolet for DecimalType 2020-02-11 14:01:36.553 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Update ASSOCIATION group_ZWaveAssociationGroup [index=3, name=Flood Alarm, profile1=113, profile2=5, associations=[node_1]]: Adding Controller (node_1) 2020-02-11 14:01:36.570 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Update ASSOCIATION group_ZWaveAssociationGroup [index=4, name=Tamper Alarm, profile1=113, profile2=7, associations=[node_1]]: Adding Controller (node_1) 2020-02-11 14:01:36.570 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added. 2020-02-11 14:01:36.558 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Update ASSOCIATION group_ZWaveAssociationGroup [index=2, name=null, profile1=null, profile2=null, associations=[node_1]]: Adding Controller (node_1) 2020-02-11 14:01:36.572 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Update ASSOCIATION group_ZWaveAssociationGroup [index=3, name=null, profile1=null, profile2=null, associations=[node_1]]: Adding Controller (node_1) 2020-02-11 14:01:36.572 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Initialising state channel zwave:device:cf541806:node15:alarm_smoke for DecimalType 2020-02-11 14:01:36.572 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-02-11 14:01:36.574 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Initialising cmd channel zwave:device:cf541806:node15:sensor_relhumidity for DecimalType 2020-02-11 14:01:36.574 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Update ASSOCIATION group_ZWaveAssociationGroup [index=4, name=null, profile1=null, profile2=null, associations=[node_1]]: Adding Controller (node_1) 2020-02-11 14:01:36.574 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 1: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes. 2020-02-11 14:01:36.575 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Initialising state channel zwave:device:cf541806:node15:sensor_relhumidity for DecimalType 2020-02-11 14:01:36.576 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 314: Transaction COMPLETED 2020-02-11 14:01:36.577 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Initialising cmd channel zwave:device:cf541806:node15:sensor_luminance for DecimalType 2020-02-11 14:01:36.578 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Initialising state channel zwave:device:cf541806:node15:sensor_luminance for DecimalType 2020-02-11 14:01:36.579 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 120ms 2020-02-11 14:01:36.580 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Initialising cmd channel zwave:device:cf541806:node15:sensor_temperature for QuantityType 2020-02-11 14:01:36.581 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 314: Transaction completed 2020-02-11 14:01:36.582 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:cf541806:node2:sensor_luminance for DecimalType 2020-02-11 14:01:36.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:314 DONE 2020-02-11 14:01:36.584 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:cf541806:node2:sensor_luminance for DecimalType 2020-02-11 14:01:36.582 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Initialising state channel zwave:device:cf541806:node15:sensor_temperature for QuantityType 2020-02-11 14:01:36.587 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added. 2020-02-11 14:01:36.587 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising Thing Node... 2020-02-11 14:01:36.587 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Initialising cmd channel zwave:device:cf541806:node15:alarm_co2 for DecimalType 2020-02-11 14:01:36.589 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:cf541806:node2:sensor_relhumidity for DecimalType 2020-02-11 14:01:36.589 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:36.589 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Initialising Thing Node... 2020-02-11 14:01:36.590 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:cf541806:node2:sensor_relhumidity for DecimalType 2020-02-11 14:01:36.591 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Initialising cmd channel zwave:device:cf541806:node13:scene_number for DecimalType 2020-02-11 14:01:36.590 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:36.591 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:cf541806:node2:alarm_motion for OnOffType 2020-02-11 14:01:36.593 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:cf541806:node2:alarm_motion for OnOffType 2020-02-11 14:01:36.593 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 08 B2 2020-02-11 14:01:36.594 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:cf541806:node2:alarm_tamper for OnOffType 2020-02-11 14:01:36.595 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 08 B2 2020-02-11 14:01:36.596 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:cf541806:node2:alarm_tamper for OnOffType 2020-02-11 14:01:36.597 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:cf541806:node2:battery-level for PercentType 2020-02-11 14:01:36.592 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Initialising state channel zwave:device:cf541806:node13:scene_number for DecimalType 2020-02-11 14:01:36.597 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:36.598 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:cf541806:node2:battery-level for PercentType 2020-02-11 14:01:36.599 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 315: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.599 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling initialised at 86400 seconds - start in 71798400 milliseconds. 2020-02-11 14:01:36.601 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:cf541806:node12:scene_number for DecimalType 2020-02-11 14:01:36.601 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:36.601 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Initialising state channel zwave:device:cf541806:node15:alarm_co2 for DecimalType 2020-02-11 14:01:36.604 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Polling initialised at 86400 seconds - start in 27129600 milliseconds. 2020-02-11 14:01:36.604 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:cf541806:node12:scene_number for DecimalType 2020-02-11 14:01:36.602 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 314: Transaction event listener: DONE: DONE -> 2020-02-11 14:01:36.605 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Device initialisation complete. 2020-02-11 14:01:36.600 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added. 2020-02-11 14:01:36.607 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1d9f56e 2020-02-11 14:01:36.608 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init transaction completed with response COMPLETE 2020-02-11 14:01:36.609 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: FAILED_CHECK - Controller - terminating initialisation 2020-02-11 14:01:36.611 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to DONE 2020-02-11 14:01:36.612 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 1: Serializing to file /var/lib/openhab2/zwave/network_e5a7b0ac__node_1.xml 2020-02-11 14:01:36.613 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Initialising cmd channel zwave:device:cf541806:node13:alarm_general for OnOffType 2020-02-11 14:01:36.614 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Initialising state channel zwave:device:cf541806:node13:alarm_general for OnOffType 2020-02-11 14:01:36.616 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Initialising cmd channel zwave:device:cf541806:node13:battery-level for PercentType 2020-02-11 14:01:36.607 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Controller status changed to ONLINE. 2020-02-11 14:01:36.617 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Initialising state channel zwave:device:cf541806:node13:battery-level for PercentType 2020-02-11 14:01:36.618 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Controller is ONLINE. Starting device initialisation. 2020-02-11 14:01:36.619 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Polling initialised at 86400 seconds - start in 8467200 milliseconds. 2020-02-11 14:01:36.621 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Updating node properties. 2020-02-11 14:01:36.623 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Updating node properties. MAN=881 2020-02-11 14:01:36.624 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Updating node properties. MAN=881. SET. Was 881 ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:36.624 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node3' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:36.626 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Properties synchronised 2020-02-11 14:01:36.628 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Update ASSOCIATION group_ZWaveAssociationGroup [index=1, name=null, profile1=null, profile2=null, associations=[node_1]]: Adding Controller (node_1) 2020-02-11 14:01:36.630 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added. 2020-02-11 14:01:36.608 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising Thing Node... 2020-02-11 14:01:36.641 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising cmd channel zwave:device:cf541806:node10:sensor_temperature for QuantityType 2020-02-11 14:01:36.642 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Device initialisation complete. 2020-02-11 14:01:36.642 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising state channel zwave:device:cf541806:node10:sensor_temperature for QuantityType 2020-02-11 14:01:36.644 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.644 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:cf541806:node12:alarm_general for OnOffType 2020-02-11 14:01:36.645 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.646 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 53 9C 01 04 18 01 65 2020-02-11 14:01:36.646 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 315: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.647 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:36.648 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 18 01 2020-02-11 14:01:36.649 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:36.650 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.652 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 18 01 2020-02-11 14:01:36.652 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising cmd channel zwave:device:cf541806:node10:alarm_tamper for OnOffType 2020-02-11 14:01:36.640 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising Thing Node... 2020-02-11 14:01:36.653 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 315: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.655 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:36.657 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 315: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.639 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Device initialisation complete. 2020-02-11 14:01:36.659 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:cf541806:node12:alarm_general for OnOffType 2020-02-11 14:01:36.659 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising state channel zwave:device:cf541806:node10:alarm_tamper for OnOffType 2020-02-11 14:01:36.661 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising cmd channel zwave:device:cf541806:node12:battery-level for PercentType 2020-02-11 14:01:36.655 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising cmd channel zwave:device:cf541806:node3:switch_binary for OnOffType 2020-02-11 14:01:36.661 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising cmd channel zwave:device:cf541806:node10:alarm_flood for OnOffType 2020-02-11 14:01:36.663 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Initialising state channel zwave:device:cf541806:node12:battery-level for PercentType 2020-02-11 14:01:36.663 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising state channel zwave:device:cf541806:node10:alarm_flood for OnOffType 2020-02-11 14:01:36.665 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Polling initialised at 1800 seconds - start in 127800 milliseconds. 2020-02-11 14:01:36.665 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising cmd channel zwave:device:cf541806:node10:battery-level for PercentType 2020-02-11 14:01:36.666 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising state channel zwave:device:cf541806:node3:switch_binary for OnOffType 2020-02-11 14:01:36.667 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Device initialisation complete. 2020-02-11 14:01:36.668 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising state channel zwave:device:cf541806:node10:battery-level for PercentType 2020-02-11 14:01:36.670 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 18 01 2020-02-11 14:01:36.670 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling initialised at 86400 seconds - start in 25056000 milliseconds. 2020-02-11 14:01:36.671 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising state channel zwave:device:cf541806:node3:switch_binary for OnOffType 2020-02-11 14:01:36.671 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 8: ProtocolInfo 2020-02-11 14:01:36.673 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 8: Listening = false 2020-02-11 14:01:36.673 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Device initialisation complete. 2020-02-11 14:01:36.675 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising cmd channel zwave:device:cf541806:node3:switch_dimmer for OnOffType 2020-02-11 14:01:36.677 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising cmd channel zwave:device:cf541806:node3:switch_dimmer for PercentType 2020-02-11 14:01:36.679 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising state channel zwave:device:cf541806:node3:switch_dimmer for PercentType 2020-02-11 14:01:36.680 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising cmd channel zwave:device:cf541806:node3:scene_number for DecimalType 2020-02-11 14:01:36.675 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 8: Routing = true 2020-02-11 14:01:36.682 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising state channel zwave:device:cf541806:node3:scene_number for DecimalType 2020-02-11 14:01:36.682 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 8: Beaming = true 2020-02-11 14:01:36.684 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising cmd channel zwave:device:cf541806:node3:meter_current for DecimalType 2020-02-11 14:01:36.684 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 8: Version = 4 2020-02-11 14:01:36.685 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising state channel zwave:device:cf541806:node3:meter_current for DecimalType 2020-02-11 14:01:36.685 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 8: FLIRS = false 2020-02-11 14:01:36.686 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 8: Security = false 2020-02-11 14:01:36.687 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising cmd channel zwave:device:cf541806:node3:meter_kwh for DecimalType 2020-02-11 14:01:36.688 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 8: Max Baud = 40000 2020-02-11 14:01:36.689 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising state channel zwave:device:cf541806:node3:meter_kwh for DecimalType 2020-02-11 14:01:36.690 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 8: Basic = BASIC_TYPE_ROUTING_SLAVE 2020-02-11 14:01:36.691 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 8: Generic = GENERIC_TYPE_WALL_CONTROLLER 2020-02-11 14:01:36.693 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 8: Specific = SPECIFIC_TYPE_BASIC_WALL_CONTROLLER 2020-02-11 14:01:36.694 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Creating new instance of command class COMMAND_CLASS_NO_OPERATION 2020-02-11 14:01:36.695 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-02-11 14:01:36.697 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Version = 1, version set. Enabling extra functionality. 2020-02-11 14:01:36.698 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes. 2020-02-11 14:01:36.700 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Creating new instance of command class COMMAND_CLASS_BASIC 2020-02-11 14:01:36.701 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-02-11 14:01:36.703 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes. 2020-02-11 14:01:36.704 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising cmd channel zwave:device:cf541806:node3:meter_watts for DecimalType 2020-02-11 14:01:36.704 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 315: Transaction COMPLETED 2020-02-11 14:01:36.705 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising state channel zwave:device:cf541806:node3:meter_watts for DecimalType 2020-02-11 14:01:36.707 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising cmd channel zwave:device:cf541806:node3:meter_voltage for DecimalType 2020-02-11 14:01:36.709 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising state channel zwave:device:cf541806:node3:meter_voltage for DecimalType 2020-02-11 14:01:36.710 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 111ms 2020-02-11 14:01:36.710 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising cmd channel zwave:device:cf541806:node3:color_color for OnOffType 2020-02-11 14:01:36.711 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 315: Transaction completed 2020-02-11 14:01:36.712 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising cmd channel zwave:device:cf541806:node3:color_color for PercentType 2020-02-11 14:01:36.712 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:315 DONE 2020-02-11 14:01:36.714 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising state channel zwave:device:cf541806:node3:color_color for PercentType 2020-02-11 14:01:36.714 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:36.715 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:36.715 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising cmd channel zwave:device:cf541806:node3:color_color for HSBType 2020-02-11 14:01:36.716 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising state channel zwave:device:cf541806:node3:color_color for HSBType 2020-02-11 14:01:36.716 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 02 B8 2020-02-11 14:01:36.718 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 02 B8 2020-02-11 14:01:36.718 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising cmd channel zwave:device:cf541806:node3:color_temperature for OnOffType 2020-02-11 14:01:36.719 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:36.720 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:36.721 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 315: Transaction event listener: DONE: DONE -> 2020-02-11 14:01:36.723 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising cmd channel zwave:device:cf541806:node3:color_temperature for PercentType 2020-02-11 14:01:36.724 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.724 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 316: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.723 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1f55087 2020-02-11 14:01:36.726 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node Init transaction completed with response COMPLETE 2020-02-11 14:01:36.727 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 9C 01 04 21 01 DC 2020-02-11 14:01:36.727 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer - advancing to REQUEST_NIF 2020-02-11 14:01:36.728 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@f7d59d 2020-02-11 14:01:36.730 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Bump transaction 323 priority from Controller to Immediate 2020-02-11 14:01:36.731 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.732 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Adding to device queue 2020-02-11 14:01:36.733 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 316: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:36.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Added 323 to queue - size 2 2020-02-11 14:01:36.736 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.736 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:36.729 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 9C 01 04 21 01 2020-02-11 14:01:36.741 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising state channel zwave:device:cf541806:node3:color_temperature for PercentType 2020-02-11 14:01:36.741 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.743 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 9C 01 04 21 01 2020-02-11 14:01:36.743 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising cmd channel zwave:device:cf541806:node3:alarm_power for OnOffType 2020-02-11 14:01:36.744 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 316: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.744 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising state channel zwave:device:cf541806:node3:alarm_power for OnOffType 2020-02-11 14:01:36.746 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising cmd channel zwave:device:cf541806:node3:alarm_system for OnOffType 2020-02-11 14:01:36.746 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:36.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 316: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.747 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising state channel zwave:device:cf541806:node3:alarm_system for OnOffType 2020-02-11 14:01:36.748 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 9C 01 04 21 01 2020-02-11 14:01:36.748 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising cmd channel zwave:device:cf541806:node3:time_offset for DecimalType 2020-02-11 14:01:36.750 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: ProtocolInfo 2020-02-11 14:01:36.750 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising state channel zwave:device:cf541806:node3:time_offset for DecimalType 2020-02-11 14:01:36.751 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Listening = true 2020-02-11 14:01:36.751 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling initialised at 1800 seconds - start in 16200 milliseconds. 2020-02-11 14:01:36.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Device initialisation complete. 2020-02-11 14:01:36.752 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Routing = true 2020-02-11 14:01:36.754 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Beaming = true 2020-02-11 14:01:36.755 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Version = 4 2020-02-11 14:01:36.756 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: FLIRS = false 2020-02-11 14:01:36.757 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Security = false 2020-02-11 14:01:36.758 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Max Baud = 40000 2020-02-11 14:01:36.760 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Basic = BASIC_TYPE_ROUTING_SLAVE 2020-02-11 14:01:36.761 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Generic = GENERIC_TYPE_SENSOR_MULTILEVEL 2020-02-11 14:01:36.762 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 2: Specific = SPECIFIC_TYPE_ROUTING_SENSOR_MULTILEVEL 2020-02-11 14:01:36.764 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class COMMAND_CLASS_NO_OPERATION 2020-02-11 14:01:36.766 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-02-11 14:01:36.768 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Version = 1, version set. Enabling extra functionality. 2020-02-11 14:01:36.769 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes. 2020-02-11 14:01:36.770 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Creating new instance of command class COMMAND_CLASS_BASIC 2020-02-11 14:01:36.772 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-02-11 14:01:36.773 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes. 2020-02-11 14:01:36.775 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 316: Transaction COMPLETED 2020-02-11 14:01:36.776 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 52ms 2020-02-11 14:01:36.777 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 316: Transaction completed 2020-02-11 14:01:36.779 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:316 DONE 2020-02-11 14:01:36.780 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:36.780 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 316: Transaction event listener: DONE: DONE -> 2020-02-11 14:01:36.781 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:36.783 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@a01c65 2020-02-11 14:01:36.784 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init transaction completed with response COMPLETE 2020-02-11 14:01:36.785 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - advancing to PING 2020-02-11 14:01:36.786 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInitializationStateEvent 2020-02-11 14:01:36.789 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 0F B5 2020-02-11 14:01:36.791 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 0F B5 ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:36.791 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node2' changed from ONLINE to ONLINE: Node initialising: PING ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:36.791 [DEBUG] [ndclass.ZWaveNoOperationCommandClass] - NODE 2: Creating new message for command NO_OPERATION_PING 2020-02-11 14:01:36.793 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:36.794 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: ZWaveCommandClassTransactionPayload - send to node 2020-02-11 14:01:36.794 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:36.794 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 317: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.796 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.795 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported 2020-02-11 14:01:36.796 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.796 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_NO_OPERATION is NOT required to be secured 2020-02-11 14:01:36.797 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@1a29995 2020-02-11 14:01:36.797 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 9C 01 04 21 01 DC 2020-02-11 14:01:36.797 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 317: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.798 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:36.798 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue 2020-02-11 14:01:36.799 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 324 to queue - size 3 2020-02-11 14:01:36.799 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:36.800 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.801 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.802 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 9C 01 04 21 01 2020-02-11 14:01:36.803 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 9C 01 04 21 01 2020-02-11 14:01:36.804 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 317: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.805 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:36.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 317: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.807 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 9C 01 04 21 01 2020-02-11 14:01:36.808 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: ProtocolInfo 2020-02-11 14:01:36.809 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Listening = true 2020-02-11 14:01:36.810 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Routing = true 2020-02-11 14:01:36.811 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Beaming = true 2020-02-11 14:01:36.812 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Version = 4 2020-02-11 14:01:36.813 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: FLIRS = false 2020-02-11 14:01:36.814 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Security = false 2020-02-11 14:01:36.815 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Max Baud = 40000 2020-02-11 14:01:36.816 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Basic = BASIC_TYPE_ROUTING_SLAVE 2020-02-11 14:01:36.817 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Generic = GENERIC_TYPE_SENSOR_MULTILEVEL 2020-02-11 14:01:36.818 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 15: Specific = SPECIFIC_TYPE_ROUTING_SENSOR_MULTILEVEL 2020-02-11 14:01:36.819 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Creating new instance of command class COMMAND_CLASS_NO_OPERATION 2020-02-11 14:01:36.820 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-02-11 14:01:36.821 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Version = 1, version set. Enabling extra functionality. 2020-02-11 14:01:36.822 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes. 2020-02-11 14:01:36.822 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Creating new instance of command class COMMAND_CLASS_BASIC 2020-02-11 14:01:36.823 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-02-11 14:01:36.824 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes. 2020-02-11 14:01:36.825 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 317: Transaction COMPLETED 2020-02-11 14:01:36.826 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 32ms 2020-02-11 14:01:36.827 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 317: Transaction completed 2020-02-11 14:01:36.828 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:317 DONE 2020-02-11 14:01:36.833 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:36.834 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:36.835 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 03 B9 2020-02-11 14:01:36.836 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 317: Transaction event listener: DONE: DONE -> 2020-02-11 14:01:36.836 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 03 B9 2020-02-11 14:01:36.838 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1f129fc 2020-02-11 14:01:36.838 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:36.838 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:36.839 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 318: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.839 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node Init transaction completed with response COMPLETE 2020-02-11 14:01:36.839 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.840 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 318: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.841 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 9C 01 04 10 01 ED 2020-02-11 14:01:36.842 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:36.842 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: Node advancer - advancing to PING 2020-02-11 14:01:36.843 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:36.843 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Got an event from Z-Wave network: ZWaveInitializationStateEvent 2020-02-11 14:01:36.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.846 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 9C 01 04 10 01 2020-02-11 14:01:36.851 [DEBUG] [ndclass.ZWaveNoOperationCommandClass] - NODE 15: Creating new message for command NO_OPERATION_PING 2020-02-11 14:01:36.852 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 15: ZWaveCommandClassTransactionPayload - send to node 2020-02-11 14:01:36.853 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: SECURITY not supported 2020-02-11 14:01:36.854 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 9C 01 04 10 01 2020-02-11 14:01:36.854 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Command Class COMMAND_CLASS_NO_OPERATION is NOT required to be secured 2020-02-11 14:01:36.855 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 318: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.855 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:36.855 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@f3afa6 ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:36.854 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node15' changed from ONLINE to ONLINE: Node initialising: PING ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:36.856 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 318: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.857 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 9C 01 04 10 01 2020-02-11 14:01:36.858 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 3: ProtocolInfo 2020-02-11 14:01:36.859 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 3: Listening = true 2020-02-11 14:01:36.860 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 3: Routing = true 2020-02-11 14:01:36.861 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 3: Beaming = true 2020-02-11 14:01:36.863 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 3: Version = 4 2020-02-11 14:01:36.863 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Adding to device queue 2020-02-11 14:01:36.864 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Added 325 to queue - size 4 2020-02-11 14:01:36.864 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 3: FLIRS = false 2020-02-11 14:01:36.865 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 3: Security = false 2020-02-11 14:01:36.865 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.866 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 3: Max Baud = 40000 2020-02-11 14:01:36.867 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 3: Basic = BASIC_TYPE_ROUTING_SLAVE 2020-02-11 14:01:36.868 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 3: Generic = GENERIC_TYPE_SWITCH_BINARY 2020-02-11 14:01:36.869 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 3: Specific = SPECIFIC_TYPE_POWER_SWITCH_BINARY 2020-02-11 14:01:36.871 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Creating new instance of command class COMMAND_CLASS_NO_OPERATION 2020-02-11 14:01:36.872 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-02-11 14:01:36.873 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Version = 1, version set. Enabling extra functionality. 2020-02-11 14:01:36.874 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes. 2020-02-11 14:01:36.876 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Creating new instance of command class COMMAND_CLASS_BASIC 2020-02-11 14:01:36.877 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-02-11 14:01:36.878 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes. 2020-02-11 14:01:36.879 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 318: Transaction COMPLETED 2020-02-11 14:01:36.881 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 42ms 2020-02-11 14:01:36.882 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 318: Transaction completed 2020-02-11 14:01:36.884 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:318 DONE 2020-02-11 14:01:36.885 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:36.885 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 318: Transaction event listener: DONE: DONE -> 2020-02-11 14:01:36.886 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:36.888 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 0A B0 2020-02-11 14:01:36.889 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1bef902 2020-02-11 14:01:36.889 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 0A B0 2020-02-11 14:01:36.890 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node Init transaction completed with response COMPLETE 2020-02-11 14:01:36.890 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:36.890 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer - advancing to PING 2020-02-11 14:01:36.891 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveInitializationStateEvent 2020-02-11 14:01:36.891 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 320: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.892 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:36.894 [DEBUG] [ndclass.ZWaveNoOperationCommandClass] - NODE 3: Creating new message for command NO_OPERATION_PING 2020-02-11 14:01:36.893 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.897 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:36.895 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node3' changed from ONLINE to ONLINE: Node initialising: PING ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:36.897 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 53 9C 01 04 07 01 7A 2020-02-11 14:01:36.894 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: ZWaveCommandClassTransactionPayload - send to node 2020-02-11 14:01:36.899 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY doesn't encrypt PING 2020-02-11 14:01:36.900 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 07 01 2020-02-11 14:01:36.900 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Command Class COMMAND_CLASS_NO_OPERATION is NOT required to be secured 2020-02-11 14:01:36.898 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 320: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.901 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@bc7a91 2020-02-11 14:01:36.902 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:36.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue 2020-02-11 14:01:36.904 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 07 01 2020-02-11 14:01:36.904 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 326 to queue - size 5 2020-02-11 14:01:36.905 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 320: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.905 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.906 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:36.907 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 320: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.909 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 07 01 2020-02-11 14:01:36.910 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: ProtocolInfo 2020-02-11 14:01:36.911 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Listening = false 2020-02-11 14:01:36.912 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Routing = true 2020-02-11 14:01:36.913 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Beaming = true 2020-02-11 14:01:36.914 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Version = 4 2020-02-11 14:01:36.916 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: FLIRS = false 2020-02-11 14:01:36.917 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Security = false 2020-02-11 14:01:36.918 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Max Baud = 40000 2020-02-11 14:01:36.918 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Basic = BASIC_TYPE_ROUTING_SLAVE 2020-02-11 14:01:36.920 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Generic = GENERIC_TYPE_SENSOR_NOTIFICATION 2020-02-11 14:01:36.921 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Specific = SPECIFIC_TYPE_NOTIFICATION_SENSOR 2020-02-11 14:01:36.922 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Creating new instance of command class COMMAND_CLASS_NO_OPERATION 2020-02-11 14:01:36.924 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-02-11 14:01:36.925 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Version = 1, version set. Enabling extra functionality. 2020-02-11 14:01:36.926 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes. 2020-02-11 14:01:36.927 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Creating new instance of command class COMMAND_CLASS_BASIC 2020-02-11 14:01:36.929 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-02-11 14:01:36.931 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes. 2020-02-11 14:01:36.932 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 320: Transaction COMPLETED 2020-02-11 14:01:36.935 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 43ms 2020-02-11 14:01:36.936 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 320: Transaction completed 2020-02-11 14:01:36.937 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:320 DONE 2020-02-11 14:01:36.938 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:36.938 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 320: Transaction event listener: DONE: DONE -> 2020-02-11 14:01:36.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:36.939 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@3b0675 2020-02-11 14:01:36.940 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 0D B7 2020-02-11 14:01:36.940 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node Init transaction completed with response COMPLETE 2020-02-11 14:01:36.941 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - advancing to REQUEST_NIF 2020-02-11 14:01:36.941 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 0D B7 2020-02-11 14:01:36.942 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveInitializationStateEvent 2020-02-11 14:01:36.942 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:36.943 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:36.943 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 321: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.944 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1398ed6 2020-02-11 14:01:36.945 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.945 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Bump transaction 327 priority from Controller to Immediate 2020-02-11 14:01:36.946 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Adding to device queue 2020-02-11 14:01:36.946 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:36.946 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 53 9C 01 04 18 01 65 2020-02-11 14:01:36.946 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Added 327 to queue - size 6 2020-02-11 14:01:36.946 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 321: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.947 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:36.947 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.948 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:36.947 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node10' changed from ONLINE to ONLINE: Node initialising: REQUEST_NIF ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:36.950 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:36.952 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 18 01 2020-02-11 14:01:36.953 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 18 01 2020-02-11 14:01:36.954 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 321: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.955 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:36.956 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 321: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:36.957 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 18 01 2020-02-11 14:01:36.958 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 13: ProtocolInfo 2020-02-11 14:01:36.959 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 13: Listening = false 2020-02-11 14:01:36.960 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 13: Routing = true 2020-02-11 14:01:36.961 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 13: Beaming = true 2020-02-11 14:01:36.962 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 13: Version = 4 2020-02-11 14:01:36.963 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 13: FLIRS = false 2020-02-11 14:01:36.964 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 13: Security = false 2020-02-11 14:01:36.965 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 13: Max Baud = 40000 2020-02-11 14:01:36.966 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 13: Basic = BASIC_TYPE_ROUTING_SLAVE 2020-02-11 14:01:36.967 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 13: Generic = GENERIC_TYPE_WALL_CONTROLLER 2020-02-11 14:01:36.968 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 13: Specific = SPECIFIC_TYPE_BASIC_WALL_CONTROLLER 2020-02-11 14:01:36.969 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Creating new instance of command class COMMAND_CLASS_NO_OPERATION 2020-02-11 14:01:36.971 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-02-11 14:01:36.972 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Version = 1, version set. Enabling extra functionality. 2020-02-11 14:01:36.985 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes. 2020-02-11 14:01:36.986 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Creating new instance of command class COMMAND_CLASS_BASIC 2020-02-11 14:01:36.990 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 13: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-02-11 14:01:36.993 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 13: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes. 2020-02-11 14:01:37.002 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 321: Transaction COMPLETED 2020-02-11 14:01:37.004 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 61ms 2020-02-11 14:01:37.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 321: Transaction completed 2020-02-11 14:01:37.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:321 DONE 2020-02-11 14:01:37.013 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:37.015 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 321: Transaction event listener: DONE: DONE -> 2020-02-11 14:01:37.018 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:37.020 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 13: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@c49afe 2020-02-11 14:01:37.021 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 13: Node Init transaction completed with response COMPLETE 2020-02-11 14:01:37.022 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 13: Node advancer - advancing to REQUEST_NIF 2020-02-11 14:01:37.023 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 0C B6 2020-02-11 14:01:37.023 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Got an event from Z-Wave network: ZWaveInitializationStateEvent ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:37.027 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node13' changed from ONLINE to ONLINE: Node initialising: REQUEST_NIF ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:37.026 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 0C B6 2020-02-11 14:01:37.027 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1c61742 2020-02-11 14:01:37.038 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:37.040 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:37.040 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:37.041 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 322: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:37.043 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Bump transaction 328 priority from Controller to Immediate 2020-02-11 14:01:37.044 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:37.042 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 53 9C 01 04 18 01 65 2020-02-11 14:01:37.044 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Adding to device queue 2020-02-11 14:01:37.047 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 18 01 2020-02-11 14:01:37.047 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 322: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:37.049 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:37.049 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 13: Added 328 to queue - size 7 2020-02-11 14:01:37.050 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:37.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 18 01 2020-02-11 14:01:37.053 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 322: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:37.054 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:37.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 322: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:37.057 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=53 9C 01 04 18 01 2020-02-11 14:01:37.058 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: ProtocolInfo 2020-02-11 14:01:37.059 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Listening = false 2020-02-11 14:01:37.061 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Routing = true 2020-02-11 14:01:37.062 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Beaming = true 2020-02-11 14:01:37.063 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Version = 4 2020-02-11 14:01:37.064 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: FLIRS = false 2020-02-11 14:01:37.067 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Security = false 2020-02-11 14:01:37.068 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Max Baud = 40000 2020-02-11 14:01:37.069 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Basic = BASIC_TYPE_ROUTING_SLAVE 2020-02-11 14:01:37.071 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Generic = GENERIC_TYPE_WALL_CONTROLLER 2020-02-11 14:01:37.072 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 12: Specific = SPECIFIC_TYPE_BASIC_WALL_CONTROLLER 2020-02-11 14:01:37.073 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Creating new instance of command class COMMAND_CLASS_NO_OPERATION 2020-02-11 14:01:37.075 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created 2020-02-11 14:01:37.076 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Version = 1, version set. Enabling extra functionality. 2020-02-11 14:01:37.078 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes. 2020-02-11 14:01:37.079 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Creating new instance of command class COMMAND_CLASS_BASIC 2020-02-11 14:01:37.081 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 12: Command class COMMAND_CLASS_BASIC, endpoint 0 created 2020-02-11 14:01:37.082 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes. 2020-02-11 14:01:37.084 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 322: Transaction COMPLETED 2020-02-11 14:01:37.085 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 44ms 2020-02-11 14:01:37.086 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 322: Transaction completed 2020-02-11 14:01:37.087 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:322 DONE 2020-02-11 14:01:37.089 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:37.089 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 322: Transaction event listener: DONE: DONE -> 2020-02-11 14:01:37.090 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:37.090 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1cda2f2 2020-02-11 14:01:37.091 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node Init transaction completed with response COMPLETE 2020-02-11 14:01:37.092 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 02 01 00 25 2A E8 2020-02-11 14:01:37.093 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - advancing to REQUEST_NIF 2020-02-11 14:01:37.094 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 08 00 13 02 01 00 25 2A E8 2020-02-11 14:01:37.094 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveInitializationStateEvent 2020-02-11 14:01:37.096 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:37.097 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 324: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 42 2020-02-11 14:01:37.097 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:37.098 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:37.101 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@cf242f ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:37.102 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node12' changed from ONLINE to ONLINE: Node initialising: REQUEST_NIF ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:37.103 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2020-02-11 14:01:37.100 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:37.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-02-11 14:01:37.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 324: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 42 2020-02-11 14:01:37.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:37.107 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Bump transaction 329 priority from Controller to Immediate 2020-02-11 14:01:37.108 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-02-11 14:01:37.108 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Adding to device queue 2020-02-11 14:01:37.108 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 324: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 42 2020-02-11 14:01:37.110 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Added 329 to queue - size 7 2020-02-11 14:01:37.111 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:37.112 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:37.113 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 324: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 42 2020-02-11 14:01:37.114 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-02-11 14:01:37.115 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack. 2020-02-11 14:01:37.117 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 324: Advanced to WAIT_REQUEST 2020-02-11 14:01:37.118 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 324: Transaction not completed 2020-02-11 14:01:37.118 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:37.119 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:37.123 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 2A 00 00 02 00 CA 7F 7F 7F 7F 00 00 03 00 00 00 00 03 01 00 00 17 2020-02-11 14:01:37.125 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=42, payload=2A 00 00 02 00 CA 7F 7F 7F 7F 00 00 03 00 00 00 00 03 01 00 00 2020-02-11 14:01:37.126 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=42, payload=2A 00 00 02 00 CA 7F 7F 7F 7F 00 00 03 00 00 00 00 03 01 00 00 2020-02-11 14:01:37.127 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 324: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 42 2020-02-11 14:01:37.127 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:37.128 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 324: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 42 2020-02-11 14:01:37.129 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 324: (Callback 42) 2020-02-11 14:01:37.130 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-02-11 14:01:37.131 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 324: callback 42 2020-02-11 14:01:37.133 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=42, payload=2A 00 00 02 00 CA 7F 7F 7F 7F 00 00 03 00 00 00 00 03 01 00 00 2020-02-11 14:01:37.134 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 42, Status = Transmission complete and ACK received(0) 2020-02-11 14:01:37.134 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 324: Transaction COMPLETED 2020-02-11 14:01:37.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Response processed after 38ms 2020-02-11 14:01:37.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 324: Transaction completed 2020-02-11 14:01:37.137 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:324 DONE 2020-02-11 14:01:37.139 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2020-02-11 14:01:37.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 324: Transaction event listener: DONE: DONE -> 2020-02-11 14:01:37.140 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:37.140 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@57a56b 2020-02-11 14:01:37.141 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:37.141 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init transaction completed with response COMPLETE 2020-02-11 14:01:37.141 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 0F 01 00 25 2B E4 2020-02-11 14:01:37.142 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - advancing to REQUEST_NIF 2020-02-11 14:01:37.142 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 15: Sending REQUEST Message = 01 08 00 13 0F 01 00 25 2B E4 2020-02-11 14:01:37.143 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInitializationStateEvent 2020-02-11 14:01:37.143 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:37.144 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 325: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 43 2020-02-11 14:01:37.145 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@f145ac 2020-02-11 14:01:37.146 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue ==> /var/log/openhab2/events.log <== 2020-02-11 14:01:37.148 [hingStatusInfoChangedEvent] - 'zwave:device:cf541806:node2' changed from ONLINE: Node initialising: PING to ONLINE: Node initialising: REQUEST_NIF ==> /var/log/openhab2/openhab.log <== 2020-02-11 14:01:37.149 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 330 to queue - size 7 2020-02-11 14:01:37.146 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:37.152 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:37.151 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:37.153 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:37.154 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 325: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 43 2020-02-11 14:01:37.154 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2020-02-11 14:01:37.155 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:37.155 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-02-11 14:01:37.155 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:37.156 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:37.157 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-02-11 14:01:37.158 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 325: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 43 2020-02-11 14:01:37.159 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:37.160 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 325: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 43 2020-02-11 14:01:37.161 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-02-11 14:01:37.161 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 15: sentData successfully placed on stack. 2020-02-11 14:01:37.162 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 325: Advanced to WAIT_REQUEST 2020-02-11 14:01:37.163 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: TID 325: Transaction not completed 2020-02-11 14:01:37.165 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:37.166 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:42.163 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 15: TID 325: Timeout at state WAIT_REQUEST. 3 retries remaining. 2020-02-11 14:01:42.165 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction! 2020-02-11 14:01:42.167 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 325: Transaction ABORTED 2020-02-11 14:01:42.169 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 2020-02-11 14:01:42.171 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 2020-02-11 14:01:42.173 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:42.174 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:42.176 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:42.176 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:42.177 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:42.178 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 325: [ABORTED] priority=Poll, requiresResponse=true, callback: 43 2020-02-11 14:01:42.180 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:42.181 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:42.184 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:43.910 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 13 2B 01 02 A4 00 7F 7F 7F 7F 7F 00 01 07 00 00 00 00 02 0B 03 0F 04 2020-02-11 14:01:43.913 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=43, payload=2B 01 02 A4 00 7F 7F 7F 7F 7F 00 01 07 00 00 00 00 02 0B 03 0F 2020-02-11 14:01:43.916 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=43, payload=2B 01 02 A4 00 7F 7F 7F 7F 7F 00 01 07 00 00 00 00 02 0B 03 0F 2020-02-11 14:01:43.917 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 325: [ABORTED] priority=Poll, requiresResponse=true, callback: 43 2020-02-11 14:01:43.919 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:43.920 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 325: [ABORTED] priority=Poll, requiresResponse=true, callback: 43 2020-02-11 14:01:43.922 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 325: (Callback 43) 2020-02-11 14:01:43.923 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2020-02-11 14:01:43.925 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 325: callback 43 2020-02-11 14:01:43.927 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=43, payload=2B 01 02 A4 00 7F 7F 7F 7F 7F 00 01 07 00 00 00 00 02 0B 03 0F 2020-02-11 14:01:43.929 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 15: SendData Request. CallBack ID = 43, Status = Transmission complete, no ACK received(1) 2020-02-11 14:01:43.930 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 325: Transaction CANCELLED 2020-02-11 14:01:43.932 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2020-02-11 14:01:43.934 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: CANCEL while sending message. Requeueing - 2 attempts left! 2020-02-11 14:01:43.936 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 325: Transaction RESET with 2 retries remaining. 2020-02-11 14:01:43.937 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Adding to device queue 2020-02-11 14:01:43.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Added 325 to queue - size 8 2020-02-11 14:01:43.941 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:43.943 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 60 02 99 2020-02-11 14:01:43.945 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 60 02 99 2020-02-11 14:01:43.947 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:43.948 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:43.949 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 330: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:43.950 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:43.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: TID 325: Transaction not completed 2020-02-11 14:01:43.952 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:43.954 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:43.956 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:43.958 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 330: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:43.959 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:43.960 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:43.960 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 60 01 9B 2020-02-11 14:01:43.962 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:43.968 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2020-02-11 14:01:43.971 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2020-02-11 14:01:43.972 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 330: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:43.975 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:43.976 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 330: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:43.979 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=RequestNodeInfo[96], type=Response[1], dest=255, callback=0, payload=01 2020-02-11 14:01:43.981 [DEBUG] [lmessage.RequestNodeInfoMessageClass] - Request node info successfully placed on stack. 2020-02-11 14:01:43.983 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 330: Advanced to WAIT_DATA 2020-02-11 14:01:43.985 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 330: Transaction not completed 2020-02-11 14:01:43.988 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:43.989 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:43.992 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 18 00 49 84 02 12 04 21 01 5E 86 72 59 85 73 71 84 80 30 31 70 7A 5A EF D0 2020-02-11 14:01:43.996 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=2, callback=132, payload=84 02 12 04 21 01 5E 86 72 59 85 73 71 84 80 30 31 70 7A 5A EF 2020-02-11 14:01:43.999 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=2, callback=132, payload=84 02 12 04 21 01 5E 86 72 59 85 73 71 84 80 30 31 70 7A 5A EF 2020-02-11 14:01:44.000 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 330: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:44.002 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:44.006 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 330: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:44.008 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 330: (Callback 0) 2020-02-11 14:01:44.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 330: callback 0 2020-02-11 14:01:44.013 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=2, callback=132, payload=84 02 12 04 21 01 5E 86 72 59 85 73 71 84 80 30 31 70 7A 5A EF 2020-02-11 14:01:44.015 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update request. Node information received. Transaction TID 330: [WAIT_DATA] priority=Controller, requiresResponse=true, callback: 0 2020-02-11 14:01:44.016 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 330: Transaction COMPLETED 2020-02-11 14:01:44.017 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Response processed after 68ms 2020-02-11 14:01:44.018 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 330: Transaction completed 2020-02-11 14:01:44.019 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:330 DONE 2020-02-11 14:01:44.021 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2020-02-11 14:01:44.022 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:44.023 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2020-02-11 14:01:44.023 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 330: Transaction event listener: DONE: DONE -> 2020-02-11 14:01:44.024 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@ee27e3 2020-02-11 14:01:44.025 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init transaction completed with response COMPLETE 2020-02-11 14:01:44.026 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 0F 01 00 25 2C E3 2020-02-11 14:01:44.026 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: Restored from file - skipping static initialisation 2020-02-11 14:01:44.026 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 15: Sending REQUEST Message = 01 08 00 13 0F 01 00 25 2C E3 2020-02-11 14:01:44.027 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2020-02-11 14:01:44.027 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - advancing to STATIC_END 2020-02-11 14:01:44.028 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInitializationStateEvent 2020-02-11 14:01:44.028 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 325: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 44 2020-02-11 14:01:44.029 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2020-02-11 14:01:44.030 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties. 2020-02-11 14:01:44.030 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:44.031 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2020-02-11 14:01:44.031 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties. MAN=134 2020-02-11 14:01:44.032 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 325: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 44 2020-02-11 14:01:44.032 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties. MAN=134. SET. Was 134 2020-02-11 14:01:44.033 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2020-02-11 14:01:44.035 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:44.035 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Properties synchronised 2020-02-11 14:01:44.036 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:44.038 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2020-02-11 14:01:44.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-02-11 14:01:44.041 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-02-11 14:01:44.042 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 325: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 44 2020-02-11 14:01:44.045 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Update ASSOCIATION group_ZWaveAssociationGroup [index=1, name=null, profile1=null, profile2=null, associations=[node_1]]: Adding Controller (node_1) 2020-02-11 14:01:44.046 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2020-02-11 14:01:44.047 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising Thing Node... 2020-02-11 14:01:44.047 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 325: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 44 2020-02-11 14:01:44.048 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2020-02-11 14:01:44.048 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:cf541806:node2:sensor_temperature for QuantityType 2020-02-11 14:01:44.049 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:cf541806:node2:sensor_temperature for QuantityType 2020-02-11 14:01:44.049 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 15: sentData successfully placed on stack. 2020-02-11 14:01:44.050 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:cf541806:node2:sensor_ultraviolet for DecimalType 2020-02-11 14:01:44.051 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:cf541806:node2:sensor_ultraviolet for DecimalType 2020-02-11 14:01:44.052 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 325: Advanced to WAIT_REQUEST 2020-02-11 14:01:44.053 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: TID 325: Transaction not completed 2020-02-11 14:01:44.053 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:cf541806:node2:sensor_luminance for DecimalType 2020-02-11 14:01:44.054 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:cf541806:node2:sensor_luminance for DecimalType 2020-02-11 14:01:44.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2020-02-11 14:01:44.056 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:cf541806:node2:sensor_relhumidity for DecimalType 2020-02-11 14:01:44.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2020-02-11 14:01:44.057 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:cf541806:node2:sensor_relhumidity for DecimalType 2020-02-11 14:01:44.059 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:cf541806:node2:alarm_motion for OnOffType 2020-02-11 14:01:44.060 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:cf541806:node2:alarm_motion for OnOffType 2020-02-11 14:01:44.061 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:cf541806:node2:alarm_tamper for OnOffType 2020-02-11 14:01:44.062 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:cf541806:node2:alarm_tamper for OnOffType 2020-02-11 14:01:44.064 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:cf541806:node2:battery-level for PercentType 2020-02-11 14:01:44.065 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:cf541806:node2:battery-level for PercentType 2020-02-11 14:01:44.066 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling initialised at 86400 seconds - start in 36547200 milliseconds. 2020-02-11 14:01:44.067 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 2: Serialise aborted as static stages not complete 2020-02-11 14:01:44.069 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - advancing to DYNAMIC_VALUES 2020-02-11 14:01:44.070 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveInitializationStateEvent 2020-02-11 14:01:44.071 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_ZWAVEPLUS_INFO 2020-02-11 14:01:44.072 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_SENSOR_BINARY 2020-02-11 14:01:44.073 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Found 1 instances of COMMAND_CLASS_SENSOR_BINARY for endpoint 0 2020-02-11 14:01:44.074 [DEBUG] [dclass.ZWaveBinarySensorCommandClass] - NODE 2: Creating new message for application command SENSOR_BINARY_GET 2020-02-11 14:01:44.075 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported 2020-02-11 14:01:44.076 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_SENSOR_BINARY is NOT required to be secured 2020-02-11 14:01:44.077 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: ZWaveCommandClassTransactionPayload - send to node 2020-02-11 14:01:44.078 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported 2020-02-11 14:01:44.082 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_SENSOR_BINARY is NOT required to be secured 2020-02-11 14:01:44.084 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@18d66da 2020-02-11 14:01:44.085 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue 2020-02-11 14:01:44.086 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 331 to queue - size 7 2020-02-11 14:01:44.087 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.