Hi,
I’m using OH2 with z-wave dongle ( blue in color ) to control z-wave devices. I’m currently using the latest z-wave binding (2.3.0). I managed to enroll 34 devices such as Fibaro dimmers, relays, roller-shutter eventually they all worked fine without any problems except initial inclusion to openhab2 was bit of a pain but I managed to enroll them. I was able to control z-wave devices that was enroll via control page where I was happy about but when I try to turn physical switch on or off I couldn’t get any updates so I went other forums and found I need to update each device configuration to report to OpenHab controller where I went inside each device configuration and change associate group to OpenHab controller and tested with two devices which worked fine. But when I tried to do to all the other devices z-wave dongle ( blue in color ) started to act weirdly and stopped sending any commands to any devices sometime some devices gets update after 5 to 10 mins or more which made things worst where now if I have to update any device I will have to send a command then wait for n number of times. Did any got this issue ? Please help me out.
P:S - Z-wave dongle not able to flash it’s blue light when I put it onto inclusion mode
I have attached openhab log
2018-08-24 13:10:27.020 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-08-24 13:10:27.883 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 51 7B 00 D0
2018-08-24 13:10:27.885 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AssignSucReturnRoute[81], type=Request[0], dest=0, callback=123, payload=7B 00
2018-08-24 13:10:27.887 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=AssignSucReturnRoute[81], type=Request[0], dest=0, callback=123, payload=7B 00
2018-08-24 13:10:27.888 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AssignSucReturnRoute[81], type=Request[0], dest=0, callback=123, payload=7B 00
2018-08-24 13:10:27.890 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 616: [WAIT_REQUEST] requiresResponse=true callback: 123
2018-08-24 13:10:27.891 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-08-24 13:10:27.892 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 616: [WAIT_REQUEST] requiresResponse=true callback: 123
2018-08-24 13:10:27.893 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 616: (Callback 123)
2018-08-24 13:10:27.895 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2018-08-24 13:10:27.896 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 616: callback 123
2018-08-24 13:10:27.898 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AssignSucReturnRoute[81], type=Request[0], dest=0, callback=123, payload=7B 00
2018-08-24 13:10:27.899 [DEBUG] [age.AssignSucReturnRouteMessageClass] - NODE 12: Got AssignSucReturnRoute request.
2018-08-24 13:10:27.900 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 616: Transaction COMPLETED
2018-08-24 13:10:27.902 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveNetworkEvent
2018-08-24 13:10:27.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Response processed after 910ms
2018-08-24 13:10:27.905 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: TID 616: Transaction completed
2018-08-24 13:10:27.906 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: notifyTransactionResponse TID:616 DONE
2018-08-24 13:10:27.908 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-08-24 13:10:27.908 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 616: Transaction event listener: DONE: DONE ->
2018-08-24 13:10:27.909 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-08-24 13:10:27.910 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: – To notify – COMPLETE
2018-08-24 13:10:27.911 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 80 08 00 00 03 73
2018-08-24 13:10:27.912 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction Response Complete – 616 –
2018-08-24 13:10:27.913 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 07 00 80 08 00 00 03 73
2018-08-24 13:10:27.913 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@b3a37b
2018-08-24 13:10:27.914 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node Init transaction completed with response COMPLETE
2018-08-24 13:10:27.914 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2018-08-24 13:10:27.915 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - advancing to DELETE_ROUTES
2018-08-24 13:10:27.915 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 60: Transaction Start type GetRoutingInfo
2018-08-24 13:10:27.915 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2018-08-24 13:10:27.916 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2018-08-24 13:10:27.919 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Generate return routes list
2018-08-24 13:10:27.919 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-08-24 13:10:27.920 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer is deleting return routes.
2018-08-24 13:10:27.921 [DEBUG] [essage.DeleteReturnRouteMessageClass] - NODE 12: Deleting return routes
2018-08-24 13:10:27.922 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@25ba52
2018-08-24 13:10:27.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Adding to device queue
2018-08-24 13:10:27.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-08-24 13:10:27.926 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-08-24 13:10:27.926 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Added to queue - size 1
2018-08-24 13:10:27.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 60: [WAIT_RESPONSE] requiresResponse=true callback: 0
2018-08-24 13:10:27.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2018-08-24 13:10:27.928 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 20 01 80 7F FF C7 DD 6E 1E 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 B4
2018-08-24 13:10:27.928 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-08-24 13:10:27.930 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetRoutingInfo[128], type=Response[1], dest=255, callback=0, payload=7F FF C7 DD 6E 1E 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2018-08-24 13:10:27.932 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=GetRoutingInfo[128], type=Response[1], dest=255, callback=0, payload=7F FF C7 DD 6E 1E 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2018-08-24 13:10:27.935 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetRoutingInfo[128], type=Response[1], dest=255, callback=0, payload=7F FF C7 DD 6E 1E 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2018-08-24 13:10:27.936 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 60: [WAIT_RESPONSE] requiresResponse=true callback: 0
2018-08-24 13:10:27.937 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-08-24 13:10:27.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 60: [WAIT_RESPONSE] requiresResponse=true callback: 0
2018-08-24 13:10:27.940 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetRoutingInfo[128], type=Response[1], dest=255, callback=0, payload=7F FF C7 DD 6E 1E 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2018-08-24 13:10:27.942 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 8: Got NodeRoutingInfo request.
2018-08-24 13:10:27.943 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 8: Neighbor nodes: 1 2 3 4 5 6 7 9 10 11 12 13 14 15 16 17 18 19 23 24 25 27 28 29 31 32 34 35 36 38 39 42 43 44 45
2018-08-24 13:10:27.945 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveNetworkEvent
2018-08-24 13:10:27.971 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 60: Transaction COMPLETED
2018-08-24 13:10:27.972 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 57ms
2018-08-24 13:10:27.973 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 60: Transaction completed
2018-08-24 13:10:27.974 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:60 DONE
2018-08-24 13:10:27.986 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-08-24 13:10:27.986 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 60: Transaction event listener: DONE: DONE ->
2018-08-24 13:10:27.987 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: listening == true, frequentlyListening == false, awake == false
2018-08-24 13:10:27.988 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: – To notify – COMPLETE
2018-08-24 13:10:27.989 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 47 0C 7C CD
2018-08-24 13:10:27.990 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction Response Complete – 60 –
2018-08-24 13:10:27.991 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 47 0C 7C CD
2018-08-24 13:10:27.991 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@46282a
2018-08-24 13:10:27.993 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node Init transaction completed with response COMPLETE
2018-08-24 13:10:27.993 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2018-08-24 13:10:27.993 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 618: Transaction Start type DeleteReturnRoute
2018-08-24 13:10:27.994 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2018-08-24 13:10:27.994 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer - advancing to FAILED_CHECK
2018-08-24 13:10:27.995 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-08-24 13:10:27.997 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-08-24 13:10:27.997 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2018-08-24 13:10:27.998 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-08-24 13:10:28.000 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 47 01 BC
2018-08-24 13:10:28.001 [DEBUG] [rialmessage.IsFailedNodeMessageClass] - NODE 8: Requesting IsFailedNode status from controller.
2018-08-24 13:10:28.003 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1fd4a9c
2018-08-24 13:10:28.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 618: [WAIT_RESPONSE] requiresResponse=true callback: 124
2018-08-24 13:10:28.006 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2018-08-24 13:10:28.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to controller queue
2018-08-24 13:10:28.007 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-08-24 13:10:28.008 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added to queue - size 9
2018-08-24 13:10:28.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=DeleteReturnRoute[71], type=Response[1], dest=255, callback=0, payload=01
2018-08-24 13:10:28.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=DeleteReturnRoute[71], type=Response[1], dest=255, callback=0, payload=01
2018-08-24 13:10:28.012 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=DeleteReturnRoute[71], type=Response[1], dest=255, callback=0, payload=01
2018-08-24 13:10:28.014 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 618: [WAIT_RESPONSE] requiresResponse=true callback: 124
2018-08-24 13:10:28.015 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-08-24 13:10:28.017 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 618: [WAIT_RESPONSE] requiresResponse=true callback: 124
2018-08-24 13:10:28.018 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=DeleteReturnRoute[71], type=Response[1], dest=255, callback=0, payload=01
2018-08-24 13:10:28.020 [DEBUG] [essage.DeleteReturnRouteMessageClass] - NODE 12: Got DeleteReturnRoute response.
2018-08-24 13:10:28.021 [DEBUG] [essage.DeleteReturnRouteMessageClass] - NODE 12: DeleteReturnRoute command started.
2018-08-24 13:10:28.023 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 618: Advanced to WAIT_REQUEST
2018-08-24 13:10:28.024 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: TID 618: Transaction not completed
2018-08-24 13:10:28.025 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-08-24 13:10:28.650 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 47 7C 00 C1
2018-08-24 13:10:28.652 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=DeleteReturnRoute[71], type=Request[0], dest=0, callback=124, payload=7C 00
2018-08-24 13:10:28.653 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=DeleteReturnRoute[71], type=Request[0], dest=0, callback=124, payload=7C 00
2018-08-24 13:10:28.655 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=DeleteReturnRoute[71], type=Request[0], dest=0, callback=124, payload=7C 00
2018-08-24 13:10:28.656 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 618: [WAIT_REQUEST] requiresResponse=true callback: 124
2018-08-24 13:10:28.657 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-08-24 13:10:28.659 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 618: [WAIT_REQUEST] requiresResponse=true callback: 124
2018-08-24 13:10:28.660 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 618: (Callback 124)
2018-08-24 13:10:28.662 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2018-08-24 13:10:28.663 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 618: callback 124
2018-08-24 13:10:28.664 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=DeleteReturnRoute[71], type=Request[0], dest=0, callback=124, payload=7C 00
2018-08-24 13:10:28.666 [DEBUG] [essage.DeleteReturnRouteMessageClass] - NODE 12: Got DeleteReturnRoute request.
2018-08-24 13:10:28.667 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveNetworkEvent
2018-08-24 13:10:28.669 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 618: Transaction COMPLETED
2018-08-24 13:10:28.670 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Response processed after 677ms
2018-08-24 13:10:28.672 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: TID 618: Transaction completed
2018-08-24 13:10:28.673 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: notifyTransactionResponse TID:618 DONE
2018-08-24 13:10:28.675 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-08-24 13:10:28.675 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 618: Transaction event listener: DONE: DONE ->
2018-08-24 13:10:28.676 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: – To notify – COMPLETE
2018-08-24 13:10:28.676 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-08-24 13:10:28.677 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction Response Complete – 618 –
2018-08-24 13:10:28.678 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 80 2C 00 00 03 57
2018-08-24 13:10:28.678 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@b670c
2018-08-24 13:10:28.679 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 07 00 80 2C 00 00 03 57
2018-08-24 13:10:28.680 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node Init transaction completed with response COMPLETE
2018-08-24 13:10:28.681 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2018-08-24 13:10:28.682 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Node advancer - advancing to RETURN_ROUTES
2018-08-24 13:10:28.682 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 617: Transaction Start type GetRoutingInfo
2018-08-24 13:10:28.682 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2018-08-24 13:10:28.683 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2018-08-24 13:10:28.683 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-08-24 13:10:28.685 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Generate return routes list
2018-08-24 13:10:28.685 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-08-24 13:10:28.687 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 12: Adding return route to 1
2018-08-24 13:10:28.689 [DEBUG] [essage.AssignReturnRouteMessageClass] - NODE 12: Assigning return route to node 1
2018-08-24 13:10:28.690 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-08-24 13:10:28.690 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 20 01 80 DF FF C7 DD EE 33 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 B9
2018-08-24 13:10:28.693 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1760969
2018-08-24 13:10:28.694 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 617: [WAIT_RESPONSE] requiresResponse=true callback: 0
2018-08-24 13:10:28.695 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2018-08-24 13:10:28.696 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Adding to device queue
2018-08-24 13:10:28.697 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetRoutingInfo[128], type=Response[1], dest=255, callback=0, payload=DF FF C7 DD EE 33 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2018-08-24 13:10:28.698 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Added to queue - size 1
2018-08-24 13:10:28.698 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=GetRoutingInfo[128], type=Response[1], dest=255, callback=0, payload=DF FF C7 DD EE 33 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2018-08-24 13:10:28.699 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-08-24 13:10:28.702 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetRoutingInfo[128], type=Response[1], dest=255, callback=0, payload=DF FF C7 DD EE 33 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2018-08-24 13:10:28.703 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 617: [WAIT_RESPONSE] requiresResponse=true callback: 0
2018-08-24 13:10:28.704 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-08-24 13:10:28.706 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 617: [WAIT_RESPONSE] requiresResponse=true callback: 0
2018-08-24 13:10:28.708 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetRoutingInfo[128], type=Response[1], dest=255, callback=0, payload=DF FF C7 DD EE 33 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2018-08-24 13:10:28.709 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 44: Got NodeRoutingInfo request.
2018-08-24 13:10:28.711 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 44: Neighbor nodes: 1 2 3 4 5 7 8 9 10 11 12 13 14 15 16 17 18 19 23 24 25 27 28 29 31 32 34 35 36 38 39 40 41 42 45 46
2018-08-24 13:10:28.712 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 44: Got an event from Z-Wave network: ZWaveNetworkEvent
2018-08-24 13:10:28.714 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 617: Transaction COMPLETED
2018-08-24 13:10:28.716 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 34ms
2018-08-24 13:10:28.717 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 617: Transaction completed
2018-08-24 13:10:28.719 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:617 DONE
2018-08-24 13:10:28.720 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-08-24 13:10:28.720 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 617: Transaction event listener: DONE: DONE ->
2018-08-24 13:10:28.722 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: listening == true, frequentlyListening == false, awake == false
2018-08-24 13:10:28.722 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: – To notify – COMPLETE
2018-08-24 13:10:28.723 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction Response Complete – 617 –
2018-08-24 13:10:28.724 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 44: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1153fd
2018-08-24 13:10:28.725 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 44: Node Init transaction completed with response COMPLETE
2018-08-24 13:10:28.724 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 06 00 46 0C 01 7D CF
2018-08-24 13:10:28.726 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 44: Node advancer - advancing to DELETE_SUC_ROUTES
2018-08-24 13:10:28.727 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 06 00 46 0C 01 7D CF
2018-08-24 13:10:28.727 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 44: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2018-08-24 13:10:28.728 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 44: Node advancer is deleting SUC return route.
2018-08-24 13:10:28.729 [DEBUG] [age.DeleteSucReturnRouteMessageClass] - NODE 44: Deleting SUC return routes
2018-08-24 13:10:28.729 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2018-08-24 13:10:28.730 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2018-08-24 13:10:28.731 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 620: Transaction Start type AssignReturnRoute
2018-08-24 13:10:28.731 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-08-24 13:10:28.732 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-08-24 13:10:28.733 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-08-24 13:10:28.733 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 44: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1fcc108
2018-08-24 13:10:28.735 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 44: Adding to device queue
2018-08-24 13:10:28.736 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 44: Added to queue - size 1
2018-08-24 13:10:28.736 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 620: [WAIT_RESPONSE] requiresResponse=true callback: 125
2018-08-24 13:10:28.737 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2018-08-24 13:10:28.738 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-08-24 13:10:28.742 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 46 01 BD
2018-08-24 13:10:28.744 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AssignReturnRoute[70], type=Response[1], dest=255, callback=0, payload=01
2018-08-24 13:10:28.745 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=AssignReturnRoute[70], type=Response[1], dest=255, callback=0, payload=01
2018-08-24 13:10:28.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AssignReturnRoute[70], type=Response[1], dest=255, callback=0, payload=01
2018-08-24 13:10:28.749 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 620: [WAIT_RESPONSE] requiresResponse=true callback: 125
2018-08-24 13:10:28.751 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-08-24 13:10:28.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 620: [WAIT_RESPONSE] requiresResponse=true callback: 125
2018-08-24 13:10:28.754 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AssignReturnRoute[70], type=Response[1], dest=255, callback=0, payload=01
2018-08-24 13:10:28.756 [DEBUG] [essage.AssignReturnRouteMessageClass] - NODE 12: Got AssignReturnRoute response.
2018-08-24 13:10:28.758 [DEBUG] [essage.AssignReturnRouteMessageClass] - NODE 12: AssignReturnRoute command started.
2018-08-24 13:10:28.760 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 620: Advanced to WAIT_REQUEST
2018-08-24 13:10:28.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: TID 620: Transaction not completed
2018-08-24 13:10:28.763 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-08-24 13:10:28.989 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 48 7A 23 EB
2018-08-24 13:10:28.990 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=RequestNodeNeighborUpdate[72], type=Request[0], dest=35, callback=122, payload=7A 23
2018-08-24 13:10:28.992 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=RequestNodeNeighborUpdate[72], type=Request[0], dest=35, callback=122, payload=7A 23
2018-08-24 13:10:28.994 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=RequestNodeNeighborUpdate[72], type=Request[0], dest=35, callback=122, payload=7A 23
2018-08-24 13:10:28.996 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 620: [WAIT_REQUEST] requiresResponse=true callback: 125
2018-08-24 13:10:28.997 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-08-24 13:10:28.999 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 620: [WAIT_REQUEST] requiresResponse=true callback: 125
2018-08-24 13:10:29.001 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 620: (Callback 125)
2018-08-24 13:10:29.003 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - NO callback match! (125 <> 122)
2018-08-24 13:10:29.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ****************** Transaction not correlated
2018-08-24 13:10:29.007 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=RequestNodeNeighborUpdate[72], type=Request[0], dest=35, callback=122, payload=7A 23
2018-08-24 13:10:29.008 [DEBUG] [equestNodeNeighborUpdateMessageClass] - NodeNeighborUpdate request without transaction
2018-08-24 13:10:29.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-08-24 13:10:29.224 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 25: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@226dc0
2018-08-24 13:10:29.226 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 25: Adding to device queue
2018-08-24 13:10:29.228 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 25: Added to queue - size 2
2018-08-24 13:10:29.599 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 46 7D 00 C1
2018-08-24 13:10:29.600 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AssignReturnRoute[70], type=Request[0], dest=0, callback=125, payload=7D 00
2018-08-24 13:10:29.602 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=AssignReturnRoute[70], type=Request[0], dest=0, callback=125, payload=7D 00
2018-08-24 13:10:29.605 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AssignReturnRoute[70], type=Request[0], dest=0, callback=125, payload=7D 00
2018-08-24 13:10:29.606 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 620: [WAIT_REQUEST] requiresResponse=true callback: 125
2018-08-24 13:10:29.607 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-08-24 13:10:29.609 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 620: [WAIT_REQUEST] requiresResponse=true callback: 125
2018-08-24 13:10:29.610 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 620: (Callback 125)
2018-08-24 13:10:29.611 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2018-08-24 13:10:29.613 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 620: callback 125