I don’t understand this. Why the bulb looks like online, but I cannot control it?
This is log from manual heal:
2019-02-02 22:30:44.679 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-02-02 22:30:44.681 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:30:44.683 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-02-02 22:32:45.914 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Configuration update received
2019-02-02 22:32:45.920 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Configuration update set action_heal to true (Boolean)
2019-02-02 22:32:45.922 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Starting heal on node!
2019-02-02 22:32:45.924 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Starting network mesh heal.
2019-02-02 22:32:45.926 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Starting initialisation from HEAL_START
2019-02-02 22:32:45.929 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer - advancing to HEAL_START
2019-02-02 22:32:45.931 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2019-02-02 22:32:45.935 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@e52f10
2019-02-02 22:32:45.935 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer - advancing to UPDATE_NEIGHBORS
2019-02-02 22:32:45.938 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2019-02-02 22:32:45.940 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer: UPDATE_NEIGHBORS - updating neighbor list
2019-02-02 22:32:45.945 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:e90a5045:node9' has been updated.
2019-02-02 22:32:45.945 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@265741
2019-02-02 22:32:45.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Adding to device queue
2019-02-02 22:32:45.954 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Added 418 to queue - size 3
2019-02-02 22:32:45.957 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-02-02 22:32:45.963 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 48 09 69 D2
2019-02-02 22:32:45.965 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-02-02 22:32:45.977 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 418: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 105
2019-02-02 22:32:45.978 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-02-02 22:32:45.984 [vent.ItemStateChangedEvent] - ZWave_FramesAcknowledged changed from 689 to 690
2019-02-02 22:32:45.986 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-02-02 22:32:45.990 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-02-02 22:32:45.992 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 418: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 105
2019-02-02 22:32:45.995 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-02-02 22:32:45.997 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:32:45.998 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-02-02 22:32:46.014 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 48 69 21 FA
2019-02-02 22:32:46.019 [vent.ItemStateChangedEvent] - ZWave_StartFrames changed from 3560 to 3561
2019-02-02 22:32:46.018 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=RequestNodeNeighborUpdate[72], type=Request[0], dest=33, callback=105, payload=69 21
2019-02-02 22:32:46.022 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=RequestNodeNeighborUpdate[72], type=Request[0], dest=33, callback=105, payload=69 21
2019-02-02 22:32:46.024 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 418: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 105
2019-02-02 22:32:46.025 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-02-02 22:32:46.026 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 418: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 105
2019-02-02 22:32:46.027 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 418: (Callback 105)
2019-02-02 22:32:46.029 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-02-02 22:32:46.030 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 418: callback 105
2019-02-02 22:32:46.032 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=RequestNodeNeighborUpdate[72], type=Request[0], dest=33, callback=105, payload=69 21
2019-02-02 22:32:46.036 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 418: Advanced to DONE
2019-02-02 22:32:46.037 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Response processed after 60ms
2019-02-02 22:32:46.038 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: TID 418: Transaction completed
2019-02-02 22:32:46.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: notifyTransactionResponse TID:418 DONE
2019-02-02 22:32:46.041 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-02-02 22:32:46.042 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:32:46.042 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 418: Transaction event listener: DONE: DONE ->
2019-02-02 22:32:46.044 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-02-02 22:32:46.048 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@de3c31
2019-02-02 22:32:46.050 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node Init transaction completed with response COMPLETE
2019-02-02 22:32:46.051 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer - advancing to GET_NEIGHBORS
2019-02-02 22:32:46.053 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2019-02-02 22:32:46.055 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer: GET_NEIGHBORS - get RoutingInfo
2019-02-02 22:32:46.058 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1dcb68e
2019-02-02 22:32:46.061 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 419 to queue - size 1
2019-02-02 22:32:46.062 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-02-02 22:32:46.065 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 07 00 80 09 00 00 03 72
2019-02-02 22:32:46.068 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-02-02 22:32:46.070 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-02-02 22:32:46.072 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 419: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-02-02 22:32:46.073 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-02-02 22:32:46.077 [vent.ItemStateChangedEvent] - ZWave_FramesAcknowledged changed from 690 to 691
2019-02-02 22:32:46.078 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-02-02 22:32:46.080 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 419: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-02-02 22:32:46.082 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-02-02 22:32:46.084 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:32:46.085 [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
2019-02-02 22:32:46.087 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-02-02 22:32:46.092 [vent.ItemStateChangedEvent] - ZWave_StartFrames changed from 3561 to 3562
2019-02-02 22:32:46.096 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetRoutingInfo[128], type=Response[1], 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
2019-02-02 22:32:46.100 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetRoutingInfo[128], type=Response[1], 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
2019-02-02 22:32:46.101 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 419: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-02-02 22:32:46.103 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-02-02 22:32:46.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 419: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-02-02 22:32:46.109 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetRoutingInfo[128], type=Response[1], 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
2019-02-02 22:32:46.115 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveNetworkEvent
2019-02-02 22:32:46.117 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 419: Transaction COMPLETED
2019-02-02 22:32:46.118 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 48ms
2019-02-02 22:32:46.120 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 419: Transaction completed
2019-02-02 22:32:46.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:419 DONE
2019-02-02 22:32:46.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:32:46.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 419: Transaction event listener: DONE: DONE ->
2019-02-02 22:32:46.133 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1de79eb
2019-02-02 22:32:46.126 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-02-02 22:32:46.135 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node Init transaction completed with response COMPLETE
2019-02-02 22:32:46.136 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer - advancing to DELETE_SUC_ROUTES
2019-02-02 22:32:46.138 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2019-02-02 22:32:46.140 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer is deleting SUC return route.
2019-02-02 22:32:46.144 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@f576f1
2019-02-02 22:32:46.145 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Adding to device queue
2019-02-02 22:32:46.146 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Added 420 to queue - size 3
2019-02-02 22:32:46.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-02-02 22:32:46.152 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 55 09 6A CC
2019-02-02 22:32:46.154 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-02-02 22:32:46.155 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 420: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 106
2019-02-02 22:32:46.155 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-02-02 22:32:46.157 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-02-02 22:32:46.160 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-02-02 22:32:46.161 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 420: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 106
2019-02-02 22:32:46.161 [vent.ItemStateChangedEvent] - ZWave_FramesAcknowledged changed from 691 to 692
2019-02-02 22:32:46.162 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-02-02 22:32:46.164 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:32:46.168 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-02-02 22:32:46.169 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 55 01 AE
2019-02-02 22:32:46.172 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=DeleteSUCReturnRoute[85], type=Response[1], dest=255, callback=0, payload=01
2019-02-02 22:32:46.172 [vent.ItemStateChangedEvent] - ZWave_StartFrames changed from 3562 to 3563
2019-02-02 22:32:46.174 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=DeleteSUCReturnRoute[85], type=Response[1], dest=255, callback=0, payload=01
2019-02-02 22:32:46.176 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 420: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 106
2019-02-02 22:32:46.178 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-02-02 22:32:46.180 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 420: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 106
2019-02-02 22:32:46.182 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=DeleteSUCReturnRoute[85], type=Response[1], dest=255, callback=0, payload=01
2019-02-02 22:32:46.187 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 420: Advanced to WAIT_REQUEST
2019-02-02 22:32:46.188 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: TID 420: Transaction not completed
2019-02-02 22:32:46.189 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:32:46.191 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-02-02 22:32:46.255 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 55 6A 01 C4
2019-02-02 22:32:46.258 [vent.ItemStateChangedEvent] - ZWave_StartFrames changed from 3563 to 3564
2019-02-02 22:32:46.258 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=DeleteSUCReturnRoute[85], type=Request[0], dest=1, callback=106, payload=6A 01
2019-02-02 22:32:46.260 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=DeleteSUCReturnRoute[85], type=Request[0], dest=1, callback=106, payload=6A 01
2019-02-02 22:32:46.263 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 420: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 106
2019-02-02 22:32:46.265 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-02-02 22:32:46.266 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 420: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 106
2019-02-02 22:32:46.268 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 420: (Callback 106)
2019-02-02 22:32:46.270 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-02-02 22:32:46.271 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 420: callback 106
2019-02-02 22:32:46.273 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=DeleteSUCReturnRoute[85], type=Request[0], dest=1, callback=106, payload=6A 01
2019-02-02 22:32:46.279 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveNetworkEvent
2019-02-02 22:32:46.280 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 420: Transaction COMPLETED
2019-02-02 22:32:46.282 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Response processed after 127ms
2019-02-02 22:32:46.283 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: TID 420: Transaction completed
2019-02-02 22:32:46.285 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: notifyTransactionResponse TID:420 DONE
2019-02-02 22:32:46.287 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-02-02 22:32:46.287 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 420: Transaction event listener: DONE: DONE ->
2019-02-02 22:32:46.290 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@11de72a
2019-02-02 22:32:46.290 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:32:46.295 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-02-02 22:32:46.295 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node Init transaction completed with response COMPLETE
2019-02-02 22:32:46.297 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer - advancing to SUC_ROUTE
2019-02-02 22:32:46.298 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2019-02-02 22:32:46.300 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer is setting SUC route.
2019-02-02 22:32:46.303 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1f349c1
2019-02-02 22:32:46.304 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Adding to device queue
2019-02-02 22:32:46.306 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Added 421 to queue - size 3
2019-02-02 22:32:46.307 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-02-02 22:32:46.311 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 51 09 6B C9
2019-02-02 22:32:46.313 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-02-02 22:32:46.315 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 421: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 107
2019-02-02 22:32:46.316 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-02-02 22:32:46.317 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-02-02 22:32:46.319 [vent.ItemStateChangedEvent] - ZWave_FramesAcknowledged changed from 692 to 693
2019-02-02 22:32:46.322 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-02-02 22:32:46.324 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 421: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 107
2019-02-02 22:32:46.326 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-02-02 22:32:46.328 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:32:46.330 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 51 01 AA
2019-02-02 22:32:46.330 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-02-02 22:32:46.333 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AssignSucReturnRoute[81], type=Response[1], dest=255, callback=0, payload=01
2019-02-02 22:32:46.333 [vent.ItemStateChangedEvent] - ZWave_StartFrames changed from 3564 to 3565
2019-02-02 22:32:46.335 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AssignSucReturnRoute[81], type=Response[1], dest=255, callback=0, payload=01
2019-02-02 22:32:46.338 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 421: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 107
2019-02-02 22:32:46.340 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-02-02 22:32:46.342 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 421: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 107
2019-02-02 22:32:46.343 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AssignSucReturnRoute[81], type=Response[1], dest=255, callback=0, payload=01
2019-02-02 22:32:46.348 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 421: Advanced to WAIT_REQUEST
2019-02-02 22:32:46.349 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: TID 421: Transaction not completed
2019-02-02 22:32:46.351 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:32:46.352 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-02-02 22:32:46.481 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 51 6B 01 C1
2019-02-02 22:32:46.485 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AssignSucReturnRoute[81], type=Request[0], dest=1, callback=107, payload=6B 01
2019-02-02 22:32:46.484 [vent.ItemStateChangedEvent] - ZWave_StartFrames changed from 3565 to 3566
2019-02-02 22:32:46.491 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AssignSucReturnRoute[81], type=Request[0], dest=1, callback=107, payload=6B 01
2019-02-02 22:32:46.492 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 421: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 107
2019-02-02 22:32:46.494 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-02-02 22:32:46.495 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 421: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 107
2019-02-02 22:32:46.497 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 421: (Callback 107)
2019-02-02 22:32:46.498 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-02-02 22:32:46.500 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 421: callback 107
2019-02-02 22:32:46.501 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AssignSucReturnRoute[81], type=Request[0], dest=1, callback=107, payload=6B 01
2019-02-02 22:32:46.504 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 421: Transaction COMPLETED
2019-02-02 22:32:46.507 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveNetworkEvent
2019-02-02 22:32:46.509 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Response processed after 195ms
2019-02-02 22:32:46.510 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: TID 421: Transaction completed
2019-02-02 22:32:46.511 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: notifyTransactionResponse TID:421 DONE
2019-02-02 22:32:46.513 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-02-02 22:32:46.514 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:32:46.514 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 421: Transaction event listener: DONE: DONE ->
2019-02-02 22:32:46.515 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-02-02 22:32:46.520 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1ec6975
2019-02-02 22:32:46.522 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node Init transaction completed with response COMPLETE
2019-02-02 22:32:46.523 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer - advancing to DELETE_ROUTES
2019-02-02 22:32:46.524 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2019-02-02 22:32:46.526 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Generate return routes list
2019-02-02 22:32:46.528 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer is deleting return routes.
2019-02-02 22:32:46.531 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@d7c4c7
2019-02-02 22:32:46.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Adding to device queue
2019-02-02 22:32:46.535 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Added 422 to queue - size 3
2019-02-02 22:32:46.537 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-02-02 22:32:46.541 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 47 09 6C D8
2019-02-02 22:32:46.543 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-02-02 22:32:46.545 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 422: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 108
2019-02-02 22:32:46.549 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-02-02 22:32:46.550 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-02-02 22:32:46.553 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-02-02 22:32:46.554 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 422: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 108
2019-02-02 22:32:46.555 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-02-02 22:32:46.559 [vent.ItemStateChangedEvent] - ZWave_FramesAcknowledged changed from 693 to 694
2019-02-02 22:32:46.558 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:32:46.562 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-02-02 22:32:46.565 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 47 01 BC
2019-02-02 22:32:46.568 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=DeleteReturnRoute[71], type=Response[1], dest=255, callback=0, payload=01
2019-02-02 22:32:46.569 [vent.ItemStateChangedEvent] - ZWave_StartFrames changed from 3566 to 3567
2019-02-02 22:32:46.570 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=DeleteReturnRoute[71], type=Response[1], dest=255, callback=0, payload=01
2019-02-02 22:32:46.571 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 422: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 108
2019-02-02 22:32:46.572 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-02-02 22:32:46.574 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 422: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 108
2019-02-02 22:32:46.576 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=DeleteReturnRoute[71], type=Response[1], dest=255, callback=0, payload=01
2019-02-02 22:32:46.580 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 422: Advanced to WAIT_REQUEST
2019-02-02 22:32:46.581 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: TID 422: Transaction not completed
2019-02-02 22:32:46.583 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:32:46.585 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-02-02 22:32:46.718 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 47 6C 01 D0
2019-02-02 22:32:46.722 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=DeleteReturnRoute[71], type=Request[0], dest=1, callback=108, payload=6C 01
2019-02-02 22:32:46.724 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=DeleteReturnRoute[71], type=Request[0], dest=1, callback=108, payload=6C 01
2019-02-02 22:32:46.723 [vent.ItemStateChangedEvent] - ZWave_StartFrames changed from 3567 to 3568
2019-02-02 22:32:46.726 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 422: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 108
2019-02-02 22:32:46.728 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-02-02 22:32:46.729 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 422: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 108
2019-02-02 22:32:46.731 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 422: (Callback 108)
2019-02-02 22:32:46.732 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-02-02 22:32:46.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 422: callback 108
2019-02-02 22:32:46.736 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=DeleteReturnRoute[71], type=Request[0], dest=1, callback=108, payload=6C 01
2019-02-02 22:32:46.741 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveNetworkEvent
2019-02-02 22:32:46.743 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 422: Transaction COMPLETED
2019-02-02 22:32:46.745 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Response processed after 200ms
2019-02-02 22:32:46.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: TID 422: Transaction completed
2019-02-02 22:32:46.749 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: notifyTransactionResponse TID:422 DONE
2019-02-02 22:32:46.756 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-02-02 22:32:46.756 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 422: Transaction event listener: DONE: DONE ->
2019-02-02 22:32:46.758 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:32:46.759 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1949c0
2019-02-02 22:32:46.759 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-02-02 22:32:46.761 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node Init transaction completed with response COMPLETE
2019-02-02 22:32:46.762 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer - advancing to RETURN_ROUTES
2019-02-02 22:32:46.764 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2019-02-02 22:32:46.766 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Generate return routes list
2019-02-02 22:32:46.773 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Adding return route to 3
2019-02-02 22:32:46.776 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1bdb683
2019-02-02 22:32:46.777 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Adding to device queue
2019-02-02 22:32:46.779 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Added 423 to queue - size 3
2019-02-02 22:32:46.781 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-02-02 22:32:46.785 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 06 00 46 09 03 6D D8
2019-02-02 22:32:46.788 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-02-02 22:32:46.789 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-02-02 22:32:46.791 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-02-02 22:32:46.791 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 423: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 109
2019-02-02 22:32:46.797 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-02-02 22:32:46.800 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 423: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 109
2019-02-02 22:32:46.801 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-02-02 22:32:46.798 [vent.ItemStateChangedEvent] - ZWave_FramesAcknowledged changed from 694 to 695
2019-02-02 22:32:46.805 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 46 01 BD
2019-02-02 22:32:46.811 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AssignReturnRoute[70], type=Response[1], dest=255, callback=0, payload=01
2019-02-02 22:32:46.812 [vent.ItemStateChangedEvent] - ZWave_StartFrames changed from 3568 to 3569
2019-02-02 22:32:46.814 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AssignReturnRoute[70], type=Response[1], dest=255, callback=0, payload=01
2019-02-02 22:32:46.817 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 423: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 109
2019-02-02 22:32:46.818 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-02-02 22:32:46.820 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 423: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 109
2019-02-02 22:32:46.822 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AssignReturnRoute[70], type=Response[1], dest=255, callback=0, payload=01
2019-02-02 22:32:46.828 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 423: Advanced to WAIT_REQUEST
2019-02-02 22:32:46.829 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: TID 423: Transaction not completed
2019-02-02 22:32:46.831 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:32:46.832 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-02-02 22:32:46.907 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 46 6D 01 D0
2019-02-02 22:32:46.912 [vent.ItemStateChangedEvent] - ZWave_StartFrames changed from 3569 to 3570
2019-02-02 22:32:46.911 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AssignReturnRoute[70], type=Request[0], dest=1, callback=109, payload=6D 01
2019-02-02 22:32:46.914 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AssignReturnRoute[70], type=Request[0], dest=1, callback=109, payload=6D 01
2019-02-02 22:32:46.916 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 423: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 109
2019-02-02 22:32:46.918 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-02-02 22:32:46.919 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 423: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 109
2019-02-02 22:32:46.920 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 423: (Callback 109)
2019-02-02 22:32:46.922 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-02-02 22:32:46.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 423: callback 109
2019-02-02 22:32:46.925 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AssignReturnRoute[70], type=Request[0], dest=1, callback=109, payload=6D 01
2019-02-02 22:32:46.929 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveNetworkEvent
2019-02-02 22:32:46.931 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 423: Transaction COMPLETED
2019-02-02 22:32:46.932 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Response processed after 142ms
2019-02-02 22:32:46.934 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: TID 423: Transaction completed
2019-02-02 22:32:46.935 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: notifyTransactionResponse TID:423 DONE
2019-02-02 22:32:46.937 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-02-02 22:32:46.937 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 423: Transaction event listener: DONE: DONE ->
2019-02-02 22:32:46.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:32:46.940 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1f4d0c0
2019-02-02 22:32:46.940 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-02-02 22:32:46.941 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node Init transaction completed with response COMPLETE
2019-02-02 22:32:46.946 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer - advancing to HEAL_END
2019-02-02 22:32:46.947 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2019-02-02 22:32:46.950 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@b60525
2019-02-02 22:32:46.958 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 9: Serializing to file /var/lib/openhab2/zwave/network_f0ee85c1__node_9.xml
2019-02-02 22:32:46.960 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:e90a5045:node9' has been updated.
2019-02-02 22:32:47.044 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer - advancing to DONE
2019-02-02 22:32:47.046 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2019-02-02 22:32:47.051 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 9: Serializing to file /var/lib/openhab2/zwave/network_f0ee85c1__node_9.xml
2019-02-02 22:32:54.691 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 48 69 23 F8
2019-02-02 22:32:54.695 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=RequestNodeNeighborUpdate[72], type=Request[0], dest=35, callback=105, payload=69 23
2019-02-02 22:32:54.695 [vent.ItemStateChangedEvent] - ZWave_StartFrames changed from 3570 to 3571
2019-02-02 22:32:54.698 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=RequestNodeNeighborUpdate[72], type=Request[0], dest=35, callback=105, payload=69 23
2019-02-02 22:32:54.700 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-02-02 22:32:54.702 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2019-02-02 22:32:54.705 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2019-02-02 22:32:54.706 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=RequestNodeNeighborUpdate[72], type=Request[0], dest=35, callback=105, payload=69 23
2019-02-02 22:32:54.709 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-02-02 22:32:54.711 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.![node9|690x241]