Skip to content

Instantly share code, notes, and snippets.

@davidlballenger

davidlballenger/openhab.log

Created April 26, 2018 01:29
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save davidlballenger/48ed912b4a5e498c3fd1dfa58fc5014a to your computer and use it in GitHub Desktop.
Save davidlballenger/48ed912b4a5e498c3fd1dfa58fc5014a to your computer and use it in GitHub Desktop.
Download ZIP
z-wave log fo Levtion VRCZ4-MR
Raw
openhab.log
2018-04-25 17:28:32.777 [thome.event.ExtensionEvent] - Extension 'binding-zwave' has been installed.
2018-04-25 17:30:33.607 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:6140f4be' changed from UNINITIALIZED to INITIALIZING
==> /var/log/openhab2/openhab.log <==
2018-04-25 17:30:33.693 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'
==> /var/log/openhab2/events.log <==
2018-04-25 17:30:33.697 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:6140f4be' has been updated.
2018-04-25 17:30:33.706 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:6140f4be' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
==> /var/log/openhab2/openhab.log <==
2018-04-25 17:30:33.728 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2018-04-25 17:30:33.746 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - Update networkKey
2018-04-25 17:30:33.773 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2018-04-25 17:30:33.776 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2018-04-25 17:30:37.073 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 1: Node found
2018-04-25 17:30:37.077 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 2: Node found
2018-04-25 17:30:37.081 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 3: Node found
2018-04-25 17:30:37.085 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API
2018-04-25 17:30:37.088 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller
2018-04-25 17:30:37.091 [INFO ] [age.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------
2018-04-25 17:30:37.094 [INFO ] [age.SerialApiGetInitDataMessageClass] - # Nodes = 3
2018-04-25 17:30:37.098 [INFO ] [age.SerialApiGetInitDataMessageClass] - ----------------------------------------------------------------------------
==> /var/log/openhab2/events.log <==
2018-04-25 17:30:37.587 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:6140f4be' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
==> /var/log/openhab2/openhab.log <==
2018-04-25 17:30:42.827 [WARN ] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Unknown command class 0x91
2018-04-25 17:30:46.092 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery could not resolve to a thingType! 001D:1202:0243::0.2
2018-04-25 17:30:46.149 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:6140f4be:node3' to inbox.
==> /var/log/openhab2/events.log <==
2018-04-25 17:30:46.151 [home.event.InboxAddedEvent] - Discovery Result with UID 'zwave:device:6140f4be:node3' has been added.
==> /var/log/openhab2/openhab.log <==
2018-04-25 17:32:26.330 [WARN ] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Unsupported command class REMOTE_ASSOCIATION_ACTIVATE
2018-04-25 17:32:26.340 [WARN ] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Unknown command class 0x91
2018-04-25 17:32:26.486 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery could not resolve to a thingType! 001D:1202:0243::0.2
2018-04-25 17:32:26.501 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:6140f4be:node2' to inbox.
==> /var/log/openhab2/events.log <==
2018-04-25 17:32:26.501 [home.event.InboxAddedEvent] - Discovery Result with UID 'zwave:device:6140f4be:node2' has been added.
2018-04-25 17:33:40.521 [me.event.InboxRemovedEvent] - Discovery Result with UID 'zwave:device:6140f4be:node2' has been removed.
2018-04-25 17:33:40.594 [hingStatusInfoChangedEvent] - 'zwave:device:6140f4be:node2' changed from UNINITIALIZED to INITIALIZING
2018-04-25 17:33:40.604 [hingStatusInfoChangedEvent] - 'zwave:device:6140f4be:node2' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2018-04-25 17:33:40.619 [hingStatusInfoChangedEvent] - 'zwave:device:6140f4be:node2' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2018-04-25 17:33:40.627 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:6140f4be:node2' has been updated.
==> /var/log/openhab2/openhab.log <==
2018-04-25 17:35:01.475 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Stage VERSION. Initialisation retry timer triggered. Increased to 160000
2018-04-25 17:35:01.481 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - VERSION: queue length(0), free to send(false)
2018-04-25 17:35:01.485 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Initialisation retry timer started 160000
2018-04-25 17:35:01.489 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - VERSION try 5: stageAdvanced(false)
2018-04-25 17:35:01.500 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - thing is null!
2018-04-25 17:35:01.504 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking POWERLEVEL, version is 0
2018-04-25 17:35:01.508 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued POWERLEVEL
2018-04-25 17:35:01.511 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class POWERLEVEL
2018-04-25 17:35:01.516 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - queued packet. Queue length is 1
2018-04-25 17:35:01.522 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:35:01.522 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:35:01.527 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 86 13 73 25 3B 1F
2018-04-25 17:35:01.528 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking NO_OPERATION, version is 1
2018-04-25 17:35:01.530 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 86 13 73 25 3B 1F
2018-04-25 17:35:01.531 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking NODE_NAMING, version is 0
2018-04-25 17:35:01.535 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued NODE_NAMING
2018-04-25 17:35:01.540 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class NODE_NAMING
2018-04-25 17:35:01.544 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:35:01.546 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking BASIC, version is 0
2018-04-25 17:35:01.549 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued BASIC
2018-04-25 17:35:01.553 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class BASIC
2018-04-25 17:35:01.554 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:35:01.556 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking ASSOCIATION, version is 0
2018-04-25 17:35:01.558 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:35:01.561 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:35:01.563 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued ASSOCIATION
2018-04-25 17:35:01.564 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:35:01.567 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class ASSOCIATION
2018-04-25 17:35:01.568 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 3B 00 00 02 D2
2018-04-25 17:35:01.572 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data successfully placed on stack.
2018-04-25 17:35:01.570 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking HAIL, version is 0
2018-04-25 17:35:01.576 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued HAIL
2018-04-25 17:35:01.579 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:35:01.579 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class HAIL
2018-04-25 17:35:01.582 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking VERSION, version is 0
2018-04-25 17:35:01.586 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued VERSION
2018-04-25 17:35:01.588 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class VERSION
2018-04-25 17:35:01.590 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking MANUFACTURER_SPECIFIC, version is 0
2018-04-25 17:35:01.590 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 3B 00 00 02 00 00 DC
2018-04-25 17:35:01.592 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued MANUFACTURER_SPECIFIC
2018-04-25 17:35:01.593 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 3B 00 00 02 00 00 DC
2018-04-25 17:35:01.594 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class MANUFACTURER_SPECIFIC
2018-04-25 17:35:01.597 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking SCENE_CONTROLLER_CONF, version is 0
2018-04-25 17:35:01.605 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued SCENE_CONTROLLER_CONF
2018-04-25 17:35:01.607 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class SCENE_CONTROLLER_CONF
2018-04-25 17:35:01.609 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued 8 frames
2018-04-25 17:35:01.612 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=3B 00 00 02
2018-04-25 17:35:01.615 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 59, Status = Transmission complete and ACK received(0)
2018-04-25 17:35:01.618 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=2, callback=59, payload=02 03 86 13 73
2018-04-25 17:35:01.621 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=3B 00 00 02
2018-04-25 17:35:01.624 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=59, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:35:06.533 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 2 attempts left!
2018-04-25 17:35:06.538 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
2018-04-25 17:35:06.541 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:35:06.544 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:35:06.547 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 86 13 73 25 3C 18
2018-04-25 17:35:06.550 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 86 13 73 25 3C 18
2018-04-25 17:35:06.562 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:35:06.569 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:35:06.573 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:35:06.577 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:35:06.580 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:35:06.579 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 3C 00 00 02 D5
2018-04-25 17:35:06.587 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data successfully placed on stack.
2018-04-25 17:35:06.592 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:35:06.594 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 3C 00 00 02 00 00 DB
2018-04-25 17:35:06.599 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 3C 00 00 02 00 00 DB
2018-04-25 17:35:06.604 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=3C 00 00 02
2018-04-25 17:35:06.608 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 60, Status = Transmission complete and ACK received(0)
2018-04-25 17:35:06.610 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=2, callback=60, payload=02 03 86 13 73
2018-04-25 17:35:06.612 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=3C 00 00 02
2018-04-25 17:35:06.614 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=60, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:35:11.553 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 1 attempts left!
2018-04-25 17:35:11.556 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
2018-04-25 17:35:11.573 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:35:11.576 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:35:11.579 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 86 13 73 25 3D 19
2018-04-25 17:35:11.582 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 86 13 73 25 3D 19
2018-04-25 17:35:11.594 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:35:11.598 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:35:11.601 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:35:11.604 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:35:11.607 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:35:11.610 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data successfully placed on stack.
2018-04-25 17:35:11.612 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 3D 00 00 02 D4
2018-04-25 17:35:11.617 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:35:11.621 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 3D 00 00 02 00 00 DA
2018-04-25 17:35:11.624 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 3D 00 00 02 00 00 DA
2018-04-25 17:35:11.627 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=3D 00 00 02
2018-04-25 17:35:11.630 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 61, Status = Transmission complete and ACK received(0)
2018-04-25 17:35:11.637 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=2, callback=61, payload=02 03 86 13 73
2018-04-25 17:35:11.641 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=3D 00 00 02
2018-04-25 17:35:11.644 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=61, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:35:16.586 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 0 attempts left!
2018-04-25 17:35:16.589 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
2018-04-25 17:35:16.600 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:35:16.603 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:35:16.606 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 86 13 73 25 3E 1A
2018-04-25 17:35:16.610 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 86 13 73 25 3E 1A
2018-04-25 17:35:16.621 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:35:16.626 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:35:16.629 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:35:16.632 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:35:16.635 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:35:16.639 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data successfully placed on stack.
2018-04-25 17:35:16.640 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 3E 00 00 03 D6
2018-04-25 17:35:16.643 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:35:16.649 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 3E 00 00 03 00 00 D8
2018-04-25 17:35:16.654 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 3E 00 00 03 00 00 D8
2018-04-25 17:35:16.659 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=3E 00 00 03
2018-04-25 17:35:16.661 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 62, Status = Transmission complete and ACK received(0)
2018-04-25 17:35:16.665 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=2, callback=62, payload=02 03 86 13 73
2018-04-25 17:35:16.668 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=3E 00 00 03
2018-04-25 17:35:16.671 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=62, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:35:21.616 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=2, callback=62, payload=02 03 86 13 73
2018-04-25 17:35:57.956 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Stage VERSION. Initialisation retry timer triggered. Increased to 320000
2018-04-25 17:35:57.958 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer - VERSION: queue length(0), free to send(false)
2018-04-25 17:35:57.960 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Initialisation retry timer started 320000
2018-04-25 17:35:57.962 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: Retries exceeded at VERSION
2018-04-25 17:35:57.963 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Retry timout: Can't advance
==> /var/log/openhab2/events.log <==
2018-04-25 17:37:08.078 [me.event.InboxRemovedEvent] - Discovery Result with UID 'zwave:device:6140f4be:node3' has been removed.
==> /var/log/openhab2/openhab.log <==
2018-04-25 17:37:08.097 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=364, service.bundleid=229, service.scope=singleton} - org.openhab.binding.zwave
2018-04-25 17:37:08.116 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler.
==> /var/log/openhab2/events.log <==
2018-04-25 17:37:08.120 [hingStatusInfoChangedEvent] - 'zwave:device:6140f4be:node3' changed from UNINITIALIZED to INITIALIZING
2018-04-25 17:37:08.139 [hingStatusInfoChangedEvent] - 'zwave:device:6140f4be:node3' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
==> /var/log/openhab2/openhab.log <==
2018-04-25 17:37:08.147 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Controller status changed to ONLINE.
2018-04-25 17:37:08.150 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Controller is ONLINE. Starting device initialisation.
==> /var/log/openhab2/events.log <==
2018-04-25 17:37:08.164 [hingStatusInfoChangedEvent] - 'zwave:device:6140f4be:node3' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
==> /var/log/openhab2/openhab.log <==
2018-04-25 17:37:08.179 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Updating node properties.
==> /var/log/openhab2/events.log <==
2018-04-25 17:37:08.182 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:6140f4be:node3' has been updated.
==> /var/log/openhab2/openhab.log <==
2018-04-25 17:37:08.185 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Updating node properties. MAN=29
2018-04-25 17:37:08.188 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Updating node properties. MAN=29. SET. Was 29
2018-04-25 17:37:08.191 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Initialising Thing Node...
2018-04-25 17:37:08.194 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling intialised at 1800 seconds - start in 1800000 milliseconds.
2018-04-25 17:37:41.486 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Stage VERSION. Initialisation retry timer triggered. Increased to 320000
2018-04-25 17:37:41.488 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - VERSION: queue length(0), free to send(false)
2018-04-25 17:37:41.490 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Initialisation retry timer started 320000
2018-04-25 17:37:41.491 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: Retries exceeded at VERSION
2018-04-25 17:37:41.493 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Retry timout: Can't advance
2018-04-25 17:39:45.432 [ERROR] [e.internal.WriterInterceptorExecutor] - MessageBodyWriter not found for media type=text/plain, type=class java.util.Collections$UnmodifiableCollection, genericType=class java.util.Collections$UnmodifiableCollection.
2018-04-25 17:41:17.960 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Stage VERSION. Initialisation retry timer triggered. Increased to 640000
2018-04-25 17:41:17.965 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer - VERSION: queue length(0), free to send(true)
2018-04-25 17:41:17.968 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Initialisation retry timer started 640000
2018-04-25 17:41:17.970 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: loop - VERSION try 1: stageAdvanced(false)
2018-04-25 17:41:18.014 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - thing is null!
2018-04-25 17:41:18.016 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking SWITCH_BINARY, version is 0
2018-04-25 17:41:18.019 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued SWITCH_BINARY
2018-04-25 17:41:18.022 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class SWITCH_BINARY
2018-04-25 17:41:18.026 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer - queued packet. Queue length is 1
2018-04-25 17:41:18.029 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:41:18.029 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:41:18.032 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking POWERLEVEL, version is 0
2018-04-25 17:41:18.034 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued POWERLEVEL
2018-04-25 17:41:18.037 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class POWERLEVEL
2018-04-25 17:41:18.037 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 03 03 86 13 25 25 3F 4C
2018-04-25 17:41:18.041 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking NO_OPERATION, version is 1
2018-04-25 17:41:18.043 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0A 00 13 03 03 86 13 25 25 3F 4C
2018-04-25 17:41:18.043 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking NODE_NAMING, version is 0
2018-04-25 17:41:18.046 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued NODE_NAMING
2018-04-25 17:41:18.049 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class NODE_NAMING
2018-04-25 17:41:18.054 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking SCENE_ACTIVATION, version is 0
2018-04-25 17:41:18.056 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued SCENE_ACTIVATION
2018-04-25 17:41:18.055 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:41:18.061 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class SCENE_ACTIVATION
2018-04-25 17:41:18.062 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:41:18.064 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking SCENE_ACTUATOR_CONF, version is 0
2018-04-25 17:41:18.066 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:41:18.067 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued SCENE_ACTUATOR_CONF
2018-04-25 17:41:18.068 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:41:18.069 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class SCENE_ACTUATOR_CONF
2018-04-25 17:41:18.070 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:41:18.071 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: Sent Data successfully placed on stack.
2018-04-25 17:41:18.072 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking BASIC, version is 0
2018-04-25 17:41:18.072 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 3F 00 00 03 D7
2018-04-25 17:41:18.076 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued BASIC
2018-04-25 17:41:18.079 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class BASIC
2018-04-25 17:41:18.080 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:41:18.081 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking ASSOCIATION, version is 0
2018-04-25 17:41:18.082 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 3F 00 00 03 00 00 D9
2018-04-25 17:41:18.083 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued ASSOCIATION
2018-04-25 17:41:18.084 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 3F 00 00 03 00 00 D9
2018-04-25 17:41:18.086 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class ASSOCIATION
2018-04-25 17:41:18.087 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=3F 00 00 03
2018-04-25 17:41:18.088 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 63, Status = Transmission complete and ACK received(0)
2018-04-25 17:41:18.088 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking MANUFACTURER_SPECIFIC, version is 0
2018-04-25 17:41:18.093 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued MANUFACTURER_SPECIFIC
2018-04-25 17:41:18.093 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=3, callback=63, payload=03 03 86 13 25
2018-04-25 17:41:18.095 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class MANUFACTURER_SPECIFIC
2018-04-25 17:41:18.096 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=3F 00 00 03
2018-04-25 17:41:18.097 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=63, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:41:18.099 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking VERSION, version is 0
2018-04-25 17:41:18.101 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued VERSION
2018-04-25 17:41:18.104 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class VERSION
2018-04-25 17:41:18.106 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued 9 frames
2018-04-25 17:41:23.047 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Timeout while sending message. Requeueing - 2 attempts left!
2018-04-25 17:41:23.066 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: Got an error while sending data. Resending message.
2018-04-25 17:41:23.071 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:41:23.075 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:41:23.081 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 03 03 86 13 25 25 40 33
2018-04-25 17:41:23.085 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0A 00 13 03 03 86 13 25 25 40 33
2018-04-25 17:41:23.097 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:41:23.102 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:41:23.106 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:41:23.109 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:41:23.113 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:41:23.115 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 40 00 00 02 A9
2018-04-25 17:41:23.115 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: Sent Data successfully placed on stack.
2018-04-25 17:41:23.121 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:41:23.127 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 40 00 00 02 00 00 A7
2018-04-25 17:41:23.132 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 40 00 00 02 00 00 A7
2018-04-25 17:41:23.136 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=40 00 00 02
2018-04-25 17:41:23.139 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 64, Status = Transmission complete and ACK received(0)
2018-04-25 17:41:23.143 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=3, callback=64, payload=03 03 86 13 25
2018-04-25 17:41:23.147 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=40 00 00 02
2018-04-25 17:41:23.150 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=64, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:41:28.088 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Timeout while sending message. Requeueing - 1 attempts left!
2018-04-25 17:41:28.091 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: Got an error while sending data. Resending message.
2018-04-25 17:41:28.100 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:41:28.103 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:41:28.108 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 03 03 86 13 25 25 41 32
2018-04-25 17:41:28.113 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0A 00 13 03 03 86 13 25 25 41 32
2018-04-25 17:41:28.126 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:41:28.133 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:41:28.136 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:41:28.140 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:41:28.144 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:41:28.145 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 41 00 00 03 A9
2018-04-25 17:41:28.147 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: Sent Data successfully placed on stack.
2018-04-25 17:41:28.152 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:41:28.157 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 41 00 00 03 00 00 A7
2018-04-25 17:41:28.161 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 41 00 00 03 00 00 A7
2018-04-25 17:41:28.165 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=41 00 00 03
2018-04-25 17:41:28.168 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 65, Status = Transmission complete and ACK received(0)
2018-04-25 17:41:28.173 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=3, callback=65, payload=03 03 86 13 25
2018-04-25 17:41:28.177 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=41 00 00 03
2018-04-25 17:41:28.180 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=65, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:41:33.116 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Timeout while sending message. Requeueing - 0 attempts left!
2018-04-25 17:41:33.119 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: Got an error while sending data. Resending message.
2018-04-25 17:41:33.134 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:41:33.137 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:41:33.141 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 03 03 86 13 25 25 42 31
2018-04-25 17:41:33.145 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0A 00 13 03 03 86 13 25 25 42 31
2018-04-25 17:41:33.157 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:41:33.161 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:41:33.164 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:41:33.168 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:41:33.171 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:41:33.174 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: Sent Data successfully placed on stack.
2018-04-25 17:41:33.178 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 42 00 00 02 AB
2018-04-25 17:41:33.182 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:41:33.186 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 42 00 00 02 00 00 A5
2018-04-25 17:41:33.190 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 42 00 00 02 00 00 A5
2018-04-25 17:41:33.193 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=42 00 00 02
2018-04-25 17:41:33.196 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 66, Status = Transmission complete and ACK received(0)
2018-04-25 17:41:33.200 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=3, callback=66, payload=03 03 86 13 25
2018-04-25 17:41:33.203 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=42 00 00 02
2018-04-25 17:41:33.206 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=66, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:41:38.149 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=3, callback=66, payload=03 03 86 13 25
2018-04-25 17:43:01.491 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Stage VERSION. Initialisation retry timer triggered. Increased to 640000
2018-04-25 17:43:01.495 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - VERSION: queue length(0), free to send(true)
2018-04-25 17:43:01.498 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Initialisation retry timer started 640000
2018-04-25 17:43:01.501 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - VERSION try 1: stageAdvanced(false)
2018-04-25 17:43:01.537 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - thing is null!
2018-04-25 17:43:01.540 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking POWERLEVEL, version is 0
2018-04-25 17:43:01.543 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued POWERLEVEL
2018-04-25 17:43:01.546 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class POWERLEVEL
2018-04-25 17:43:01.549 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - queued packet. Queue length is 1
2018-04-25 17:43:01.552 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:43:01.555 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking NO_OPERATION, version is 1
2018-04-25 17:43:01.554 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:43:01.558 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking NODE_NAMING, version is 0
2018-04-25 17:43:01.560 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 86 13 73 25 43 67
2018-04-25 17:43:01.561 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued NODE_NAMING
2018-04-25 17:43:01.567 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 86 13 73 25 43 67
2018-04-25 17:43:01.567 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class NODE_NAMING
2018-04-25 17:43:01.573 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking BASIC, version is 0
2018-04-25 17:43:01.577 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued BASIC
2018-04-25 17:43:01.581 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:43:01.582 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class BASIC
2018-04-25 17:43:01.586 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking ASSOCIATION, version is 0
2018-04-25 17:43:01.586 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:43:01.591 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued ASSOCIATION
2018-04-25 17:43:01.591 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:43:01.596 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class ASSOCIATION
2018-04-25 17:43:01.598 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:43:01.601 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking HAIL, version is 0
2018-04-25 17:43:01.606 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued HAIL
2018-04-25 17:43:01.606 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:43:01.602 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 43 00 00 02 AA
2018-04-25 17:43:01.609 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class HAIL
2018-04-25 17:43:01.611 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data successfully placed on stack.
2018-04-25 17:43:01.613 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking VERSION, version is 0
2018-04-25 17:43:01.613 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:43:01.615 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued VERSION
2018-04-25 17:43:01.616 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 43 00 00 02 00 00 A4
2018-04-25 17:43:01.618 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class VERSION
2018-04-25 17:43:01.618 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 43 00 00 02 00 00 A4
2018-04-25 17:43:01.628 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=43 00 00 02
2018-04-25 17:43:01.629 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking MANUFACTURER_SPECIFIC, version is 0
2018-04-25 17:43:01.630 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 67, Status = Transmission complete and ACK received(0)
2018-04-25 17:43:01.632 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued MANUFACTURER_SPECIFIC
2018-04-25 17:43:01.633 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=2, callback=67, payload=02 03 86 13 73
2018-04-25 17:43:01.634 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class MANUFACTURER_SPECIFIC
2018-04-25 17:43:01.636 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=43 00 00 02
2018-04-25 17:43:01.637 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=67, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:43:01.637 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking SCENE_CONTROLLER_CONF, version is 0
2018-04-25 17:43:01.640 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued SCENE_CONTROLLER_CONF
2018-04-25 17:43:01.642 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class SCENE_CONTROLLER_CONF
2018-04-25 17:43:01.645 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued 8 frames
2018-04-25 17:43:06.572 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 2 attempts left!
2018-04-25 17:43:06.574 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
2018-04-25 17:43:06.577 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:43:06.580 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:43:06.584 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 86 13 73 25 44 60
2018-04-25 17:43:06.587 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 86 13 73 25 44 60
2018-04-25 17:43:06.600 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:43:06.605 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:43:06.610 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:43:06.616 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 44 00 00 02 AD
2018-04-25 17:43:06.617 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:43:06.622 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:43:06.625 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data successfully placed on stack.
2018-04-25 17:43:06.628 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:43:06.631 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 44 00 00 02 00 00 A3
2018-04-25 17:43:06.635 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 44 00 00 02 00 00 A3
2018-04-25 17:43:06.638 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=44 00 00 02
2018-04-25 17:43:06.641 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 68, Status = Transmission complete and ACK received(0)
2018-04-25 17:43:06.645 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=2, callback=68, payload=02 03 86 13 73
2018-04-25 17:43:06.649 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=44 00 00 02
2018-04-25 17:43:06.651 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=68, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:43:11.590 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 1 attempts left!
2018-04-25 17:43:11.593 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
2018-04-25 17:43:11.596 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:43:11.598 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:43:11.602 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 86 13 73 25 45 61
2018-04-25 17:43:11.606 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 86 13 73 25 45 61
2018-04-25 17:43:11.617 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:43:11.632 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:43:11.636 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 45 00 00 02 AC
2018-04-25 17:43:11.636 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:43:11.639 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:43:11.644 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:43:11.647 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data successfully placed on stack.
2018-04-25 17:43:11.651 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:43:11.655 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 45 00 00 02 00 00 A2
2018-04-25 17:43:11.660 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 45 00 00 02 00 00 A2
2018-04-25 17:43:11.664 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=45 00 00 02
2018-04-25 17:43:11.668 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 69, Status = Transmission complete and ACK received(0)
2018-04-25 17:43:11.673 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=2, callback=69, payload=02 03 86 13 73
2018-04-25 17:43:11.677 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=45 00 00 02
2018-04-25 17:43:11.681 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=69, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:43:16.609 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 0 attempts left!
2018-04-25 17:43:16.612 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
2018-04-25 17:43:16.615 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:43:16.617 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:43:16.621 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 86 13 73 25 46 62
2018-04-25 17:43:16.640 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 86 13 73 25 46 62
2018-04-25 17:43:16.652 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:43:16.656 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:43:16.660 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:43:16.664 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:43:16.669 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:43:16.669 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 46 00 00 02 AF
2018-04-25 17:43:16.673 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data successfully placed on stack.
2018-04-25 17:43:16.677 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:43:16.682 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 46 00 00 02 00 00 A1
2018-04-25 17:43:16.686 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 46 00 00 02 00 00 A1
2018-04-25 17:43:16.691 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=46 00 00 02
2018-04-25 17:43:16.694 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 70, Status = Transmission complete and ACK received(0)
2018-04-25 17:43:16.699 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=2, callback=70, payload=02 03 86 13 73
2018-04-25 17:43:16.704 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=46 00 00 02
2018-04-25 17:43:16.708 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=70, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:43:21.644 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=2, callback=70, payload=02 03 86 13 73
2018-04-25 17:45:56.233 [ERROR] [e.internal.WriterInterceptorExecutor] - MessageBodyWriter not found for media type=text/plain, type=class java.util.Collections$UnmodifiableCollection, genericType=class java.util.Collections$UnmodifiableCollection.
2018-04-25 17:49:52.594 [ERROR] [e.internal.WriterInterceptorExecutor] - MessageBodyWriter not found for media type=text/plain, type=class java.util.Collections$UnmodifiableCollection, genericType=class java.util.Collections$UnmodifiableCollection.
2018-04-25 17:51:57.968 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Stage VERSION. Initialisation retry timer triggered. Increased to 1280000
2018-04-25 17:51:57.974 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer - VERSION: queue length(0), free to send(false)
2018-04-25 17:51:57.978 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Initialisation retry timer started 1280000
2018-04-25 17:51:57.983 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: loop - VERSION try 2: stageAdvanced(false)
2018-04-25 17:51:58.001 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - thing is null!
2018-04-25 17:51:58.006 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking SWITCH_BINARY, version is 0
2018-04-25 17:51:58.010 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued SWITCH_BINARY
2018-04-25 17:51:58.015 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class SWITCH_BINARY
2018-04-25 17:51:58.020 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer - queued packet. Queue length is 1
2018-04-25 17:51:58.030 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:51:58.030 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:51:58.036 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking POWERLEVEL, version is 0
2018-04-25 17:51:58.037 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 03 03 86 13 25 25 47 34
2018-04-25 17:51:58.040 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued POWERLEVEL
2018-04-25 17:51:58.047 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0A 00 13 03 03 86 13 25 25 47 34
2018-04-25 17:51:58.047 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class POWERLEVEL
2018-04-25 17:51:58.052 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking NO_OPERATION, version is 1
2018-04-25 17:51:58.055 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking NODE_NAMING, version is 0
2018-04-25 17:51:58.059 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued NODE_NAMING
2018-04-25 17:51:58.062 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class NODE_NAMING
2018-04-25 17:51:58.062 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:51:58.066 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking SCENE_ACTIVATION, version is 0
2018-04-25 17:51:58.070 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:51:58.068 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued SCENE_ACTIVATION
2018-04-25 17:51:58.075 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:51:58.078 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 47 00 00 02 AE
2018-04-25 17:51:58.079 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:51:58.079 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class SCENE_ACTIVATION
2018-04-25 17:51:58.082 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:51:58.082 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking SCENE_ACTUATOR_CONF, version is 0
2018-04-25 17:51:58.085 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: Sent Data successfully placed on stack.
2018-04-25 17:51:58.088 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued SCENE_ACTUATOR_CONF
2018-04-25 17:51:58.090 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:51:58.091 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class SCENE_ACTUATOR_CONF
2018-04-25 17:51:58.094 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking BASIC, version is 0
2018-04-25 17:51:58.095 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 47 00 00 02 00 00 A0
2018-04-25 17:51:58.100 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued BASIC
2018-04-25 17:51:58.103 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class BASIC
2018-04-25 17:51:58.103 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 47 00 00 02 00 00 A0
2018-04-25 17:51:58.105 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking ASSOCIATION, version is 0
2018-04-25 17:51:58.106 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=47 00 00 02
2018-04-25 17:51:58.107 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued ASSOCIATION
2018-04-25 17:51:58.109 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 71, Status = Transmission complete and ACK received(0)
2018-04-25 17:51:58.109 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class ASSOCIATION
2018-04-25 17:51:58.112 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking MANUFACTURER_SPECIFIC, version is 0
2018-04-25 17:51:58.112 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=3, callback=71, payload=03 03 86 13 25
2018-04-25 17:51:58.114 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued MANUFACTURER_SPECIFIC
2018-04-25 17:51:58.116 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=47 00 00 02
2018-04-25 17:51:58.116 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class MANUFACTURER_SPECIFIC
2018-04-25 17:51:58.118 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=71, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:51:58.118 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - checking VERSION, version is 0
2018-04-25 17:51:58.120 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued VERSION
2018-04-25 17:51:58.122 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 3: Creating new message for application command VERSION_COMMAND_CLASS_GET command class VERSION
2018-04-25 17:51:58.124 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: VERSION - queued 9 frames
2018-04-25 17:52:03.051 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Timeout while sending message. Requeueing - 2 attempts left!
2018-04-25 17:52:03.241 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: Got an error while sending data. Resending message.
2018-04-25 17:52:03.246 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:52:03.250 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:52:03.256 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 03 03 86 13 25 25 48 3B
2018-04-25 17:52:03.261 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0A 00 13 03 03 86 13 25 25 48 3B
2018-04-25 17:52:03.274 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:52:03.282 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:52:03.286 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:52:03.290 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:52:03.292 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 48 00 00 02 A1
2018-04-25 17:52:03.293 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:52:03.295 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: Sent Data successfully placed on stack.
2018-04-25 17:52:03.298 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:52:03.303 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 48 00 00 02 00 00 AF
2018-04-25 17:52:03.307 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 48 00 00 02 00 00 AF
2018-04-25 17:52:03.313 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=48 00 00 02
2018-04-25 17:52:03.317 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 72, Status = Transmission complete and ACK received(0)
2018-04-25 17:52:03.327 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=3, callback=72, payload=03 03 86 13 25
2018-04-25 17:52:03.332 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=48 00 00 02
2018-04-25 17:52:03.336 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=72, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:52:08.266 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Timeout while sending message. Requeueing - 1 attempts left!
2018-04-25 17:52:08.269 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: Got an error while sending data. Resending message.
2018-04-25 17:52:08.364 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:52:08.367 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:52:08.371 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 03 03 86 13 25 25 49 3A
2018-04-25 17:52:08.375 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0A 00 13 03 03 86 13 25 25 49 3A
2018-04-25 17:52:08.388 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:52:08.394 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:52:08.398 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:52:08.402 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:52:08.405 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 49 00 00 03 A1
2018-04-25 17:52:08.406 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:52:08.410 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: Sent Data successfully placed on stack.
2018-04-25 17:52:08.415 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:52:08.420 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 49 00 00 03 00 00 AF
2018-04-25 17:52:08.424 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 49 00 00 03 00 00 AF
2018-04-25 17:52:08.428 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=49 00 00 03
2018-04-25 17:52:08.431 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 73, Status = Transmission complete and ACK received(0)
2018-04-25 17:52:08.436 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=3, callback=73, payload=03 03 86 13 25
2018-04-25 17:52:08.440 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=49 00 00 03
2018-04-25 17:52:08.443 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=73, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:52:13.379 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Timeout while sending message. Requeueing - 0 attempts left!
2018-04-25 17:52:13.381 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: Got an error while sending data. Resending message.
2018-04-25 17:52:13.477 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:52:13.479 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:52:13.483 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 03 03 86 13 25 25 4A 39
2018-04-25 17:52:13.489 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0A 00 13 03 03 86 13 25 25 4A 39
2018-04-25 17:52:13.503 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:52:13.508 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:52:13.512 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:52:13.517 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:52:13.520 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4A 00 00 02 A3
2018-04-25 17:52:13.523 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:52:13.527 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: Sent Data successfully placed on stack.
2018-04-25 17:52:13.530 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:52:13.535 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 4A 00 00 02 00 00 AD
2018-04-25 17:52:13.540 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 4A 00 00 02 00 00 AD
2018-04-25 17:52:13.544 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=4A 00 00 02
2018-04-25 17:52:13.548 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 74, Status = Transmission complete and ACK received(0)
2018-04-25 17:52:13.552 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=3, callback=74, payload=03 03 86 13 25
2018-04-25 17:52:13.557 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=4A 00 00 02
2018-04-25 17:52:13.561 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=74, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:52:18.494 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=3, callback=74, payload=03 03 86 13 25
2018-04-25 17:53:41.498 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Stage VERSION. Initialisation retry timer triggered. Increased to 1280000
2018-04-25 17:53:41.502 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - VERSION: queue length(0), free to send(false)
2018-04-25 17:53:41.504 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Initialisation retry timer started 1280000
2018-04-25 17:53:41.508 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: loop - VERSION try 2: stageAdvanced(false)
2018-04-25 17:53:41.525 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - thing is null!
2018-04-25 17:53:41.528 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking POWERLEVEL, version is 0
2018-04-25 17:53:41.531 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued POWERLEVEL
2018-04-25 17:53:41.534 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class POWERLEVEL
2018-04-25 17:53:41.538 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer - queued packet. Queue length is 1
2018-04-25 17:53:41.542 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 0. Queue={}
2018-04-25 17:53:41.542 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:53:41.547 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 86 13 73 25 4B 6F
2018-04-25 17:53:41.546 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking NO_OPERATION, version is 1
2018-04-25 17:53:41.550 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking NODE_NAMING, version is 0
2018-04-25 17:53:41.553 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued NODE_NAMING
2018-04-25 17:53:41.554 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 86 13 73 25 4B 6F
2018-04-25 17:53:41.557 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class NODE_NAMING
2018-04-25 17:53:41.561 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking BASIC, version is 0
2018-04-25 17:53:41.564 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued BASIC
2018-04-25 17:53:41.568 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class BASIC
2018-04-25 17:53:41.571 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:53:41.572 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking ASSOCIATION, version is 0
2018-04-25 17:53:41.577 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued ASSOCIATION
2018-04-25 17:53:41.581 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:53:41.580 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class ASSOCIATION
2018-04-25 17:53:41.589 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4B 00 00 02 A2
2018-04-25 17:53:41.594 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking HAIL, version is 0
2018-04-25 17:53:41.597 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued HAIL
2018-04-25 17:53:41.601 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:53:41.602 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class HAIL
2018-04-25 17:53:41.606 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking VERSION, version is 0
2018-04-25 17:53:41.606 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:53:41.609 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued VERSION
2018-04-25 17:53:41.611 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class VERSION
2018-04-25 17:53:41.611 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:53:41.613 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking MANUFACTURER_SPECIFIC, version is 0
2018-04-25 17:53:41.615 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued MANUFACTURER_SPECIFIC
2018-04-25 17:53:41.616 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data successfully placed on stack.
2018-04-25 17:53:41.617 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class MANUFACTURER_SPECIFIC
2018-04-25 17:53:41.619 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - checking SCENE_CONTROLLER_CONF, version is 0
2018-04-25 17:53:41.620 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:53:41.621 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued SCENE_CONTROLLER_CONF
2018-04-25 17:53:41.622 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 4B 00 00 02 00 00 AC
2018-04-25 17:53:41.623 [DEBUG] [ommandclass.ZWaveVersionCommandClass] - NODE 2: Creating new message for application command VERSION_COMMAND_CLASS_GET command class SCENE_CONTROLLER_CONF
2018-04-25 17:53:41.625 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: VERSION - queued 8 frames
2018-04-25 17:53:41.626 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 4B 00 00 02 00 00 AC
2018-04-25 17:53:41.629 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=4B 00 00 02
2018-04-25 17:53:41.631 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 75, Status = Transmission complete and ACK received(0)
2018-04-25 17:53:41.634 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=2, callback=75, payload=02 03 86 13 73
2018-04-25 17:53:41.637 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=4B 00 00 02
2018-04-25 17:53:41.639 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=75, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:53:46.562 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 2 attempts left!
2018-04-25 17:53:46.574 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
2018-04-25 17:53:46.577 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:53:46.581 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:53:46.586 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 86 13 73 25 4C 68
2018-04-25 17:53:46.591 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 86 13 73 25 4C 68
2018-04-25 17:53:46.603 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:53:46.607 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:53:46.611 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:53:46.614 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:53:46.619 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:53:46.622 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4C 00 00 02 A5
2018-04-25 17:53:46.628 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data successfully placed on stack.
2018-04-25 17:53:46.633 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:53:46.639 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 4C 00 00 02 00 00 AB
2018-04-25 17:53:46.645 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 4C 00 00 02 00 00 AB
2018-04-25 17:53:46.651 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=4C 00 00 02
2018-04-25 17:53:46.656 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 76, Status = Transmission complete and ACK received(0)
2018-04-25 17:53:46.662 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=2, callback=76, payload=02 03 86 13 73
2018-04-25 17:53:46.668 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=4C 00 00 02
2018-04-25 17:53:46.676 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=76, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:53:51.594 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 1 attempts left!
2018-04-25 17:53:51.611 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
2018-04-25 17:53:51.614 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:53:51.618 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:53:51.622 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 86 13 73 25 4D 69
2018-04-25 17:53:51.626 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 86 13 73 25 4D 69
2018-04-25 17:53:51.638 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:53:51.643 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:53:51.646 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:53:51.651 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:53:51.655 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:53:51.657 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4D 00 00 03 A5
2018-04-25 17:53:51.659 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data successfully placed on stack.
2018-04-25 17:53:51.663 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:53:51.668 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 4D 00 00 03 00 00 AB
2018-04-25 17:53:51.672 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 4D 00 00 03 00 00 AB
2018-04-25 17:53:51.676 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=4D 00 00 03
2018-04-25 17:53:51.679 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 77, Status = Transmission complete and ACK received(0)
2018-04-25 17:53:51.684 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=2, callback=77, payload=02 03 86 13 73
2018-04-25 17:53:51.688 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=4D 00 00 03
2018-04-25 17:53:51.691 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=77, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:53:56.630 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 0 attempts left!
2018-04-25 17:53:56.654 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
2018-04-25 17:53:56.658 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-04-25 17:53:56.661 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-04-25 17:53:56.666 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 86 13 73 25 4E 6A
2018-04-25 17:53:56.671 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 86 13 73 25 4E 6A
2018-04-25 17:53:56.686 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-04-25 17:53:56.690 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:53:56.694 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-04-25 17:53:56.698 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-04-25 17:53:56.701 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 4E 00 00 02 A7
2018-04-25 17:53:56.701 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-04-25 17:53:56.704 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data successfully placed on stack.
2018-04-25 17:53:56.708 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-04-25 17:53:56.713 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 4E 00 00 02 00 00 A9
2018-04-25 17:53:56.717 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 4E 00 00 02 00 00 A9
2018-04-25 17:53:56.722 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=4E 00 00 02
2018-04-25 17:53:56.725 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 78, Status = Transmission complete and ACK received(0)
2018-04-25 17:53:56.731 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=2, callback=78, payload=02 03 86 13 73
2018-04-25 17:53:56.735 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=4E 00 00 02
2018-04-25 17:53:56.738 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=78, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-04-25 17:54:01.675 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=2, callback=78, payload=02 03 86 13 73
2018-04-25 18:03:40.631 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling...
2018-04-25 18:03:40.634 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling deferred until initialisation complete
2018-04-25 18:07:08.194 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling...
2018-04-25 18:07:08.199 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling deferred until initialisation complete
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment