tail -f /var/log/openhab2/openhab.log /var/log/openhab2/events.log 2019-06-15 12:21:55.727 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@e892e. 2019-06-15 12:21:55.728 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-15 12:21:55.730 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-15 12:21:55.731 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-15 12:21:55.732 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 12:26:40.786 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Handler disposed. Unregistering listener. 2019-06-15 12:26:40.820 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 10: Serialise aborted as static stages not complete 2019-06-15 12:26:40.821 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:16b56bde664:node10. 2019-06-15 12:26:40.825 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Controller status changed to ONLINE. 2019-06-15 12:26:40.826 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Controller is ONLINE. Starting device initialisation. 2019-06-15 12:26:40.834 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating node properties. 2019-06-15 12:26:40.838 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating node properties. MAN=271 2019-06-15 12:26:40.839 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating node properties. MAN=271. SET. Was 271 2019-06-15 12:26:40.842 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Properties synchronised 2019-06-15 12:26:40.846 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Update ASSOCIATION group_ZWaveAssociationGroup [index=1, name=Lifeline, profile1=0, profile2=1, associations=[node_1]]: Adding node_1 2019-06-15 12:26:40.849 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Configuration synchronised ==> /var/log/openhab2/events.log <== 2019-06-15 12:26:40.875 [hingStatusInfoChangedEvent] - 'zwave:device:16b56bde664:node10' changed from ONLINE: Node initialising: REQUEST_NIF to OFFLINE (BRIDGE_OFFLINE): Controller is offline ==> /var/log/openhab2/openhab.log <== 2019-06-15 12:26:40.892 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added. 2019-06-15 12:26:40.893 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising Thing Node... 2019-06-15 12:26:40.895 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising cmd channel zwave:device:16b56bde664:node10:sensor_binary for OnOffType 2019-06-15 12:26:40.896 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising state channel zwave:device:16b56bde664:node10:sensor_binary for OnOffType 2019-06-15 12:26:40.898 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising state channel zwave:device:16b56bde664:node10:sensor_binary for OnOffType 2019-06-15 12:26:40.899 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising cmd channel zwave:device:16b56bde664:node10:sensor_temperature for QuantityType 2019-06-15 12:26:40.901 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising state channel zwave:device:16b56bde664:node10:sensor_temperature for QuantityType 2019-06-15 12:26:40.903 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising cmd channel zwave:device:16b56bde664:node10:sensor_seismicintensity for DecimalType 2019-06-15 12:26:40.905 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising state channel zwave:device:16b56bde664:node10:sensor_seismicintensity for DecimalType 2019-06-15 12:26:40.906 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising cmd channel zwave:device:16b56bde664:node10:sensor_luminance for DecimalType 2019-06-15 12:26:40.910 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising state channel zwave:device:16b56bde664:node10:sensor_luminance for DecimalType 2019-06-15 12:26:40.911 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising cmd channel zwave:device:16b56bde664:node10:alarm_motion for OnOffType 2019-06-15 12:26:40.913 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising state channel zwave:device:16b56bde664:node10:alarm_motion for OnOffType 2019-06-15 12:26:40.915 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising cmd channel zwave:device:16b56bde664:node10:alarm_tamper for OnOffType 2019-06-15 12:26:40.916 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising state channel zwave:device:16b56bde664:node10:alarm_tamper for OnOffType 2019-06-15 12:26:40.918 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising cmd channel zwave:device:16b56bde664:node10:battery-level for PercentType 2019-06-15 12:26:40.920 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising state channel zwave:device:16b56bde664:node10:battery-level for PercentType 2019-06-15 12:26:40.921 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising cmd channel zwave:device:16b56bde664:node10:alarm_general for OnOffType 2019-06-15 12:26:40.923 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Initialising state channel zwave:device:16b56bde664:node10:alarm_general for OnOffType 2019-06-15 12:26:40.925 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Polling intialised at 86400 seconds - start in 68342400 milliseconds. 2019-06-15 12:26:40.927 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Device initialisation complete. ==> /var/log/openhab2/events.log <== 2019-06-15 12:26:40.929 [hingStatusInfoChangedEvent] - 'zwave:device:16b56bde664:node10' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE 2019-06-15 12:26:40.961 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:16b56bde664:node10' has been updated. 2019-06-15 12:26:40.977 [vent.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]] 2019-06-15 12:26:40.991 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:16b56bde664:node10' has been updated. ==> /var/log/openhab2/openhab.log <== 2019-06-15 12:27:08.424 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:16b56bde664 2019-06-15 12:27:08.432 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do 2019-06-15 12:27:08.437 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:16b56bde664 2019-06-15 12:27:08.440 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2 2019-06-15 12:27:08.444 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added. 2019-06-15 12:27:08.447 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion 2019-06-15 12:27:08.451 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true. 2019-06-15 12:27:08.454 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 1296 to queue - size 1 2019-06-15 12:27:08.458 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 12:27:08.463 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 48 39 2019-06-15 12:27:08.467 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 48 39 2019-06-15 12:27:08.472 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-15 12:27:08.475 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 12:27:08.477 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 12:27:08.479 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2019-06-15 12:27:08.470 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-15 12:27:08.480 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 48 01 00 00 FB 2019-06-15 12:27:08.480 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-06-15 12:27:08.483 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-15 12:27:08.482 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1296: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 72 2019-06-15 12:27:08.487 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-15 12:27:08.491 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=72, payload=48 01 00 00 2019-06-15 12:27:08.494 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=72, payload=48 01 00 00 2019-06-15 12:27:08.496 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1296: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 72 2019-06-15 12:27:08.499 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-06-15 12:27:08.500 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 1296: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 72 2019-06-15 12:27:08.503 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 1296: (Callback 72) 2019-06-15 12:27:08.505 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2019-06-15 12:27:08.507 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 1296: callback 72 2019-06-15 12:27:08.510 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=72, payload=48 01 00 00 2019-06-15 12:27:08.513 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready. 2019-06-15 12:27:10.491 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery completed 2019-06-15 12:27:10.506 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 12:27:10.526 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery completed 2019-06-15 12:27:10.543 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 12:27:10.560 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovery completed 2019-06-15 12:27:10.577 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 12:27:10.742 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery completed 2019-06-15 12:27:10.748 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery resolved to thingType zwave:fibaro_fgd212_03_005 2019-06-15 12:27:10.868 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery completed 2019-06-15 12:27:10.874 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery resolved to thingType zwave:fibaro_fgs222_00_000 2019-06-15 12:27:10.984 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery completed 2019-06-15 12:27:10.988 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery resolved to thingType zwave:fibaro_fgwp102_03_002 2019-06-15 12:27:11.069 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery completed 2019-06-15 12:27:11.074 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 12:27:11.185 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 9: Device discovery completed 2019-06-15 12:27:11.190 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 9: Device discovery could not resolve to a thingType! Manufacturer data not known. 2019-06-15 12:27:11.237 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery completed 2019-06-15 12:27:11.242 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery resolved to thingType zwave:fibaro_fgms001_03_002 2019-06-15 12:27:13.486 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 1296: Timeout at state WAIT_REQUEST. 3 retries remaining. 2019-06-15 12:27:13.491 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 1296: Transaction is current transaction, so clearing!!!!! 2019-06-15 12:27:13.494 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1296: Transaction CANCELLED 2019-06-15 12:27:13.497 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:1296 CANCELLED 2019-06-15 12:27:13.499 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 12:27:38.436 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:16b56bde664 2019-06-15 12:27:38.440 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeSent 2019-06-15 12:27:38.443 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode. 2019-06-15 12:27:38.446 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 1297 to queue - size 1 2019-06-15 12:27:38.449 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 12:27:38.453 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 49 FC 2019-06-15 12:27:38.457 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 49 FC 2019-06-15 12:27:38.460 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-15 12:27:38.464 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-15 12:27:38.463 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1297: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 73 2019-06-15 12:27:38.466 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 12:27:38.514 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 49 06 09 00 F4 2019-06-15 12:27:38.517 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=73, payload=49 06 09 00 2019-06-15 12:27:39.525 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 0A 09 71 05 00 00 00 FF 07 08 00 73 2019-06-15 12:27:39.546 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 2<>126 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 09 71 05 00 00 00 FF 07 08 00 2019-06-15 12:27:43.467 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 1297: Timeout at state WAIT_REQUEST. 3 retries remaining. 2019-06-15 12:27:43.477 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 1297: Transaction is current transaction, so clearing!!!!! 2019-06-15 12:27:43.479 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1297: Transaction CANCELLED 2019-06-15 12:27:43.482 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:1297 CANCELLED 2019-06-15 12:27:43.485 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 12:27:53.489 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion timer at IncludeDone 2019-06-15 12:27:57.249 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 09 09 71 05 00 00 00 FF 06 16 00 6F 2019-06-15 12:27:57.256 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 3<>125 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 09 71 05 00 00 00 FF 06 16 00 2019-06-15 12:28:00.338 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 08 07 60 0D 01 01 25 03 FF 4D 2019-06-15 12:28:00.346 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 4<>124 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 07 60 0D 01 01 25 03 FF 2019-06-15 12:28:01.069 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 09 09 71 05 00 00 00 FF 06 17 00 6E 2019-06-15 12:28:01.077 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 5<>123 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 09 71 05 00 00 00 FF 06 17 00 2019-06-15 12:28:02.738 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 12 00 04 00 08 0C 60 0D 01 01 32 02 21 32 00 3A 00 00 99 2019-06-15 12:28:02.745 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 6<>122 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0C 60 0D 01 01 32 02 21 32 00 3A 00 00 2019-06-15 12:28:30.292 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 0A 0A 71 05 00 00 00 FF 07 00 01 08 6E 2019-06-15 12:28:30.299 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 7<>121 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0A 71 05 00 00 00 FF 07 00 01 08 2019-06-15 12:29:39.214 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 09 09 71 05 00 00 00 FF 06 16 00 6F 2019-06-15 12:29:39.220 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 8<>120 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 09 71 05 00 00 00 FF 06 16 00 2019-06-15 12:29:40.356 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 08 07 60 0D 01 01 25 03 00 B2 2019-06-15 12:29:40.362 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 9<>119 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 07 60 0D 01 01 25 03 00 2019-06-15 12:29:40.738 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 12 00 04 00 08 0C 60 0D 01 01 32 02 21 32 00 00 00 00 A3 2019-06-15 12:29:40.745 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 10<>118 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0C 60 0D 01 01 32 02 21 32 00 00 00 00 2019-06-15 12:29:41.161 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 0A 09 71 05 00 00 00 FF 07 08 00 73 2019-06-15 12:29:41.167 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 11<>117 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 09 71 05 00 00 00 FF 07 08 00 2019-06-15 12:29:42.529 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 09 09 71 05 00 00 00 FF 06 17 00 6E 2019-06-15 12:29:42.982 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 12<>116 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 09 71 05 00 00 00 FF 06 17 00 2019-06-15 12:30:11.673 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 0A 0A 71 05 00 00 00 FF 07 00 01 08 6E 2019-06-15 12:30:11.678 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 13<>115 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0A 71 05 00 00 00 FF 07 00 01 08 2019-06-15 12:30:26.799 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 0A 09 71 05 00 00 00 FF 07 08 00 73 2019-06-15 12:30:26.805 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 14<>114 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 09 71 05 00 00 00 FF 07 08 00 2019-06-15 12:30:57.404 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 0A 0A 71 05 00 00 00 FF 07 00 01 08 6E 2019-06-15 12:30:57.410 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 15<>113 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0A 71 05 00 00 00 FF 07 00 01 08 2019-06-15 12:30:59.076 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 0A 09 71 05 00 00 00 FF 07 08 00 73 2019-06-15 12:30:59.081 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 16<>112 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 09 71 05 00 00 00 FF 07 08 00 2019-06-15 12:31:29.209 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 0A 0A 71 05 00 00 00 FF 07 00 01 08 6E 2019-06-15 12:31:29.216 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 17<>111 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0A 71 05 00 00 00 FF 07 00 01 08 2019-06-15 12:32:52.664 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling... 2019-06-15 12:32:52.668 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling zwave:device:16b56bde664:node3:switch_binary1 2019-06-15 12:32:52.669 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 3: Generating poll message for COMMAND_CLASS_SWITCH_BINARY, endpoint 1 2019-06-15 12:32:52.671 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 3: Creating new message for application command SWITCH_BINARY_GET 2019-06-15 12:32:52.673 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Encapsulating message, instance / endpoint 1 2019-06-15 12:32:52.675 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 3: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1 2019-06-15 12:32:52.677 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL 2019-06-15 12:32:52.679 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured 2019-06-15 12:32:52.681 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling skipped for zwave:device:16b56bde664:node3:switch_binary1 on COMMAND_CLASS_BASIC 2019-06-15 12:32:52.683 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue 2019-06-15 12:32:52.685 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 1298 to queue - size 3 2019-06-15 12:32:52.687 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 12:32:52.691 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 03 06 60 0D 01 01 25 02 25 4A C1 2019-06-15 12:32:52.694 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0D 00 13 03 06 60 0D 01 01 25 02 25 4A C1 2019-06-15 12:32:52.696 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-15 12:32:52.699 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1298: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 74 2019-06-15 12:32:52.700 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-15 12:32:52.703 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 18<>110 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 12:32:52.707 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2019-06-15 12:32:52.710 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 19<>109 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-06-15 12:32:52.723 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4A 00 00 02 A3 2019-06-15 12:32:52.726 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 20<>108 : Message: class=SendData[19], type=Request[0], dest=0, callback=74, payload=4A 00 00 02 2019-06-15 12:32:52.736 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 03 07 60 0D 01 01 25 03 00 B9 2019-06-15 12:32:52.741 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 21<>107 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=3, callback=0, payload=00 03 07 60 0D 01 01 25 03 00 2019-06-15 12:32:54.702 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 3: TID 1298: Timeout at state WAIT_RESPONSE. 3 retries remaining. 2019-06-15 12:32:54.704 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction! 2019-06-15 12:32:54.706 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1298: Transaction ABORTED 2019-06-15 12:32:54.709 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 2019-06-15 12:32:54.712 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 2019-06-15 12:32:54.715 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-15 12:32:54.717 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-15 12:32:54.718 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-15 12:32:54.722 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 22<>106 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 12:33:06.708 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 3: TID 1298: Timeout at state ABORTED. 3 retries remaining. 2019-06-15 12:33:06.714 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 1298: Transaction is current transaction, so clearing!!!!! 2019-06-15 12:33:06.717 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1298: Transaction CANCELLED 2019-06-15 12:33:06.719 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2019-06-15 12:33:06.721 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: notifyTransactionResponse TID:1298 CANCELLED 2019-06-15 12:33:06.724 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 12:38:02.492 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 12 00 04 00 03 0C 60 0D 01 01 32 02 21 32 00 00 00 00 A8 2019-06-15 12:38:02.502 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 23<>105 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=3, callback=0, payload=00 03 0C 60 0D 01 01 32 02 21 32 00 00 00 00 2019-06-15 12:41:07.606 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 0A 09 71 05 00 00 00 FF 07 08 00 73 2019-06-15 12:41:07.617 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 24<>104 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 09 71 05 00 00 00 FF 07 08 00 2019-06-15 12:41:38.101 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 0A 0A 71 05 00 00 00 FF 07 00 01 08 6E 2019-06-15 12:41:38.111 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 25<>103 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0A 71 05 00 00 00 FF 07 00 01 08 2019-06-15 12:42:57.827 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 0A 09 71 05 00 00 00 FF 07 08 00 73 2019-06-15 12:42:57.836 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 26<>102 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 09 71 05 00 00 00 FF 07 08 00 2019-06-15 12:43:37.314 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 0A 0A 71 05 00 00 00 FF 07 00 01 08 6E 2019-06-15 12:43:37.323 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 27<>101 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0A 71 05 00 00 00 FF 07 00 01 08 2019-06-15 12:48:27.557 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:16b56bde664 2019-06-15 12:48:27.564 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeDone 2019-06-15 12:48:27.568 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion 2019-06-15 12:48:27.573 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done 2019-06-15 12:48:27.579 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:16b56bde664 2019-06-15 12:48:27.585 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2 2019-06-15 12:48:27.590 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added. 2019-06-15 12:48:27.595 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion 2019-06-15 12:48:27.603 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true. 2019-06-15 12:48:27.610 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 1299 to queue - size 1 2019-06-15 12:48:27.615 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 12:48:27.623 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 4B 3A 2019-06-15 12:48:27.630 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 4B 3A 2019-06-15 12:48:27.635 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-15 12:48:27.637 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-15 12:48:27.640 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1299: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 75 2019-06-15 12:48:27.643 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 28<>100 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 12:48:27.650 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 4B 01 00 00 F8 2019-06-15 12:48:27.706 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 29<>99 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=75, payload=4B 01 00 00 2019-06-15 12:48:29.646 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery completed 2019-06-15 12:48:29.743 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 12:48:29.759 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery completed 2019-06-15 12:48:29.777 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 12:48:29.792 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovery completed 2019-06-15 12:48:29.798 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 12:48:29.811 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery completed 2019-06-15 12:48:29.816 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery resolved to thingType zwave:fibaro_fgd212_03_005 2019-06-15 12:48:29.829 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery completed 2019-06-15 12:48:29.834 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery resolved to thingType zwave:fibaro_fgs222_00_000 2019-06-15 12:48:29.846 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery completed 2019-06-15 12:48:29.850 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery resolved to thingType zwave:fibaro_fgwp102_03_002 2019-06-15 12:48:29.859 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery completed 2019-06-15 12:48:29.864 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-15 12:48:29.876 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 9: Device discovery completed 2019-06-15 12:48:29.882 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 9: Device discovery could not resolve to a thingType! Manufacturer data not known. 2019-06-15 12:48:29.888 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery completed 2019-06-15 12:48:29.893 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery resolved to thingType zwave:fibaro_fgms001_03_002 2019-06-15 12:48:32.645 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 1299: Timeout at state WAIT_REQUEST. 3 retries remaining. 2019-06-15 12:48:32.651 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 1299: Transaction is current transaction, so clearing!!!!! 2019-06-15 12:48:32.654 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1299: Transaction CANCELLED 2019-06-15 12:48:32.657 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:1299 CANCELLED 2019-06-15 12:48:32.659 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 12:48:57.577 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:16b56bde664 2019-06-15 12:48:57.582 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeSent 2019-06-15 12:48:57.585 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode. 2019-06-15 12:48:57.588 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 1300 to queue - size 1 2019-06-15 12:48:57.591 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 12:48:57.596 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 4C F9 2019-06-15 12:48:57.600 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 4C F9 2019-06-15 12:48:57.604 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-15 12:48:57.607 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 30<>98 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 12:48:57.603 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-15 12:48:57.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1300: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 76 2019-06-15 12:48:57.658 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 4C 06 09 00 F1 2019-06-15 12:48:57.664 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 31<>97 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=76, payload=4C 06 09 00 2019-06-15 12:49:02.614 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 1300: Timeout at state WAIT_REQUEST. 3 retries remaining. 2019-06-15 12:49:02.623 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 1300: Transaction is current transaction, so clearing!!!!! 2019-06-15 12:49:02.625 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1300: Transaction CANCELLED 2019-06-15 12:49:02.628 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:1300 CANCELLED 2019-06-15 12:49:02.631 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 12:49:12.621 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion timer at IncludeDone ==> /var/log/openhab2/events.log <== 2019-06-15 12:50:46.092 [ome.event.ItemCommandEvent] - Item 'SwitchLichtToilet' received command ON ==> /var/log/openhab2/openhab.log <== 2019-06-15 12:50:46.101 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Command received zwave:device:16b56bde664:node8:switch_binary1 --> ON [OnOffType] 2019-06-15 12:50:46.105 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 8: Creating new message for application command SWITCH_BINARY_SET 2019-06-15 12:50:46.108 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Encapsulating message, instance / endpoint 1 2019-06-15 12:50:46.110 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 8: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1 2019-06-15 12:50:46.113 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL ==> /var/log/openhab2/events.log <== 2019-06-15 12:50:46.117 [nt.ItemStatePredictedEvent] - SwitchLichtToilet predicted to become ON ==> /var/log/openhab2/openhab.log <== 2019-06-15 12:50:46.116 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured 2019-06-15 12:50:46.120 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Adding to device queue 2019-06-15 12:50:46.122 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Added 1301 to queue - size 3 2019-06-15 12:50:46.127 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 12:50:46.132 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 13 08 07 60 0D 01 01 25 01 FF 25 4D 33 2019-06-15 12:50:46.136 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 8: Sending REQUEST Message = 01 0E 00 13 08 07 60 0D 01 01 25 01 FF 25 4D 33 2019-06-15 12:50:46.138 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-15 12:50:46.141 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1301: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 77 2019-06-15 12:50:46.141 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-15 12:50:46.144 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 32<>96 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 12:50:46.148 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2019-06-15 12:50:46.151 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Polling intialised at 86400 seconds - start in 1500 milliseconds. 2019-06-15 12:50:46.151 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 33<>95 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 ==> /var/log/openhab2/events.log <== 2019-06-15 12:50:46.189 [vent.ItemStateChangedEvent] - SwitchLichtToilet changed from OFF to ON ==> /var/log/openhab2/openhab.log <== 2019-06-15 12:50:46.220 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4D 00 00 08 AE 2019-06-15 12:50:46.224 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 34<>94 : Message: class=SendData[19], type=Request[0], dest=0, callback=77, payload=4D 00 00 08 2019-06-15 12:50:46.299 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 08 07 60 0D 01 01 25 03 FF 4D 2019-06-15 12:50:46.311 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 35<>93 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 07 60 0D 01 01 25 03 FF 2019-06-15 12:50:47.644 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Polling... 2019-06-15 12:50:47.648 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Polling zwave:device:16b56bde664:node8:switch_binary1 2019-06-15 12:50:47.653 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 8: Generating poll message for COMMAND_CLASS_SWITCH_BINARY, endpoint 1 2019-06-15 12:50:47.655 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 8: Creating new message for application command SWITCH_BINARY_GET 2019-06-15 12:50:47.659 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Encapsulating message, instance / endpoint 1 2019-06-15 12:50:47.662 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 8: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1 2019-06-15 12:50:47.667 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL 2019-06-15 12:50:47.669 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured 2019-06-15 12:50:47.674 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Polling skipped for zwave:device:16b56bde664:node8:switch_binary1 on COMMAND_CLASS_BASIC 2019-06-15 12:50:47.677 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Adding to device queue 2019-06-15 12:50:47.681 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Added 1302 to queue - size 3 2019-06-15 12:50:47.684 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. ==> /var/log/openhab2/events.log <== 2019-06-15 12:50:47.703 [ome.event.ItemCommandEvent] - Item 'SwitchLichtToilet' received command OFF ==> /var/log/openhab2/openhab.log <== 2019-06-15 12:50:47.716 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Command received zwave:device:16b56bde664:node8:switch_binary1 --> OFF [OnOffType] 2019-06-15 12:50:47.722 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 8: Creating new message for application command SWITCH_BINARY_SET 2019-06-15 12:50:47.726 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Encapsulating message, instance / endpoint 1 2019-06-15 12:50:47.731 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 8: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1 2019-06-15 12:50:47.734 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL 2019-06-15 12:50:47.740 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured ==> /var/log/openhab2/events.log <== 2019-06-15 12:50:47.742 [nt.ItemStatePredictedEvent] - SwitchLichtToilet predicted to become OFF ==> /var/log/openhab2/openhab.log <== 2019-06-15 12:50:47.742 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Adding to device queue 2019-06-15 12:50:47.745 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Added 1303 to queue - size 4 2019-06-15 12:50:47.748 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-15 12:50:47.750 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Polling intialised at 86400 seconds - start in 1500 milliseconds. ==> /var/log/openhab2/events.log <== 2019-06-15 12:50:47.794 [vent.ItemStateChangedEvent] - SwitchLichtToilet changed from ON to OFF ==> /var/log/openhab2/openhab.log <== 2019-06-15 12:50:48.142 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 8: TID 1301: Timeout at state WAIT_RESPONSE. 3 retries remaining. 2019-06-15 12:50:48.144 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction! 2019-06-15 12:50:48.145 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1301: Transaction ABORTED 2019-06-15 12:50:48.148 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 2019-06-15 12:50:48.150 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 2019-06-15 12:50:48.152 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-15 12:50:48.153 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-15 12:50:48.155 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-15 12:50:48.155 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 36<>92 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 12:50:48.739 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 12 00 04 00 08 0C 60 0D 01 01 32 02 21 32 00 34 00 00 97 2019-06-15 12:50:48.750 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 37<>91 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0C 60 0D 01 01 32 02 21 32 00 34 00 00 2019-06-15 12:50:49.250 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Polling... 2019-06-15 12:50:49.255 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Polling zwave:device:16b56bde664:node8:switch_binary1 2019-06-15 12:50:49.258 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 8: Generating poll message for COMMAND_CLASS_SWITCH_BINARY, endpoint 1 2019-06-15 12:50:49.262 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 8: Creating new message for application command SWITCH_BINARY_GET 2019-06-15 12:50:49.264 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Encapsulating message, instance / endpoint 1 2019-06-15 12:50:49.267 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 8: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1 2019-06-15 12:50:49.271 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL 2019-06-15 12:50:49.275 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured 2019-06-15 12:50:49.278 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Polling skipped for zwave:device:16b56bde664:node8:switch_binary1 on COMMAND_CLASS_BASIC 2019-06-15 12:50:49.282 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Adding to device queue 2019-06-15 12:50:49.285 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Transaction already in queue - removed original 2019-06-15 12:50:49.292 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Added 1304 to queue - size 4 2019-06-15 12:50:49.295 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-15 12:51:00.146 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 8: TID 1301: Timeout at state ABORTED. 3 retries remaining. 2019-06-15 12:51:00.148 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 1301: Transaction is current transaction, so clearing!!!!! 2019-06-15 12:51:00.151 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1301: Transaction CANCELLED 2019-06-15 12:51:00.153 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2019-06-15 12:51:00.155 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: notifyTransactionResponse TID:1301 CANCELLED 2019-06-15 12:51:00.158 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 12:51:00.164 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 13 08 07 60 0D 01 01 25 01 00 25 4E CF 2019-06-15 12:51:00.170 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 8: Sending REQUEST Message = 01 0E 00 13 08 07 60 0D 01 01 25 01 00 25 4E CF 2019-06-15 12:51:00.173 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-15 12:51:00.175 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1303: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 78 2019-06-15 12:51:00.175 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-15 12:51:00.178 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 38<>90 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 12:51:00.184 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2019-06-15 12:51:00.188 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 39<>89 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-06-15 12:51:00.255 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4E 00 00 07 A2 2019-06-15 12:51:00.261 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 40<>88 : Message: class=SendData[19], type=Request[0], dest=0, callback=78, payload=4E 00 00 07 2019-06-15 12:51:00.342 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 08 07 60 0D 01 01 25 03 00 B2 2019-06-15 12:51:00.356 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 41<>87 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 07 60 0D 01 01 25 03 00 2019-06-15 12:51:00.737 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 12 00 04 00 08 0C 60 0D 01 01 32 02 21 32 00 00 00 00 A3 2019-06-15 12:51:00.749 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 42<>86 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 0C 60 0D 01 01 32 02 21 32 00 00 00 00 2019-06-15 12:51:02.178 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 8: TID 1303: Timeout at state WAIT_RESPONSE. 3 retries remaining. 2019-06-15 12:51:02.181 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction! 2019-06-15 12:51:02.184 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1303: Transaction ABORTED 2019-06-15 12:51:02.188 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 2019-06-15 12:51:02.192 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 2019-06-15 12:51:02.195 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-15 12:51:02.197 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-15 12:51:02.198 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-15 12:51:02.200 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 43<>85 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 12:51:14.188 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 8: TID 1303: Timeout at state ABORTED. 3 retries remaining. 2019-06-15 12:51:14.190 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 1303: Transaction is current transaction, so clearing!!!!! 2019-06-15 12:51:14.193 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1303: Transaction CANCELLED 2019-06-15 12:51:14.195 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2019-06-15 12:51:14.197 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: notifyTransactionResponse TID:1303 CANCELLED 2019-06-15 12:51:14.200 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 12:51:14.205 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 08 06 60 0D 01 01 25 02 25 4F CF 2019-06-15 12:51:14.209 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 8: Sending REQUEST Message = 01 0D 00 13 08 06 60 0D 01 01 25 02 25 4F CF 2019-06-15 12:51:14.212 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-15 12:51:14.213 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-15 12:51:14.214 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1304: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 79 2019-06-15 12:51:14.218 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 44<>84 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 12:51:14.224 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2019-06-15 12:51:14.228 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 45<>83 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-06-15 12:51:14.294 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4F 00 00 07 A3 2019-06-15 12:51:14.299 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 46<>82 : Message: class=SendData[19], type=Request[0], dest=0, callback=79, payload=4F 00 00 07 2019-06-15 12:51:14.380 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 08 07 60 0D 01 01 25 03 00 B2 2019-06-15 12:51:14.386 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 47<>81 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=0, payload=00 08 07 60 0D 01 01 25 03 00 2019-06-15 12:51:14.648 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling... 2019-06-15 12:51:14.650 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling deferred until initialisation complete 2019-06-15 12:51:16.216 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 8: TID 1304: Timeout at state WAIT_RESPONSE. 3 retries remaining. 2019-06-15 12:51:16.218 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction! 2019-06-15 12:51:16.221 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1304: Transaction ABORTED 2019-06-15 12:51:16.224 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 2019-06-15 12:51:16.226 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 2019-06-15 12:51:16.229 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-15 12:51:16.231 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-15 12:51:16.233 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-15 12:51:16.236 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 48<>80 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-15 12:51:28.224 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 8: TID 1304: Timeout at state ABORTED. 3 retries remaining. 2019-06-15 12:51:28.226 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 1304: Transaction is current transaction, so clearing!!!!! 2019-06-15 12:51:28.228 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1304: Transaction CANCELLED 2019-06-15 12:51:28.231 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2019-06-15 12:51:28.234 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: notifyTransactionResponse TID:1304 CANCELLED 2019-06-15 12:51:28.237 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-15 12:52:19.936 [ERROR] [ersey.server.ServerRuntime$Responder] - An I/O error has occurred while writing a response message entity to the container output stream. org.glassfish.jersey.server.internal.process.MappableException: org.eclipse.jetty.io.EofException at org.glassfish.jersey.server.internal.MappableExceptionWrapperInterceptor.aroundWriteTo(MappableExceptionWrapperInterceptor.java:92) ~[?:?] at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:162) ~[128:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.message.internal.MessageBodyFactory.writeTo(MessageBodyFactory.java:1130) ~[128:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.server.ServerRuntime$Responder.writeResponse(ServerRuntime.java:711) [129:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.ServerRuntime$Responder.processResponse(ServerRuntime.java:444) [129:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.ServerRuntime$Responder.process(ServerRuntime.java:434) [129:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:329) [129:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [128:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [128:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [128:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [128:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [128:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) [128:org.glassfish.jersey.core.jersey-common:2.22.2] at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) [129:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) [129:org.glassfish.jersey.core.jersey-server:2.22.2] at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) [126:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) [126:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) [126:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) [126:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) [126:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2] at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76) [20:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253] at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:873) [92:org.eclipse.jetty.servlet:9.4.18.v20190429] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:542) [92:org.eclipse.jetty.servlet:9.4.18.v20190429] at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) [197:org.ops4j.pax.web.pax-web-jetty:7.2.10] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) [91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [89:org.eclipse.jetty.security:9.4.18.v20190429] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) [91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1700) [91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345) [91:org.eclipse.jetty.server:9.4.18.v20190429] at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:293) [197:org.ops4j.pax.web.pax-web-jetty:7.2.10] at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480) [92:org.eclipse.jetty.servlet:9.4.18.v20190429] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1667) [91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247) [91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [91:org.eclipse.jetty.server:9.4.18.v20190429] at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) [197:org.ops4j.pax.web.pax-web-jetty:7.2.10] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.Server.handle(Server.java:505) [91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:370) [91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:267) [91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305) [82:org.eclipse.jetty.io:9.4.18.v20190429] at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [82:org.eclipse.jetty.io:9.4.18.v20190429] at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) [82:org.eclipse.jetty.io:9.4.18.v20190429] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333) [94:org.eclipse.jetty.util:9.4.18.v20190429] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310) [94:org.eclipse.jetty.util:9.4.18.v20190429] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168) [94:org.eclipse.jetty.util:9.4.18.v20190429] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126) [94:org.eclipse.jetty.util:9.4.18.v20190429] at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366) [94:org.eclipse.jetty.util:9.4.18.v20190429] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:698) [94:org.eclipse.jetty.util:9.4.18.v20190429] at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:804) [94:org.eclipse.jetty.util:9.4.18.v20190429] at java.lang.Thread.run(Thread.java:748) [?:?] Caused by: org.eclipse.jetty.io.EofException at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:284) ~[82:org.eclipse.jetty.io:9.4.18.v20190429] at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:393) ~[82:org.eclipse.jetty.io:9.4.18.v20190429] at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:277) ~[82:org.eclipse.jetty.io:9.4.18.v20190429] at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:380) ~[82:org.eclipse.jetty.io:9.4.18.v20190429] at org.eclipse.jetty.server.HttpConnection$SendCallback.process(HttpConnection.java:814) ~[91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) ~[94:org.eclipse.jetty.util:9.4.18.v20190429] at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:224) ~[94:org.eclipse.jetty.util:9.4.18.v20190429] at org.eclipse.jetty.server.HttpConnection.send(HttpConnection.java:550) ~[91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.HttpChannel.sendResponse(HttpChannel.java:845) ~[91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:921) ~[91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:249) ~[91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:225) ~[91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:550) ~[91:org.eclipse.jetty.server:9.4.18.v20190429] at java.io.OutputStream.write(OutputStream.java:75) ~[?:?] at org.glassfish.jersey.servlet.internal.ResponseWriter$NonCloseableOutputStreamWrapper.write(ResponseWriter.java:320) ~[?:?] at org.glassfish.jersey.message.internal.CommittingOutputStream.write(CommittingOutputStream.java:218) ~[?:?] at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$UnCloseableOutputStream.write(WriterInterceptorExecutor.java:294) ~[?:?] at org.eclipse.smarthome.io.rest.core.internal.GsonProvider.writeTo(GsonProvider.java:71) ~[?:?] at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$TerminalWriterInterceptor.invokeWriteTo(WriterInterceptorExecutor.java:265) ~[?:?] at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$TerminalWriterInterceptor.aroundWriteTo(WriterInterceptorExecutor.java:250) ~[?:?] at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:162) ~[?:?] at org.glassfish.jersey.server.internal.JsonWithPaddingInterceptor.aroundWriteTo(JsonWithPaddingInterceptor.java:106) ~[?:?] at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:162) ~[?:?] at org.glassfish.jersey.server.internal.MappableExceptionWrapperInterceptor.aroundWriteTo(MappableExceptionWrapperInterceptor.java:86) ~[?:?] ... 53 more Caused by: java.io.IOException: Broken pipe at sun.nio.ch.FileDispatcherImpl.writev0(Native Method) ~[?:?] at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:51) ~[?:?] at sun.nio.ch.IOUtil.write(IOUtil.java:148) ~[?:?] at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:504) ~[?:?] at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:264) ~[82:org.eclipse.jetty.io:9.4.18.v20190429] at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:393) ~[82:org.eclipse.jetty.io:9.4.18.v20190429] at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:277) ~[82:org.eclipse.jetty.io:9.4.18.v20190429] at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:380) ~[82:org.eclipse.jetty.io:9.4.18.v20190429] at org.eclipse.jetty.server.HttpConnection$SendCallback.process(HttpConnection.java:814) ~[91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) ~[94:org.eclipse.jetty.util:9.4.18.v20190429] at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:224) ~[94:org.eclipse.jetty.util:9.4.18.v20190429] at org.eclipse.jetty.server.HttpConnection.send(HttpConnection.java:550) ~[91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.HttpChannel.sendResponse(HttpChannel.java:845) ~[91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:921) ~[91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:249) ~[91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:225) ~[91:org.eclipse.jetty.server:9.4.18.v20190429] at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:550) ~[91:org.eclipse.jetty.server:9.4.18.v20190429] at java.io.OutputStream.write(OutputStream.java:75) ~[?:?] at org.glassfish.jersey.servlet.internal.ResponseWriter$NonCloseableOutputStreamWrapper.write(ResponseWriter.java:320) ~[?:?] at org.glassfish.jersey.message.internal.CommittingOutputStream.write(CommittingOutputStream.java:218) ~[?:?] at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$UnCloseableOutputStream.write(WriterInterceptorExecutor.java:294) ~[?:?] at org.eclipse.smarthome.io.rest.core.internal.GsonProvider.writeTo(GsonProvider.java:71) ~[?:?] at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$TerminalWriterInterceptor.invokeWriteTo(WriterInterceptorExecutor.java:265) ~[?:?] at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$TerminalWriterInterceptor.aroundWriteTo(WriterInterceptorExecutor.java:250) ~[?:?] at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:162) ~[?:?] at org.glassfish.jersey.server.internal.JsonWithPaddingInterceptor.aroundWriteTo(JsonWithPaddingInterceptor.java:106) ~[?:?] at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:162) ~[?:?] at org.glassfish.jersey.server.internal.MappableExceptionWrapperInterceptor.aroundWriteTo(MappableExceptionWrapperInterceptor.java:86) ~[?:?] ... 53 more