Skip to content

Instantly share code, notes, and snippets.

@BenWoodford

BenWoodford/gist:09943b42ca0ee9dec296f7617f638504

Created September 22, 2016 09:42
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 BenWoodford/09943b42ca0ee9dec296f7617f638504 to your computer and use it in GitHub Desktop.
Save BenWoodford/09943b42ca0ee9dec296f7617f638504 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
gistfile1.txt
2016-09-22 10:39:35.770 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Configuration update received
2016-09-22 10:39:35.798 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Configuration update action_reinit to -232323.0
2016-09-22 10:39:35.798 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Re-initialising node!
2016-09-22 10:39:35.810 [TRACE] [l.initialization.ZWaveNodeSerializer] - Initializing ZWaveNodeSerializer.
2016-09-22 10:39:35.819 [TRACE] [l.initialization.ZWaveNodeSerializer] - Initialized ZWaveNodeSerializer.
2016-09-22 10:39:35.820 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
2016-09-22 10:39:35.820 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2016-09-22 10:39:35.835 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 10: Init node thread start
2016-09-22 10:39:35.846 [TRACE] [l.initialization.ZWaveNodeSerializer] - Initializing ZWaveNodeSerializer.
2016-09-22 10:39:35.856 [TRACE] [l.initialization.ZWaveNodeSerializer] - Initialized ZWaveNodeSerializer.
2016-09-22 10:39:35.857 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 10: Serializing from file /var/lib/openhab2/zwave/node10.xml
2016-09-22 10:39:35.857 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 10: Error serializing from file: file does not exist.
2016-09-22 10:39:35.861 [TRACE] [e.internal.protocol.ZWaveDeviceClass] - Constructing Zwave Device Class
2016-09-22 10:39:35.862 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Starting initialisation from EMPTYNODE
2016-09-22 10:39:35.862 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - EMPTYNODE: queue length(0), free to send(true)
2016-09-22 10:39:35.862 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: loop - EMPTYNODE try 1: stageAdvanced(false)
2016-09-22 10:39:35.862 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: Initialisation starting
2016-09-22 10:39:35.863 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - advancing to PROTOINFO
2016-09-22 10:39:35.863 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
2016-09-22 10:39:35.863 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2016-09-22 10:39:35.909 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: loop - PROTOINFO try 0: stageAdvanced(true)
2016-09-22 10:39:35.910 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: PROTOINFO - send IdentifyNode
2016-09-22 10:39:35.910 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating empty message of class = IdentifyNode (0x41), type = Request (0x00)
2016-09-22 10:39:35.910 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - queued packet. Queue length is 1
2016-09-22 10:39:35.910 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 5. Queue={}
2016-09-22 10:39:35.910 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 10: Init node thread finished
2016-09-22 10:39:37.052 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 12: Timeout while sending message. Requeueing - 0 attempts left!
2016-09-22 10:39:37.052 [TRACE] [l.serialmessage.SendDataMessageClass] - NODE 12: Handling failed message.
2016-09-22 10:39:37.053 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 12: Got an error while sending data. Resending message.
2016-09-22 10:39:37.053 [TRACE] [ve.internal.protocol.ZWaveController] - Callback ID = 15
2016-09-22 10:39:37.053 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 6. Queue={}
2016-09-22 10:39:37.053 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 5
2016-09-22 10:39:37.054 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xB0
2016-09-22 10:39:37.054 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 0A B0
2016-09-22 10:39:37.054 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 0A B0
2016-09-22 10:39:37.055 [TRACE] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2016-09-22 10:39:37.056 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received ACK
2016-09-22 10:39:37.057 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2016-09-22 10:39:37.058 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 53 9C 00 04 20 01 5C
2016-09-22 10:39:37.058 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 09 01 41 53 9C 00 04 20 01 5C
2016-09-22 10:39:37.059 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0x5C
2016-09-22 10:39:37.059 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2016-09-22 10:39:37.060 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Message payload = 53 9C 00 04 20 01
2016-09-22 10:39:37.060 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2016-09-22 10:39:37.061 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT
2016-09-22 10:39:37.061 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-09-22 10:39:37.062 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0x5C
2016-09-22 10:39:37.062 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 01 41 53 9C 00 04 20 01 5C
2016-09-22 10:39:37.063 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 01 41 53 9C 00 04 20 01 5C
2016-09-22 10:39:37.063 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=IdentifyNode[0x41], type=Response[0x01], priority=High, dest=255, callback=0, payload=53 9C 00 04 20 01
2016-09-22 10:39:37.064 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE
2016-09-22 10:39:37.064 [TRACE] [rialmessage.IdentifyNodeMessageClass] - Handle Message Get Node ProtocolInfo Response
2016-09-22 10:39:37.064 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: ProtocolInfo
2016-09-22 10:39:37.065 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Listening = false
2016-09-22 10:39:37.065 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Routing = true
2016-09-22 10:39:37.065 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Beaming = true
2016-09-22 10:39:37.066 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Version = 4
2016-09-22 10:39:37.066 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: FLIRS = false
2016-09-22 10:39:37.066 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Security = false
2016-09-22 10:39:37.067 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Max Baud = 40000
2016-09-22 10:39:37.067 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Basic = Routing Slave
2016-09-22 10:39:37.067 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Generic = Binary Sensor
2016-09-22 10:39:37.068 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 10: Specific = Routing Binary Sensor
2016-09-22 10:39:37.068 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Creating new instance of command class NO_OPERATION
2016-09-22 10:39:37.069 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class NO_OPERATION, endpoint null created
2016-09-22 10:39:37.069 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Version = 1, version set. Enabling extra functionality.
2016-09-22 10:39:37.070 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Adding command class NO_OPERATION to the list of supported command classes.
2016-09-22 10:39:37.070 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Creating new instance of command class BASIC
2016-09-22 10:39:37.070 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class BASIC, endpoint null created
2016-09-22 10:39:37.071 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Adding command class BASIC to the list of supported command classes.
2016-09-22 10:39:37.071 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Creating new instance of command class SENSOR_BINARY
2016-09-22 10:39:37.071 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class SENSOR_BINARY, endpoint null created
2016-09-22 10:39:37.072 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Adding command class SENSOR_BINARY to the list of supported command classes.
2016-09-22 10:39:37.072 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IdentifyNode[0x41], type=Request[0x00], priority=High, dest=255, callback=0, payload=0A
2016-09-22 10:39:37.073 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=IdentifyNode[0x41], type=Response[0x01], priority=High, dest=255, callback=0, payload=53 9C 00 04 20 01
2016-09-22 10:39:37.073 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=IdentifyNode, callback id=0, expected=IdentifyNode, cancelled=false transaction complete!
2016-09-22 10:39:37.074 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2016-09-22 10:39:37.074 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - PING: Transaction complete (IdentifyNode:Request) success(true)
2016-09-22 10:39:37.075 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - checking initialisation queue. Queue size 1.
2016-09-22 10:39:37.075 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - PROTOINFO: Transaction complete (IdentifyNode:Request) success(true)
2016-09-22 10:39:37.076 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - checking initialisation queue. Queue size 1.
2016-09-22 10:39:37.076 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - message removed from queue. Queue size 0.
2016-09-22 10:39:37.077 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - PROTOINFO: queue length(0), free to send(true)
2016-09-22 10:39:37.089 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: loop - PROTOINFO try 1: stageAdvanced(false)
2016-09-22 10:39:37.089 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - advancing to INIT_NEIGHBORS
2016-09-22 10:39:37.090 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
2016-09-22 10:39:37.090 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2016-09-22 10:39:37.091 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: loop - INIT_NEIGHBORS try 0: stageAdvanced(true)
2016-09-22 10:39:37.091 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: INIT_NEIGHBORS - send RoutingInfo
2016-09-22 10:39:37.091 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 10: Request routing info
2016-09-22 10:39:37.092 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating empty message of class = GetRoutingInfo (0x80), type = Request (0x00)
2016-09-22 10:39:37.092 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - queued packet. Queue length is 1
2016-09-22 10:39:37.092 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 6. Queue={}
2016-09-22 10:39:37.092 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 37ms/85ms.
2016-09-22 10:39:37.093 [TRACE] [ocol.ZWaveController$ZWaveSendThread] - Acquired. Transaction completed permit count -> 0
2016-09-22 10:39:37.093 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 5
2016-09-22 10:39:37.094 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0x71
2016-09-22 10:39:37.094 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 80 0A 00 00 03 71
2016-09-22 10:39:37.094 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 07 00 80 0A 00 00 03 71
2016-09-22 10:39:37.095 [TRACE] [ve.internal.protocol.ZWaveController] - Released. Transaction completed permit count -> 0
2016-09-22 10:39:37.095 [TRACE] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2016-09-22 10:39:37.096 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received ACK
2016-09-22 10:39:37.100 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2016-09-22 10:39:37.101 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 20 01 80 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 5E
2016-09-22 10:39:37.102 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 20 01 80 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 5E
2016-09-22 10:39:37.102 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0x5E
2016-09-22 10:39:37.103 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2016-09-22 10:39:37.103 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Message payload = 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2016-09-22 10:39:37.103 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2016-09-22 10:39:37.104 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT
2016-09-22 10:39:37.104 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-09-22 10:39:37.105 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0x5E
2016-09-22 10:39:37.106 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 20 01 80 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 5E
2016-09-22 10:39:37.107 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 20 01 80 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 5E
2016-09-22 10:39:37.108 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=GetRoutingInfo[0x80], type=Response[0x01], priority=High, dest=255, callback=0, payload=00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2016-09-22 10:39:37.109 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE
2016-09-22 10:39:37.110 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 10: Got NodeRoutingInfo request.
2016-09-22 10:39:37.110 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 10: No neighbors reported
2016-09-22 10:39:37.111 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNetworkEvent
2016-09-22 10:39:37.111 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveNetworkEvent
2016-09-22 10:39:37.112 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=GetRoutingInfo[0x80], type=Request[0x00], priority=High, dest=255, callback=0, payload=0A 00 00 03
2016-09-22 10:39:37.113 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=GetRoutingInfo[0x80], type=Response[0x01], priority=High, dest=255, callback=0, payload=00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2016-09-22 10:39:37.114 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=GetRoutingInfo, callback id=0, expected=GetRoutingInfo, cancelled=false transaction complete!
2016-09-22 10:39:37.114 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2016-09-22 10:39:37.114 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - PING: Transaction complete (GetRoutingInfo:Request) success(true)
2016-09-22 10:39:37.115 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - checking initialisation queue. Queue size 1.
2016-09-22 10:39:37.115 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - INIT_NEIGHBORS: Transaction complete (GetRoutingInfo:Request) success(true)
2016-09-22 10:39:37.116 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - checking initialisation queue. Queue size 1.
2016-09-22 10:39:37.116 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - message removed from queue. Queue size 0.
2016-09-22 10:39:37.117 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - INIT_NEIGHBORS: queue length(0), free to send(true)
2016-09-22 10:39:37.117 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: loop - INIT_NEIGHBORS try 1: stageAdvanced(false)
2016-09-22 10:39:37.118 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - advancing to FAILED_CHECK
2016-09-22 10:39:37.119 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
2016-09-22 10:39:37.119 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2016-09-22 10:39:37.120 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: loop - FAILED_CHECK try 0: stageAdvanced(true)
2016-09-22 10:39:37.121 [DEBUG] [rialmessage.IsFailedNodeMessageClass] - NODE 10: Requesting IsFailedNode status from controller.
2016-09-22 10:39:37.123 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating empty message of class = IsFailedNodeID (0x62), type = Request (0x00)
2016-09-22 10:39:37.123 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - queued packet. Queue length is 1
2016-09-22 10:39:37.124 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 6. Queue={}
2016-09-22 10:39:37.125 [TRACE] [ve.internal.protocol.ZWaveController] - Released. Transaction completed permit count -> 1
2016-09-22 10:39:37.125 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 30ms/85ms.
2016-09-22 10:39:37.125 [TRACE] [ocol.ZWaveController$ZWaveSendThread] - Acquired. Transaction completed permit count -> 0
2016-09-22 10:39:37.126 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 5
2016-09-22 10:39:37.126 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0x93
2016-09-22 10:39:37.126 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 62 0A 93
2016-09-22 10:39:37.127 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 62 0A 93
2016-09-22 10:39:37.128 [TRACE] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2016-09-22 10:39:37.130 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received ACK
2016-09-22 10:39:37.130 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2016-09-22 10:39:37.131 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 62 00 98
2016-09-22 10:39:37.132 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 04 01 62 00 98
2016-09-22 10:39:37.133 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0x98
2016-09-22 10:39:37.134 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2016-09-22 10:39:37.134 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Message payload = 00
2016-09-22 10:39:37.135 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2016-09-22 10:39:37.145 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT
2016-09-22 10:39:37.146 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-09-22 10:39:37.147 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0x98
2016-09-22 10:39:37.147 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 62 00 98
2016-09-22 10:39:37.148 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 62 00 98
2016-09-22 10:39:37.148 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=IsFailedNodeID[0x62], type=Response[0x01], priority=High, dest=255, callback=0, payload=00
2016-09-22 10:39:37.149 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE
2016-09-22 10:39:37.149 [DEBUG] [rialmessage.IsFailedNodeMessageClass] - NODE 10: Is currently marked as healthy by the controller
2016-09-22 10:39:37.150 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IsFailedNodeID[0x62], type=Request[0x00], priority=High, dest=255, callback=0, payload=0A
2016-09-22 10:39:37.150 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=IsFailedNodeID[0x62], type=Response[0x01], priority=High, dest=255, callback=0, payload=00
2016-09-22 10:39:37.151 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=IsFailedNodeID, callback id=0, expected=IsFailedNodeID, cancelled=false transaction complete!
2016-09-22 10:39:37.151 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2016-09-22 10:39:37.152 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - PING: Transaction complete (IsFailedNodeID:Request) success(true)
2016-09-22 10:39:37.152 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - checking initialisation queue. Queue size 1.
2016-09-22 10:39:37.152 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - FAILED_CHECK: Transaction complete (IsFailedNodeID:Request) success(true)
2016-09-22 10:39:37.153 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - checking initialisation queue. Queue size 1.
2016-09-22 10:39:37.153 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - message removed from queue. Queue size 0.
2016-09-22 10:39:37.154 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - FAILED_CHECK: queue length(0), free to send(true)
2016-09-22 10:39:37.154 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: loop - FAILED_CHECK try 1: stageAdvanced(false)
2016-09-22 10:39:37.155 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - advancing to WAIT
2016-09-22 10:39:37.155 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
2016-09-22 10:39:37.156 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2016-09-22 10:39:37.157 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: loop - WAIT try 0: stageAdvanced(true)
2016-09-22 10:39:37.158 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: WAIT - Listening=false, FrequentlyListening=false
2016-09-22 10:39:37.159 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: WAIT - Still waiting!
2016-09-22 10:39:37.159 [TRACE] [ve.internal.protocol.ZWaveController] - Released. Transaction completed permit count -> 1
2016-09-22 10:39:37.159 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 31ms/85ms.
2016-09-22 10:39:37.160 [TRACE] [ocol.ZWaveController$ZWaveSendThread] - Acquired. Transaction completed permit count -> 0
2016-09-22 10:39:37.160 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 4
2016-09-22 10:39:37.160 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xB4
2016-09-22 10:39:37.161 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 0C 03 70 05 02 25 0F B4
2016-09-22 10:39:37.161 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 12: Sending REQUEST Message = 01 0A 00 13 0C 03 70 05 02 25 0F B4
2016-09-22 10:39:37.162 [TRACE] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2016-09-22 10:39:37.164 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received ACK
2016-09-22 10:39:37.166 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2016-09-22 10:39:37.167 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2016-09-22 10:39:37.167 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 04 01 13 01 E8
2016-09-22 10:39:37.168 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
2016-09-22 10:39:37.168 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2016-09-22 10:39:37.169 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Message payload = 01
2016-09-22 10:39:37.169 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2016-09-22 10:39:37.169 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT
2016-09-22 10:39:37.170 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-09-22 10:39:37.170 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
2016-09-22 10:39:37.171 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2016-09-22 10:39:37.171 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2016-09-22 10:39:37.172 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2016-09-22 10:39:37.172 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE
2016-09-22 10:39:37.172 [TRACE] [l.serialmessage.SendDataMessageClass] - Handle Message Send Data Response
2016-09-22 10:39:37.173 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: Sent Data successfully placed on stack.
2016-09-22 10:39:37.173 [TRACE] [wave.internal.protocol.SerialMessage] - Ack Pending cleared
2016-09-22 10:39:37.182 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2016-09-22 10:39:37.183 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 0F 00 E6
2016-09-22 10:39:37.184 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 05 00 13 0F 00 E6
2016-09-22 10:39:37.184 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xE6
2016-09-22 10:39:37.185 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2016-09-22 10:39:37.185 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Message payload = 0F 00
2016-09-22 10:39:37.186 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2016-09-22 10:39:37.186 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT
2016-09-22 10:39:37.187 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-09-22 10:39:37.187 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xE4
2016-09-22 10:39:37.187 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 13 0F 00 00 00 E4
2016-09-22 10:39:37.188 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 13 0F 00 00 00 E4
2016-09-22 10:39:37.188 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=0F 00
2016-09-22 10:39:37.189 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
2016-09-22 10:39:37.189 [TRACE] [l.serialmessage.SendDataMessageClass] - Handle Message Send Data Request
2016-09-22 10:39:37.189 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: SendData Request. CallBack ID = 15, Status = Transmission complete and ACK received(0)
2016-09-22 10:39:37.190 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=12, callback=15, payload=0C 03 70 05 02
2016-09-22 10:39:37.191 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=0F 00
2016-09-22 10:39:37.191 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=15, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2016-09-22 10:39:41.988 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Stage GET_CONFIGURATION. Initialisation retry timer triggered. Increased to 40000
2016-09-22 10:39:41.988 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - GET_CONFIGURATION: queue length(0), free to send(false)
2016-09-22 10:39:41.989 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Initialisation retry timer started 40000
2016-09-22 10:39:41.989 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: loop - GET_CONFIGURATION try 3: stageAdvanced(false)
2016-09-22 10:39:42.002 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_2_2 - config
2016-09-22 10:39:42.002 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_2_2 - index 2
2016-09-22 10:39:42.002 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 12: Creating new message for application command CONFIGURATIONCMD_GET
2016-09-22 10:39:42.003 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 12: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-09-22 10:39:42.003 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - queued packet. Queue length is 1
2016-09-22 10:39:42.003 [TRACE] [ve.internal.protocol.ZWaveController] - Callback ID = 16
2016-09-22 10:39:42.004 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 5. Queue={}
2016-09-22 10:39:42.004 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_3_1 - config
2016-09-22 10:39:42.004 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_3_1 - index 3
2016-09-22 10:39:42.004 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 12: Creating new message for application command CONFIGURATIONCMD_GET
2016-09-22 10:39:42.004 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 12: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-09-22 10:39:42.005 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_20_1 - config
2016-09-22 10:39:42.005 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_20_1 - index 20
2016-09-22 10:39:42.005 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 12: Creating new message for application command CONFIGURATIONCMD_GET
2016-09-22 10:39:42.005 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 12: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-09-22 10:39:42.006 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_80_1 - config
2016-09-22 10:39:42.006 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_80_1 - index 80
2016-09-22 10:39:42.006 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 12: Creating new message for application command CONFIGURATIONCMD_GET
2016-09-22 10:39:42.006 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 12: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-09-22 10:39:42.006 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_81_1 - config
2016-09-22 10:39:42.007 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_81_1 - index 81
2016-09-22 10:39:42.007 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 12: Creating new message for application command CONFIGURATIONCMD_GET
2016-09-22 10:39:42.007 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 12: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-09-22 10:39:42.007 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_90_1 - config
2016-09-22 10:39:42.008 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_90_1 - index 90
2016-09-22 10:39:42.008 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 12: Creating new message for application command CONFIGURATIONCMD_GET
2016-09-22 10:39:42.008 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 12: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-09-22 10:39:42.008 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_91_2 - config
2016-09-22 10:39:42.009 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_91_2 - index 91
2016-09-22 10:39:42.009 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_92_1 - config
2016-09-22 10:39:42.009 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_92_1 - index 92
2016-09-22 10:39:42.009 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 12: Creating new message for application command CONFIGURATIONCMD_GET
2016-09-22 10:39:42.009 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 12: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-09-22 10:39:42.010 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_100_1 - config
2016-09-22 10:39:42.010 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_100_1 - index 100
2016-09-22 10:39:42.010 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 12: Creating new message for application command CONFIGURATIONCMD_GET
2016-09-22 10:39:42.010 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 12: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-09-22 10:39:42.011 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_101_4 - config
2016-09-22 10:39:42.011 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_101_4 - index 101
2016-09-22 10:39:42.011 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 12: Creating new message for application command CONFIGURATIONCMD_GET
2016-09-22 10:39:42.011 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 12: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-09-22 10:39:42.011 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_102_4 - config
2016-09-22 10:39:42.012 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_102_4 - index 102
2016-09-22 10:39:42.012 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 12: Creating new message for application command CONFIGURATIONCMD_GET
2016-09-22 10:39:42.012 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 12: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-09-22 10:39:42.012 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_103_4 - config
2016-09-22 10:39:42.013 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_103_4 - index 103
2016-09-22 10:39:42.013 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 12: Creating new message for application command CONFIGURATIONCMD_GET
2016-09-22 10:39:42.013 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 12: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-09-22 10:39:42.013 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_111_4 - config
2016-09-22 10:39:42.013 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_111_4 - index 111
2016-09-22 10:39:42.014 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 12: Creating new message for application command CONFIGURATIONCMD_GET
2016-09-22 10:39:42.014 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 12: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-09-22 10:39:42.014 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_112_4 - config
2016-09-22 10:39:42.014 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_112_4 - index 112
2016-09-22 10:39:42.014 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 12: Creating new message for application command CONFIGURATIONCMD_GET
2016-09-22 10:39:42.015 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 12: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-09-22 10:39:42.015 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_113_4 - config
2016-09-22 10:39:42.015 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_113_4 - index 113
2016-09-22 10:39:42.016 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 12: Creating new message for application command CONFIGURATIONCMD_GET
2016-09-22 10:39:42.016 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 12: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-09-22 10:39:42.016 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_252_1 - config
2016-09-22 10:39:42.016 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer: GET_CONFIGURATION - checking config_252_1 - index 252
2016-09-22 10:39:42.017 [DEBUG] [class.ZWaveConfigurationCommandClass] - NODE 12: Creating new message for application command CONFIGURATIONCMD_GET
2016-09-22 10:39:42.017 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 12: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-09-22 10:39:42.163 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 12: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=12, callback=15, payload=0C 03 70 05 02
2016-09-22 10:39:42.163 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 4
2016-09-22 10:39:42.164 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xB7
2016-09-22 10:39:42.164 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 0C 03 70 05 02 25 0C B7
2016-09-22 10:39:42.164 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 12: Sending REQUEST Message = 01 0A 00 13 0C 03 70 05 02 25 0C B7
2016-09-22 10:39:42.165 [TRACE] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2016-09-22 10:39:42.167 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received ACK
2016-09-22 10:39:42.169 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2016-09-22 10:39:42.170 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2016-09-22 10:39:42.170 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 04 01 13 01 E8
2016-09-22 10:39:42.171 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
2016-09-22 10:39:42.171 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2016-09-22 10:39:42.171 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Message payload = 01
2016-09-22 10:39:42.171 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2016-09-22 10:39:42.172 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT
2016-09-22 10:39:42.172 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-09-22 10:39:42.173 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
2016-09-22 10:39:42.173 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2016-09-22 10:39:42.173 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2016-09-22 10:39:42.174 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2016-09-22 10:39:42.174 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE
2016-09-22 10:39:42.174 [TRACE] [l.serialmessage.SendDataMessageClass] - Handle Message Send Data Response
2016-09-22 10:39:42.174 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: Sent Data successfully placed on stack.
2016-09-22 10:39:42.174 [TRACE] [wave.internal.protocol.SerialMessage] - Ack Pending cleared
2016-09-22 10:39:42.185 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2016-09-22 10:39:42.185 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 0C 00 E5
2016-09-22 10:39:42.186 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 05 00 13 0C 00 E5
2016-09-22 10:39:42.186 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xE5
2016-09-22 10:39:42.186 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2016-09-22 10:39:42.186 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Message payload = 0C 00
2016-09-22 10:39:42.186 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2016-09-22 10:39:42.187 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT
2016-09-22 10:39:42.187 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-09-22 10:39:42.187 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xE7
2016-09-22 10:39:42.188 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 13 0C 00 00 00 E7
2016-09-22 10:39:42.188 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 13 0C 00 00 00 E7
2016-09-22 10:39:42.188 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=0C 00
2016-09-22 10:39:42.189 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
2016-09-22 10:39:42.189 [TRACE] [l.serialmessage.SendDataMessageClass] - Handle Message Send Data Request
2016-09-22 10:39:42.189 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: SendData Request. CallBack ID = 12, Status = Transmission complete and ACK received(0)
2016-09-22 10:39:42.189 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=12, callback=12, payload=0C 03 70 05 02
2016-09-22 10:39:42.190 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=0C 00
2016-09-22 10:39:42.190 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=12, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2016-09-22 10:39:47.165 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 12: Timeout while sending message. Requeueing - 2 attempts left!
2016-09-22 10:39:47.166 [TRACE] [l.serialmessage.SendDataMessageClass] - NODE 12: Handling failed message.
2016-09-22 10:39:47.166 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 12: Got an error while sending data. Resending message.
2016-09-22 10:39:47.167 [TRACE] [ve.internal.protocol.ZWaveController] - Callback ID = 17
2016-09-22 10:39:47.167 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 5. Queue={}
2016-09-22 10:39:47.168 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 4
2016-09-22 10:39:47.168 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xAA
2016-09-22 10:39:47.169 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 0C 03 70 05 02 25 11 AA
2016-09-22 10:39:47.169 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 12: Sending REQUEST Message = 01 0A 00 13 0C 03 70 05 02 25 11 AA
2016-09-22 10:39:47.170 [TRACE] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2016-09-22 10:39:47.172 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received ACK
2016-09-22 10:39:47.175 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2016-09-22 10:39:47.176 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2016-09-22 10:39:47.176 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 04 01 13 01 E8
2016-09-22 10:39:47.176 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
2016-09-22 10:39:47.176 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2016-09-22 10:39:47.177 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Message payload = 01
2016-09-22 10:39:47.177 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2016-09-22 10:39:47.186 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT
2016-09-22 10:39:47.187 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-09-22 10:39:47.187 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
2016-09-22 10:39:47.187 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2016-09-22 10:39:47.188 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2016-09-22 10:39:47.188 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2016-09-22 10:39:47.188 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE
2016-09-22 10:39:47.188 [TRACE] [l.serialmessage.SendDataMessageClass] - Handle Message Send Data Response
2016-09-22 10:39:47.188 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: Sent Data successfully placed on stack.
2016-09-22 10:39:47.188 [TRACE] [wave.internal.protocol.SerialMessage] - Ack Pending cleared
2016-09-22 10:39:47.190 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2016-09-22 10:39:47.191 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 11 00 F8
2016-09-22 10:39:47.192 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 05 00 13 11 00 F8
2016-09-22 10:39:47.192 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xF8
2016-09-22 10:39:47.192 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2016-09-22 10:39:47.193 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Message payload = 11 00
2016-09-22 10:39:47.193 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2016-09-22 10:39:47.193 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT
2016-09-22 10:39:47.194 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-09-22 10:39:47.194 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xFA
2016-09-22 10:39:47.194 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 13 11 00 00 00 FA
2016-09-22 10:39:47.195 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 13 11 00 00 00 FA
2016-09-22 10:39:47.195 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=11 00
2016-09-22 10:39:47.195 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
2016-09-22 10:39:47.195 [TRACE] [l.serialmessage.SendDataMessageClass] - Handle Message Send Data Request
2016-09-22 10:39:47.196 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: SendData Request. CallBack ID = 17, Status = Transmission complete and ACK received(0)
2016-09-22 10:39:47.196 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=12, callback=17, payload=0C 03 70 05 02
2016-09-22 10:39:47.196 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=11 00
2016-09-22 10:39:47.197 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=17, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2016-09-22 10:39:52.171 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 12: Timeout while sending message. Requeueing - 1 attempts left!
2016-09-22 10:39:52.171 [TRACE] [l.serialmessage.SendDataMessageClass] - NODE 12: Handling failed message.
2016-09-22 10:39:52.171 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 12: Got an error while sending data. Resending message.
2016-09-22 10:39:52.171 [TRACE] [ve.internal.protocol.ZWaveController] - Callback ID = 18
2016-09-22 10:39:52.172 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 5. Queue={}
2016-09-22 10:39:52.172 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 4
2016-09-22 10:39:52.172 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xA9
2016-09-22 10:39:52.173 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 0C 03 70 05 02 25 12 A9
2016-09-22 10:39:52.173 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 12: Sending REQUEST Message = 01 0A 00 13 0C 03 70 05 02 25 12 A9
2016-09-22 10:39:52.173 [TRACE] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2016-09-22 10:39:52.175 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received ACK
2016-09-22 10:39:52.178 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2016-09-22 10:39:52.179 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2016-09-22 10:39:52.179 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 04 01 13 01 E8
2016-09-22 10:39:52.179 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
2016-09-22 10:39:52.180 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2016-09-22 10:39:52.180 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Message payload = 01
2016-09-22 10:39:52.180 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2016-09-22 10:39:52.180 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT
2016-09-22 10:39:52.180 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-09-22 10:39:52.181 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
2016-09-22 10:39:52.181 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2016-09-22 10:39:52.182 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2016-09-22 10:39:52.182 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2016-09-22 10:39:52.182 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE
2016-09-22 10:39:52.182 [TRACE] [l.serialmessage.SendDataMessageClass] - Handle Message Send Data Response
2016-09-22 10:39:52.183 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: Sent Data successfully placed on stack.
2016-09-22 10:39:52.183 [TRACE] [wave.internal.protocol.SerialMessage] - Ack Pending cleared
2016-09-22 10:39:52.195 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2016-09-22 10:39:52.195 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 12 00 FB
2016-09-22 10:39:52.196 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 05 00 13 12 00 FB
2016-09-22 10:39:52.196 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xFB
2016-09-22 10:39:52.196 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2016-09-22 10:39:52.196 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Message payload = 12 00
2016-09-22 10:39:52.196 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2016-09-22 10:39:52.197 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT
2016-09-22 10:39:52.197 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-09-22 10:39:52.197 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xF9
2016-09-22 10:39:52.198 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 13 12 00 00 00 F9
2016-09-22 10:39:52.198 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 13 12 00 00 00 F9
2016-09-22 10:39:52.198 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=12 00
2016-09-22 10:39:52.198 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
2016-09-22 10:39:52.198 [TRACE] [l.serialmessage.SendDataMessageClass] - Handle Message Send Data Request
2016-09-22 10:39:52.198 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: SendData Request. CallBack ID = 18, Status = Transmission complete and ACK received(0)
2016-09-22 10:39:52.199 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=12, callback=18, payload=0C 03 70 05 02
2016-09-22 10:39:52.199 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=12 00
2016-09-22 10:39:52.199 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=18, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2016-09-22 10:39:57.174 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 12: Timeout while sending message. Requeueing - 0 attempts left!
2016-09-22 10:39:57.175 [TRACE] [l.serialmessage.SendDataMessageClass] - NODE 12: Handling failed message.
2016-09-22 10:39:57.175 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 12: Got an error while sending data. Resending message.
2016-09-22 10:39:57.175 [TRACE] [ve.internal.protocol.ZWaveController] - Callback ID = 19
2016-09-22 10:39:57.175 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 5. Queue={}
2016-09-22 10:39:57.175 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 4
2016-09-22 10:39:57.176 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xA8
2016-09-22 10:39:57.176 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 0C 03 70 05 02 25 13 A8
2016-09-22 10:39:57.177 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 12: Sending REQUEST Message = 01 0A 00 13 0C 03 70 05 02 25 13 A8
2016-09-22 10:39:57.177 [TRACE] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2016-09-22 10:39:57.179 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received ACK
2016-09-22 10:39:57.183 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2016-09-22 10:39:57.183 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2016-09-22 10:39:57.184 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 04 01 13 01 E8
2016-09-22 10:39:57.184 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
2016-09-22 10:39:57.184 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2016-09-22 10:39:57.184 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Message payload = 01
2016-09-22 10:39:57.184 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2016-09-22 10:39:57.185 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT
2016-09-22 10:39:57.185 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-09-22 10:39:57.185 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xE8
2016-09-22 10:39:57.186 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2016-09-22 10:39:57.186 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2016-09-22 10:39:57.186 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2016-09-22 10:39:57.186 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE
2016-09-22 10:39:57.186 [TRACE] [l.serialmessage.SendDataMessageClass] - Handle Message Send Data Response
2016-09-22 10:39:57.187 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: Sent Data successfully placed on stack.
2016-09-22 10:39:57.187 [TRACE] [wave.internal.protocol.SerialMessage] - Ack Pending cleared
2016-09-22 10:39:57.198 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2016-09-22 10:39:57.199 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 13 00 FA
2016-09-22 10:39:57.199 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 05 00 13 13 00 FA
2016-09-22 10:39:57.199 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xFA
2016-09-22 10:39:57.200 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2016-09-22 10:39:57.200 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Message payload = 13 00
2016-09-22 10:39:57.200 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2016-09-22 10:39:57.200 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT
2016-09-22 10:39:57.201 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-09-22 10:39:57.201 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xF8
2016-09-22 10:39:57.201 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 13 13 00 00 00 F8
2016-09-22 10:39:57.202 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 13 13 00 00 00 F8
2016-09-22 10:39:57.202 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=13 00
2016-09-22 10:39:57.202 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
2016-09-22 10:39:57.202 [TRACE] [l.serialmessage.SendDataMessageClass] - Handle Message Send Data Request
2016-09-22 10:39:57.202 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 12: SendData Request. CallBack ID = 19, Status = Transmission complete and ACK received(0)
2016-09-22 10:39:57.203 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Config, dest=12, callback=19, payload=0C 03 70 05 02
2016-09-22 10:39:57.203 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=13 00
2016-09-22 10:39:57.203 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=19, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2016-09-22 10:40:01.873 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
2016-09-22 10:40:01.874 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 0A 07 60 0D 01 00 20 01 00 B6
2016-09-22 10:40:01.874 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 0D 00 04 00 0A 07 60 0D 01 00 20 01 00 B6
2016-09-22 10:40:01.875 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xB6
2016-09-22 10:40:01.875 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched
2016-09-22 10:40:01.875 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Message payload = 00 0A 07 60 0D 01 00 20 01 00
2016-09-22 10:40:01.875 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
2016-09-22 10:40:01.876 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT
2016-09-22 10:40:01.876 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-09-22 10:40:01.876 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 0xB6
2016-09-22 10:40:01.877 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 04 00 0A 07 60 0D 01 00 20 01 00 B6
2016-09-22 10:40:01.877 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0D 00 04 00 0A 07 60 0D 01 00 20 01 00 B6
2016-09-22 10:40:01.878 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 0A 07 60 0D 01 00 20 01 00
2016-09-22 10:40:01.878 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
2016-09-22 10:40:01.878 [TRACE] [ssage.ApplicationCommandMessageClass] - Handle Message Application Command Request
2016-09-22 10:40:01.878 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 10: Application Command Request (INITIALIZING:WAIT)
2016-09-22 10:40:01.879 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Node is ALIVE. Init stage is WAIT.
2016-09-22 10:40:01.879 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNodeStatusEvent
2016-09-22 10:40:01.879 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2016-09-22 10:40:01.879 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Setting ONLINE
2016-09-22 10:40:01.880 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node Status event during initialisation - Node is ALIVE
2016-09-22 10:40:01.880 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - PING: queue length(1), free to send(false)
2016-09-22 10:40:01.881 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - queued packet. Queue length is 1
2016-09-22 10:40:01.881 [TRACE] [ve.internal.protocol.ZWaveController] - Callback ID = 20
2016-09-22 10:40:01.881 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 5. Queue={}
2016-09-22 10:40:01.881 [TRACE] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node Status event during initialisation processed
2016-09-22 10:40:01.882 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node Status event during initialisation - Node is ALIVE
2016-09-22 10:40:01.882 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer - WAIT: queue length(0), free to send(true)
2016-09-22 10:40:01.882 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: loop - WAIT try 1: stageAdvanced(false)
2016-09-22 10:40:01.886 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: WAIT - Listening=false, FrequentlyListening=false
2016-09-22 10:40:01.887 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: WAIT - Still waiting!
2016-09-22 10:40:01.887 [TRACE] [alization.ZWaveNodeInitStageAdvancer] - NODE 10: Node Status event during initialisation processed
2016-09-22 10:40:01.893 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 10: Node Status event - Node is ALIVE
2016-09-22 10:40:01.893 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 10: Incoming command class MULTI_INSTANCE
2016-09-22 10:40:01.893 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 10: Command class MULTI_INSTANCE not found, trying to add it.
2016-09-22 10:40:01.894 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Creating new instance of command class MULTI_INSTANCE
2016-09-22 10:40:01.894 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Command class MULTI_INSTANCE, endpoint null created
2016-09-22 10:40:01.894 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 10: Adding command class MULTI_INSTANCE
2016-09-22 10:40:01.894 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Adding command class MULTI_INSTANCE to the list of supported command classes.
2016-09-22 10:40:01.894 [TRACE] [ssage.ApplicationCommandMessageClass] - NODE 10: Found Command Class MULTI_INSTANCE, passing to handleApplicationCommandRequest
2016-09-22 10:40:01.894 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 10: Received MULTI_INSTANCE command V0
2016-09-22 10:40:01.895 [TRACE] [class.ZWaveMultiInstanceCommandClass] - Process Multi-channel Encapsulation
2016-09-22 10:40:01.895 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 10: Requested Command Class = BASIC (0x20)
2016-09-22 10:40:01.895 [ERROR] [class.ZWaveMultiInstanceCommandClass] - NODE 10: Endpoint 1 not found. Cannot set command classes.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment