Z-Wave binding - node is dead

newbie · January 22, 2017, 1:13pm

hi,

i am new to OH2. Currently, trying out to replace my vera but i had encounter some issues.

I am running OH2 on RPI2 with aeon labs z-stick s2. I had already finish the inclusion for fibaro FGS-221 to the z-stick.
However, in the paperui, its status show

OFFLINE - COMMUNICATION_ERROR Node is not communicating with controller

But when i tried turning on the lights, Its show online

2017-01-22 20:50:58.367 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 06 07 60 0D 02 02 25 03 FF 43
2017-01-22 20:50:58.370 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-22 20:50:58.373 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 04 00 06 07 60 0D 02 02 25 03 FF 43
2017-01-22 20:50:58.376 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0D 00 04 00 06 07 60 0D 02 02 25 03 FF 43
2017-01-22 20:50:58.379 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 06 07 60 0D 02 02 25 03 FF
2017-01-22 20:50:58.380 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Application Command Request (DEAD:DYNAMIC_VALUES)
2017-01-22 20:50:58.382 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: Node is ALIVE. Init stage is DYNAMIC_VALUES.
2017-01-22 20:50:58.383 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNodeStatusEvent
2017-01-22 20:50:58.384 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node Status event during initialisation - Node is ALIVE
2017-01-22 20:50:58.386 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer - DYNAMIC_VALUES: queue length(2), free to send(false)
2017-01-22 20:50:58.387 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Initialisation retry timer started 10000
2017-01-22 20:50:58.388 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer - queued packet. Queue length is 2
2017-01-22 20:50:58.390 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2017-01-22 20:50:58.390 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2017-01-22 20:50:58.391 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2017-01-22 20:50:58.392 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 06 02 73 02 25 39 8C
2017-01-22 20:50:58.393 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Setting ONLINE
2017-01-22 20:50:58.394 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 09 00 13 06 02 73 02 25 39 8C
2017-01-22 20:50:58.398 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 6: Node Status event - Node is ALIVE
2017-01-22 20:50:58.400 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Incoming command class MULTI_INSTANCE
2017-01-22 20:50:58.402 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 6: Received MULTI_INSTANCE command V2
2017-01-22 20:50:58.404 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 6: Requested Command Class = SWITCH_BINARY (0x25)
2017-01-22 20:50:58.406 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 6: Endpoint = 2, calling handleApplicationCommandRequest.
2017-01-22 20:50:58.407 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - Received Switch Binary Request for Node ID = 6
2017-01-22 20:50:58.408 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 6: Switch Binary report, value = 255
2017-01-22 20:50:58.410 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2017-01-22 20:50:58.411 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2017-01-22 20:50:58.413 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got a value event from Z-Wave network, endpoint = 2, command class = SWITCH_BINARY, value = 255
2017-01-22 20:50:58.415 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Updating channel state zwave:device:8c194533:node6:switch_binary2 to ON [OnOffType]
2017-01-22 20:50:58.416 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 8: Transaction not completed: node address inconsistent.  lastSent=8, incoming=255
2017-01-22 20:50:58.423 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2017-01-22 20:50:58.425 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-22 20:50:58.427 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2017-01-22 20:50:58.429 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2017-01-22 20:50:58.431 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2017-01-22 20:50:58.433 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: Sent Data successfully placed on stack.
2017-01-22 20:50:58.702 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 06 07 60 0D 02 02 25 03 00 BC
2017-01-22 20:50:58.705 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-22 20:50:58.706 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 04 00 06 07 60 0D 02 02 25 03 00 BC
2017-01-22 20:50:58.708 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0D 00 04 00 06 07 60 0D 02 02 25 03 00 BC
2017-01-22 20:50:58.709 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 06 07 60 0D 02 02 25 03 00
2017-01-22 20:50:58.710 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Application Command Request (ALIVE:DYNAMIC_VALUES)
2017-01-22 20:50:58.711 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Incoming command class MULTI_INSTANCE
2017-01-22 20:50:58.712 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 6: Received MULTI_INSTANCE command V2
2017-01-22 20:50:58.713 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 6: Requested Command Class = SWITCH_BINARY (0x25)
2017-01-22 20:50:58.714 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 6: Endpoint = 2, calling handleApplicationCommandRequest.
2017-01-22 20:50:58.715 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - Received Switch Binary Request for Node ID = 6
2017-01-22 20:50:58.716 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 6: Switch Binary report, value = 0
2017-01-22 20:50:58.717 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2017-01-22 20:50:58.718 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2017-01-22 20:50:58.719 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got a value event from Z-Wave network, endpoint = 2, command class = SWITCH_BINARY, value = 0
2017-01-22 20:50:58.720 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Updating channel state zwave:device:8c194533:node6:switch_binary2 to OFF [OnOffType]
2017-01-22 20:50:58.722 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=6, callback=57, payload=06 02 73 02
2017-01-22 20:50:58.724 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 06 07 60 0D 02 02 25 03 00
2017-01-22 20:50:58.725 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=57, expected=ApplicationCommandHandler, cancelled=false        transaction complete!
2017-01-22 20:50:58.726 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-01-22 20:50:58.727 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer - DYNAMIC_VALUES: Transaction complete (SendData:Request) success(true)
2017-01-22 20:50:58.727 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer - checking initialisation queue. Queue size 2.
2017-01-22 20:50:58.728 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer - message removed from queue. Queue size 1.
2017-01-22 20:50:58.729 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer - DYNAMIC_VALUES: queue length(1), free to send(true)
2017-01-22 20:50:58.729 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Initialisation retry timer started 10000
2017-01-22 20:50:58.730 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer - queued packet. Queue length is 1
2017-01-22 20:50:58.731 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2017-01-22 20:50:58.732 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-01-22 20:50:58.733 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Response processed after 338ms/542ms.
2017-01-22 20:50:58.733 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2017-01-22 20:50:58.735 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 06 06 60 0D 01 01 25 02 25 3A B4
2017-01-22 20:50:58.736 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0D 00 13 06 06 60 0D 01 01 25 02 25 3A B4
2017-01-22 20:50:58.764 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2017-01-22 20:50:58.766 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-22 20:50:58.767 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2017-01-22 20:50:58.768 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2017-01-22 20:50:58.769 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2017-01-22 20:50:58.770 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: Sent Data successfully placed on stack.
2017-01-22 20:50:58.873 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 3A 01 D2
2017-01-22 20:50:58.875 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-22 20:50:58.876 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 13 3A 01 00 00 D0
2017-01-22 20:50:58.877 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 13 3A 01 00 00 D0
2017-01-22 20:50:58.878 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=3A 01
2017-01-22 20:50:58.879 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: SendData Request. CallBack ID = 58, Status = Transmission complete, no ACK received(1)
2017-01-22 20:50:58.880 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 6: Got an error while sending data. Resending message.
2017-01-22 20:50:58.880 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2017-01-22 20:50:58.881 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-01-22 20:50:58.882 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer - DYNAMIC_VALUES: Transaction complete (SendData:Request) success(false)
2017-01-22 20:50:58.882 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-01-22 20:50:58.883 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Response processed after 145ms/542ms.
2017-01-22 20:50:58.884 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2017-01-22 20:50:58.886 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 06 06 60 0D 01 01 25 02 25 3B B5
2017-01-22 20:50:58.887 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0D 00 13 06 06 60 0D 01 01 25 02 25 3B B5
2017-01-22 20:50:58.915 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2017-01-22 20:50:58.917 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-22 20:50:58.918 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2017-01-22 20:50:58.919 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2017-01-22 20:50:58.920 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2017-01-22 20:50:58.921 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: Sent Data successfully placed on stack.
2017-01-22 20:50:59.221 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 3B 01 D3
2017-01-22 20:50:59.223 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-22 20:50:59.225 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 13 3B 01 00 00 D1
2017-01-22 20:50:59.226 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 13 3B 01 00 00 D1
2017-01-22 20:50:59.227 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=3B 01
2017-01-22 20:50:59.228 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: SendData Request. CallBack ID = 59, Status = Transmission complete, no ACK received(1)
2017-01-22 20:50:59.229 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 6: Got an error while sending data. Resending message.
2017-01-22 20:50:59.229 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2017-01-22 20:50:59.230 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-01-22 20:50:59.241 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer - DYNAMIC_VALUES: Transaction complete (SendData:Request) success(false)
2017-01-22 20:50:59.244 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-01-22 20:50:59.245 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Response processed after 356ms/542ms.
2017-01-22 20:50:59.245 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2017-01-22 20:50:59.247 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 06 06 60 0D 01 01 25 02 25 3C B2
2017-01-22 20:50:59.248 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 0D 00 13 06 06 60 0D 01 01 25 02 25 3C B2
2017-01-22 20:50:59.276 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2017-01-22 20:50:59.277 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-22 20:50:59.279 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2017-01-22 20:50:59.280 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2017-01-22 20:50:59.281 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2017-01-22 20:50:59.282 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: Sent Data successfully placed on stack.
2017-01-22 20:50:59.489 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 3C 01 D4
2017-01-22 20:50:59.490 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-22 20:50:59.492 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 13 3C 01 00 00 D6
2017-01-22 20:50:59.493 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 13 3C 01 00 00 D6
2017-01-22 20:50:59.495 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=3C 01
2017-01-22 20:50:59.495 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: SendData Request. CallBack ID = 60, Status = Transmission complete, no ACK received(1)
2017-01-22 20:50:59.497 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: Node is DEAD.
2017-01-22 20:50:59.497 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNodeStatusEvent
2017-01-22 20:50:59.498 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node Status event during initialisation - Node is DEAD
2017-01-22 20:50:59.499 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2017-01-22 20:50:59.499 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Setting OFFLINE
2017-01-22 20:50:59.503 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 6: Node Status event - Node is DEAD
2017-01-22 20:50:59.504 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 6: Node is DEAD. Dropping message.
2017-01-22 20:50:59.505 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-01-22 20:50:59.506 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer - DYNAMIC_VALUES: Transaction complete (SendData:Request) success(false)
2017-01-22 20:50:59.506 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-01-22 20:50:59.507 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Response processed after 258ms/542ms.
2017-01-22 20:50:59.919 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 3C 01 D4
2017-01-22 20:50:59.921 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-22 20:50:59.923 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 13 3C 01 00 00 D6
2017-01-22 20:50:59.925 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 13 3C 01 00 00 D6
2017-01-22 20:50:59.928 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=3C 01
2017-01-22 20:50:59.929 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: SendData Request. CallBack ID = 60, Status = Transmission complete, no ACK received(1)
2017-01-22 20:50:59.930 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 6: Node is DEAD. Dropping message.
2017-01-22 20:50:59.931 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-01-22 20:50:59.932 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer - DYNAMIC_VALUES: Transaction complete (SendData:Request) success(false)
2017-01-22 20:50:59.933 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-01-22 20:51:08.729 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Stage DYNAMIC_VALUES. Initialisation retry timer triggered. Increased to 20000
2017-01-22 20:51:08.730 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer - DYNAMIC_VALUES: queue length(0), free to send(false)
2017-01-22 20:51:08.731 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Initialisation retry timer started 20000
2017-01-22 20:51:08.732 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: loop - DYNAMIC_VALUES try 2: stageAdvanced(false)
2017-01-22 20:51:08.733 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking CONFIGURATION
2017-01-22 20:51:08.734 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking FIRMWARE_UPDATE_MD
2017-01-22 20:51:08.734 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking SWITCH_ALL
2017-01-22 20:51:08.735 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking ASSOCIATION
2017-01-22 20:51:08.736 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking MULTI_INSTANCE_ASSOCIATION
2017-01-22 20:51:08.736 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking NO_OPERATION
2017-01-22 20:51:08.737 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking BASIC
2017-01-22 20:51:08.738 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking MANUFACTURER_SPECIFIC
2017-01-22 20:51:08.738 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking POWERLEVEL
2017-01-22 20:51:08.739 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - found    POWERLEVEL
2017-01-22 20:51:08.739 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Found 1 instances of POWERLEVEL
2017-01-22 20:51:08.740 [DEBUG] [andclass.ZWavePowerLevelCommandClass] - NODE 6: Creating new message for application command POWERLEVEL_GET
2017-01-22 20:51:08.741 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer - queued packet. Queue length is 1
2017-01-22 20:51:08.742 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2017-01-22 20:51:08.742 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2017-01-22 20:51:08.743 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking MULTI_INSTANCE
2017-01-22 20:51:08.744 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking BASIC for endpoint 1
2017-01-22 20:51:08.744 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 06 02 73 02 25 3D 88
2017-01-22 20:51:08.745 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking SWITCH_BINARY for endpoint 1
2017-01-22 20:51:08.745 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - found    SWITCH_BINARY
2017-01-22 20:51:08.746 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 09 00 13 06 02 73 02 25 3D 88
2017-01-22 20:51:08.746 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 6: Creating new message for application command SWITCH_BINARY_GET
2017-01-22 20:51:08.747 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: Encapsulating message, instance / endpoint 1
2017-01-22 20:51:08.748 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 6: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1
2017-01-22 20:51:08.749 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking BASIC for endpoint 2
2017-01-22 20:51:08.750 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking SWITCH_BINARY for endpoint 2
2017-01-22 20:51:08.751 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - found    SWITCH_BINARY
2017-01-22 20:51:08.752 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking SWITCH_BINARY
2017-01-22 20:51:08.753 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - found    SWITCH_BINARY
2017-01-22 20:51:08.754 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Found 1 instances of SWITCH_BINARY
2017-01-22 20:51:08.755 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking VERSION
2017-01-22 20:51:08.756 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - queued 2 frames
2017-01-22 20:51:08.774 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2017-01-22 20:51:08.777 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-22 20:51:08.778 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2017-01-22 20:51:08.779 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2017-01-22 20:51:08.780 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2017-01-22 20:51:08.782 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: Sent Data successfully placed on stack.
2017-01-22 20:51:09.242 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 3D 01 D5
2017-01-22 20:51:09.245 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-01-22 20:51:09.246 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 13 3D 01 00 00 D7
2017-01-22 20:51:09.248 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 13 3D 01 00 00 D7
2017-01-22 20:51:09.249 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=3D 01
2017-01-22 20:51:09.250 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: SendData Request. CallBack ID = 61, Status = Transmission complete, no ACK received(1)
2017-01-22 20:51:09.251 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 6: Node is DEAD. Dropping message.
2017-01-22 20:51:09.251 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-01-22 20:51:09.252 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer - DYNAMIC_VALUES: Transaction complete (SendData:Request) success(false)
2017-01-22 20:51:09.253 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-01-22 20:51:09.254 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Response processed after 507ms/542ms.
2017-01-22 20:51:28.731 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Stage DYNAMIC_VALUES. Initialisation retry timer triggered. Increased to 40000
2017-01-22 20:51:28.734 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer - DYNAMIC_VALUES: queue length(0), free to send(false)
2017-01-22 20:51:28.735 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Initialisation retry timer started 40000
2017-01-22 20:51:28.735 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: loop - DYNAMIC_VALUES try 3: stageAdvanced(false)
2017-01-22 20:51:28.736 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking CONFIGURATION
2017-01-22 20:51:28.737 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking FIRMWARE_UPDATE_MD
2017-01-22 20:51:28.738 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking SWITCH_ALL
2017-01-22 20:51:28.739 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking ASSOCIATION
2017-01-22 20:51:28.740 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking MULTI_INSTANCE_ASSOCIATION
2017-01-22 20:51:28.740 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking NO_OPERATION
2017-01-22 20:51:28.741 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking BASIC
2017-01-22 20:51:28.742 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking MANUFACTURER_SPECIFIC
2017-01-22 20:51:28.743 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking POWERLEVEL
2017-01-22 20:51:28.743 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - found    POWERLEVEL
2017-01-22 20:51:28.744 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Found 1 instances of POWERLEVEL
2017-01-22 20:51:28.745 [DEBUG] [andclass.ZWavePowerLevelCommandClass] - NODE 6: Creating new message for application command POWERLEVEL_GET
2017-01-22 20:51:28.746 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer - queued packet. Queue length is 1
2017-01-22 20:51:28.748 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2017-01-22 20:51:28.748 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2017-01-22 20:51:28.748 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking MULTI_INSTANCE
2017-01-22 20:51:28.749 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking BASIC for endpoint 1
2017-01-22 20:51:28.750 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 06 02 73 02 25 3E 8B
2017-01-22 20:51:28.750 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking SWITCH_BINARY for endpoint 1
2017-01-22 20:51:28.751 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - found    SWITCH_BINARY
2017-01-22 20:51:28.751 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 09 00 13 06 02 73 02 25 3E 8B
2017-01-22 20:51:28.752 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 6: Creating new message for application command SWITCH_BINARY_GET
2017-01-22 20:51:28.754 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: Encapsulating message, instance / endpoint 1
2017-01-22 20:51:28.755 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 6: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1
2017-01-22 20:51:28.756 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking BASIC for endpoint 2
2017-01-22 20:51:28.756 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking SWITCH_BINARY for endpoint 2
2017-01-22 20:51:28.757 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - found    SWITCH_BINARY
2017-01-22 20:51:28.757 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking SWITCH_BINARY
2017-01-22 20:51:28.758 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - found    SWITCH_BINARY
2017-01-22 20:51:28.759 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Found 1 instances of SWITCH_BINARY
2017-01-22 20:51:28.760 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - checking VERSION
2017-01-22 20:51:28.760 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Node advancer: DYNAMIC_VALUES - queued 2 frames
2017-01-22 20:51:28.781 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2017-01-22 20:51:28.783 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0

rlkoshak · January 23, 2017, 7:20pm

When I last saw that sort of behavior it was caused by a sparse mesh network. Adding one or more mains powered devices somewhere between your device and the controller might help with this problem. Take a look at your network in Habmin. If you see some devices that are one or two hops from the controller or that have only one path to the controller that would be a problem.

If you have only one device that can reach the controller (that was my problem) it would be a problem as well.

newbie · January 24, 2017, 8:44am

hi,

the relay and the zstick is less than 1m apart. as i am using it as a testing environment.

chris · January 24, 2017, 9:16am

I would move the two devices further apart - maybe the stick is overloading the device. I’m not convinced that this will help, but it is certainly a potential cause.

If we look at your log, we see that we are receiving messages from the device (probably when you click the switch since there are no requests requesting this information). However, whenever we request data from the device, the messages always timeout. They are received by the controller, but there is never a ack/response from the device.

This is happening for multiple message types, so it is probably not a configuration issue.

So, I would first move them further apart to ensure there is no overload issue. If that doesn’t work, I’d reset the device. I’d also try deleting the XML file for the device so that it completely reinitialises to see what the log shows during the initial stages of initialisation - clearly it has partly initialised, so it must have received data at one time…

newbie · January 30, 2017, 2:49pm

Hi Chris,

sorry for the late reply .

However, even i place the relay further it does not seem to work .

Usually the relay will have a click sound if it received the command. But it this case it doesnt, so am quite positive that the relay didnt receive any command, Previously, it was working

chris · January 30, 2017, 3:13pm

I’m not sure what else to suggest. Maybe the device has crashed or something - I’d try resetting it. It would also be interesting to see if there’s any communications early in the initialisation cycle so if you have a log from startup it would be worth seeing if it responds to any messages at all…

newbie · January 31, 2017, 2:35pm

Hi Chris,

Had managed to reset the zstick . seem like the zstick got corrupted.

it just came back alive.

thanks for the suggestion.