2018-12-29 23:04:54.375 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart

2018-12-29 23:04:54.378 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 115: Transaction COMPLETED

2018-12-29 23:04:54.379 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 35ms

2018-12-29 23:04:54.381 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 115: Transaction completed

2018-12-29 23:04:54.382 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:115 DONE

2018-12-29 23:04:54.384 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2018-12-29 23:04:54.386 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2018-12-29 23:04:56.347 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery completed

2018-12-29 23:04:56.349 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery resolved to thingType zwave:tkb_tz68_00_000

2018-12-29 23:04:56.352 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery completed

2018-12-29 23:04:56.354 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery resolved to thingType zwave:tkb_tz68_00_000

2018-12-29 23:04:56.356 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovery completed

2018-12-29 23:04:56.358 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovery resolved to thingType zwave:telldus_tzwp100_00_000

2018-12-29 23:04:56.360 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery completed

2018-12-29 23:04:56.362 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery resolved to thingType zwave:shenzhen_doorwindowsensor_00_000

2018-12-29 23:04:56.364 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery completed

2018-12-29 23:04:56.365 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery resolved to thingType zwave:fibaro_fgwp102_03_002

2018-12-29 23:04:56.367 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery completed

2018-12-29 23:04:56.368 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery resolved to thingType zwave:qubino_zmnhod_00_000

2018-12-29 23:04:56.371 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery completed

2018-12-29 23:04:56.371 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery resolved to thingType zwave:philio_psr04_00_000

2018-12-29 23:04:56.373 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 9: Device discovery completed

2018-12-29 23:04:56.374 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 9: Device discovery resolved to thingType zwave:sensative_1101011_00_000

2018-12-29 23:04:56.376 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery completed

2018-12-29 23:04:56.378 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery resolved to thingType zwave:qubino_zmnhod_00_000

2018-12-29 23:04:56.380 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 11: Device discovery completed

2018-12-29 23:04:56.381 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 11: Device discovery resolved to thingType zwave:philio_psr04_00_000

2018-12-29 23:04:56.383 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 12: Device discovery completed

2018-12-29 23:04:56.384 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 12: Device discovery resolved to thingType zwave:telldus_tzwp100_00_000

2018-12-29 23:04:56.387 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 14: Device discovery completed

2018-12-29 23:04:56.389 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 14: Device discovery resolved to thingType zwave:qubino_zmnhod_00_000

2018-12-29 23:04:56.391 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 15: Device discovery completed

2018-12-29 23:04:56.392 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 15: Device discovery resolved to thingType zwave:philio_psr04_00_000

2018-12-29 23:04:56.394 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 16: Device discovery completed

2018-12-29 23:04:56.395 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 16: Device discovery resolved to thingType zwave:sensative_1101011_00_000

==> /var/log/openhab2/openhab.log <==

2018-12-29 23:05:04.441 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling...

2018-12-29 23:05:04.442 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling deferred until initialisation complete

2018-12-29 23:05:14.761 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 50 02 00 00 E0 

2018-12-29 23:05:14.762 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=80, payload=50 02 00 00 

2018-12-29 23:05:14.763 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=80, payload=50 02 00 00 

2018-12-29 23:05:14.764 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2018-12-29 23:05:14.765 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0

2018-12-29 23:05:14.766 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null

2018-12-29 23:05:14.767 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=2, callback=80, payload=50 02 00 00 

2018-12-29 23:05:14.768 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: New node found.

2018-12-29 23:05:14.770 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2018-12-29 23:05:14.770 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2018-12-29 23:05:17.961 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 50 07 00 00 E5 

2018-12-29 23:05:17.964 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=80, payload=50 07 00 00 

2018-12-29 23:05:17.965 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=80, payload=50 07 00 00 

2018-12-29 23:05:17.966 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2018-12-29 23:05:17.968 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0

2018-12-29 23:05:17.969 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null

2018-12-29 23:05:17.971 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=7, callback=80, payload=50 07 00 00 

2018-12-29 23:05:17.971 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Failed.

2018-12-29 23:05:17.972 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeStart, new event IncludeFail

2018-12-29 23:05:17.974 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.

2018-12-29 23:05:17.974 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 116 to queue - size 1

2018-12-29 23:05:17.975 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2018-12-29 23:05:17.976 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 51 E4 

2018-12-29 23:05:17.977 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 51 E4 

==> /var/log/openhab2/events.log <==

2018-12-29 23:05:17.978 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@2e7f4d9f

==> /var/log/openhab2/openhab.log <==

2018-12-29 23:05:17.980 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06

2018-12-29 23:05:17.982 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2018-12-29 23:05:17.984 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2018-12-29 23:05:17.984 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 116: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 81

2018-12-29 23:05:17.987 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2018-12-29 23:05:17.988 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 116: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 81

2018-12-29 23:05:17.989 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

2018-12-29 23:05:17.991 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2018-12-29 23:05:17.992 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2018-12-29 23:05:18.031 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 51 06 00 00 E5 

2018-12-29 23:05:18.033 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=81, payload=51 06 00 00 

2018-12-29 23:05:18.034 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=81, payload=51 06 00 00 

2018-12-29 23:05:18.035 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 116: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 81

2018-12-29 23:05:18.036 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2018-12-29 23:05:18.038 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 116: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 81

2018-12-29 23:05:18.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 116: (Callback 81)

2018-12-29 23:05:18.040 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!

2018-12-29 23:05:18.041 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 116: callback 81

2018-12-29 23:05:18.042 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=81, payload=51 06 00 00 

2018-12-29 23:05:18.043 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.

2018-12-29 23:05:18.044 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeFail, new event IncludeDone

2018-12-29 23:05:18.045 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.

2018-12-29 23:05:18.047 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 117 to queue - size 1

2018-12-29 23:05:18.048 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2018-12-29 23:05:18.049 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion

2018-12-29 23:05:18.050 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done

2018-12-29 23:05:18.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 116: Advanced to DONE

2018-12-29 23:05:18.052 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 68ms

2018-12-29 23:05:18.053 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 116: Transaction completed

2018-12-29 23:05:18.054 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:116 DONE

2018-12-29 23:05:18.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2018-12-29 23:05:18.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2018-12-29 23:05:18.057 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5 

2018-12-29 23:05:18.058 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5 

2018-12-29 23:05:18.060 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06

2018-12-29 23:05:18.061 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2018-12-29 23:05:18.062 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2018-12-29 23:05:18.063 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 117: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0

2018-12-29 23:05:18.064 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2018-12-29 23:05:18.065 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 117: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0

2018-12-29 23:05:18.066 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

2018-12-29 23:05:18.067 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2018-12-29 23:05:18.068 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.