ZWave exclusion / inclusion - wrong device

smhaller · March 13, 2019, 1:57pm

Dear ZWave gurus and users
Dear @chris

Due to recent issues with the ZWave exclusion and inclusion procedure. I would like to add some notes and wonder if there are any other such experiences.

Yesterday in the process of configuring one Qubino node, I needed to exlude it and include it later on due to the procedure. The first node I’ve done went fine (Old node 6, new node 10), so far so fine. I’ve continued with the next one (Node 5) still wall mounted.

Now the fun starts! One node was noted as excluded, but not 5 as I would have expected, but 10, so the one that I freshly included just minutes ago. Sadly the log was not in DEBUG mode that time. But no worries it comes better.

Today - I removed the node 5 device and placed it to my new configuration workdesk

1.5 meters (max 2) from the controller.

I did the same thing again, set ZWave to exclusion via habmin. Went down to cellar and gave the device three clicks in 3 seconds to initiate exlusion. Guess what… again node 10 was excluded.

instead of node 5.

This was the killing moment. I had no clue why. I got frustrated as I was fighting with this bloody configuration steps for several days now.

I decided to run the work around.

Stopped openHAB clear cache and tmp.
Started domoticz environment. Got node 10 still included there
Started exlusion mode on domoticz / ozw
Went to the device to initiate exlusion
Back at groundlevel domoticz reported node 5 excluded.
Did the same procedure for node 8, which also need an exclude / include
Restarted domoticz to check if everything fine afterwards. And looked promising.
Stopped domoticz
Removed the old node xml files from /var/lib/openhab2/zwave
Started openHAB
Nodes 10,11,12 found and added

I don’t know what the binding is doing, but there is something not in that way as I would expect it.

Here is: ZWave inclusion log

Regards
Stefan

chris · March 13, 2019, 2:07pm

The binding doesn’t do anything - it simply puts the controller into exclusion mode. The controller does the exclusion and it should exclude what ever device you select to exclude by pressing a button on the device.

I see nothing wrong here.

smhaller · March 13, 2019, 2:16pm

Hi Chris

This is exactly what I did. I pushed the button (i.e. three click sequence) for exclusion as described by manual for node 5, but node 10 got the exlusion so not the one I operated with.

Cheers
Stefan

chris · March 13, 2019, 3:16pm

Well, as you can see in the log - this is what is reported by the controller, so I can’t really see how the binding made it do that can you?

chris · March 13, 2019, 3:26pm

On looking at this further, it looks like there should be NO device removed from the controller in the log you show here (I can’t actually view the text log so I’m just going on the image). If a node is removed, there should have been another message before the DONE, but if it is removed from the controller, then it is solely down to the controller to do this - the binding cannot do this even if it wanted to if the device is still working.

smhaller · March 13, 2019, 3:50pm

Following is directly from the log:

2019-03-13 07:44:37.585 [DEBUG] [serialmessage.RemoveNodeMessageClass] - Remove Node: Done.
2019-03-13 07:44:37.586 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveInclusionEvent
2019-03-13 07:44:37.597 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state ExcludeFail, new event ExcludeDone
2019-03-13 07:44:37.597 [DEBUG] [serialmessage.RemoveNodeMessageClass] - Ending EXCLUSION mode.

In the log it states exclusion failed, but it received one and I saw in habmin, that the node 10 was flagged excluded. Sadly I didn’t make a screenshot of it.

And not node 5 as should have been. As I stated in the first message this happened twice. the same way. It was effectivly not excluded from the controller. But it does not work as I would expect it to do.
Or something else of what I currently not think of.

Cheers
Stefan

chris · March 13, 2019, 5:01pm

So, I can only restate what I said earlier. The exclusion is performed by the controller. All the binding does is to put the device into exclude mode. Here, I wouldn’t have expected any exclusion at all since there is no ExcludeSlaveFound message, so there might be a bug here in the binding.

However, the fact that the controller did not find node 5 to exclude is solely an issue between the controller and the device. The binding cannot exclude specific devices like this.

Can you provide the full exclusion log - not just the last message. It started 30 seconds before this…

No - it doesn’t. The of states that the internal state machine was in ExcludeFailed state - that is actually normal at the end of the exclusion.

smhaller · March 13, 2019, 8:10pm

Hey Chris

Sure I can provide the whole part. I just would like to understand what happened exactly and what I wonder more, is why it happened twice that way.

2019-03-13 07:43:07.431 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start exclusion
2019-03-13 07:43:07.434 [DEBUG] [serialmessage.RemoveNodeMessageClass] - Setting controller into EXCLUSION mode.
2019-03-13 07:43:07.434 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 275 to queue - size 1
2019-03-13 07:43:07.434 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-13 07:43:07.434 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4B 01 26 96
2019-03-13 07:43:07.435 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4B 01 26 96
2019-03-13 07:43:07.435 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-13 07:43:07.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 275: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 38
2019-03-13 07:43:07.437 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-13 07:43:07.437 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-13 07:43:07.439 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-13 07:43:07.439 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 275: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 38
2019-03-13 07:43:07.439 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-13 07:43:07.439 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-13 07:43:07.439 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-13 07:43:07.439 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4B 26 01 00 00 94
2019-03-13 07:43:07.440 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=RemoveNodeFromNetwork[75], type=Request[0], dest=1, callback=38, payload=26 01 00 00
2019-03-13 07:43:07.441 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=RemoveNodeFromNetwork[75], type=Request[0], dest=1, callback=38, payload=26 01 00 00
2019-03-13 07:43:07.441 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 275: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 38
2019-03-13 07:43:07.441 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-03-13 07:43:07.441 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 275: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 38
2019-03-13 07:43:07.441 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 275: (Callback 38)
2019-03-13 07:43:07.441 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-03-13 07:43:07.441 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 275: callback 38
2019-03-13 07:43:07.441 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=RemoveNodeFromNetwork[75], type=Request[0], dest=1, callback=38, payload=26 01 00 00
2019-03-13 07:43:07.442 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state ExcludeSent, new event ExcludeStart
2019-03-13 07:43:07.442 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 275: Transaction COMPLETED
2019-03-13 07:43:07.442 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 7ms
2019-03-13 07:43:07.442 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 275: Transaction completed
2019-03-13 07:43:07.442 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:275 DONE
2019-03-13 07:43:07.444 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-13 07:43:07.444 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-13 07:43:25.613 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 10 02 03 25 03 FF 3A
2019-03-13 07:43:25.614 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 03 25 03 FF
2019-03-13 07:43:25.614 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 03 25 03 FF
2019-03-13 07:43:25.614 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-13 07:43:25.614 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:DONE)
2019-03-13 07:43:25.614 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2019-03-13 07:43:25.614 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_SWITCH_BINARY, endpoint 0
2019-03-13 07:43:25.614 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2019-03-13 07:43:25.614 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_SWITCH_BINARY V1 SWITCH_BINARY_REPORT
2019-03-13 07:43:25.614 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 2: Switch Binary report, value = 255
2019-03-13 07:43:25.614 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2019-03-13 07:43:25.614 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SWITCH_BINARY, value=255
2019-03-13 07:43:25.614 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:2f18a74d:node2:switch_binary to ON [OnOffType]
2019-03-13 07:43:25.615 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1.
2019-03-13 07:43:25.615 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@11686102.
2019-03-13 07:43:25.615 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:25.615 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:25.615 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-13 07:43:25.615 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-13 07:43:25.885 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 10 02 03 25 03 FF 3A
2019-03-13 07:43:25.886 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 03 25 03 FF
2019-03-13 07:43:25.886 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 03 25 03 FF
2019-03-13 07:43:25.886 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-13 07:43:25.886 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:DONE)
2019-03-13 07:43:25.886 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2019-03-13 07:43:25.886 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_SWITCH_BINARY, endpoint 0
2019-03-13 07:43:25.886 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2019-03-13 07:43:25.886 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_SWITCH_BINARY V1 SWITCH_BINARY_REPORT
2019-03-13 07:43:25.886 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 2: Switch Binary report, value = 255
2019-03-13 07:43:25.887 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2019-03-13 07:43:25.887 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SWITCH_BINARY, value=255
2019-03-13 07:43:25.887 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:2f18a74d:node2:switch_binary to ON [OnOffType]
2019-03-13 07:43:25.887 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1.
2019-03-13 07:43:25.887 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@6d156eab.
2019-03-13 07:43:25.887 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:25.887 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:25.887 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-13 07:43:25.887 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-13 07:43:26.227 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 10 02 03 25 03 FF 3A
2019-03-13 07:43:26.228 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 03 25 03 FF
2019-03-13 07:43:26.228 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 03 25 03 FF
2019-03-13 07:43:26.228 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-13 07:43:26.228 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:DONE)
2019-03-13 07:43:26.228 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2019-03-13 07:43:26.228 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_SWITCH_BINARY, endpoint 0
2019-03-13 07:43:26.228 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2019-03-13 07:43:26.228 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_SWITCH_BINARY V1 SWITCH_BINARY_REPORT
2019-03-13 07:43:26.228 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 2: Switch Binary report, value = 255
2019-03-13 07:43:26.228 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2019-03-13 07:43:26.228 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SWITCH_BINARY, value=255
2019-03-13 07:43:26.229 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:2f18a74d:node2:switch_binary to ON [OnOffType]
2019-03-13 07:43:26.229 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1.
2019-03-13 07:43:26.229 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@56703d78.
2019-03-13 07:43:26.229 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:26.229 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:26.229 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-13 07:43:26.229 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-13 07:43:26.650 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 10 02 03 20 01 FF 3D
2019-03-13 07:43:26.651 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 03 20 01 FF
2019-03-13 07:43:26.651 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 03 20 01 FF
2019-03-13 07:43:26.651 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-13 07:43:26.651 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:DONE)
2019-03-13 07:43:26.651 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2019-03-13 07:43:26.651 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_BASIC, endpoint 0
2019-03-13 07:43:26.651 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2019-03-13 07:43:26.651 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_BASIC V1 BASIC_SET
2019-03-13 07:43:26.651 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 2: Basic report, value = 255
2019-03-13 07:43:26.651 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2019-03-13 07:43:26.651 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_BASIC, value=255
2019-03-13 07:43:26.652 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:2f18a74d:node2:switch_binary to ON [OnOffType]
2019-03-13 07:43:26.652 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1.
2019-03-13 07:43:26.652 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@2d48415e.
2019-03-13 07:43:26.652 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:26.652 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:26.652 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-13 07:43:26.652 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-13 07:43:27.108 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 10 02 03 20 01 FF 3D
2019-03-13 07:43:27.109 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 03 20 01 FF
2019-03-13 07:43:27.109 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 03 20 01 FF
2019-03-13 07:43:27.109 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-13 07:43:27.109 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:DONE)
2019-03-13 07:43:27.109 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2019-03-13 07:43:27.109 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_BASIC, endpoint 0
2019-03-13 07:43:27.109 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2019-03-13 07:43:27.109 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_BASIC V1 BASIC_SET
2019-03-13 07:43:27.109 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 2: Basic report, value = 255
2019-03-13 07:43:27.109 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2019-03-13 07:43:27.109 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_BASIC, value=255
2019-03-13 07:43:27.110 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:2f18a74d:node2:switch_binary to ON [OnOffType]
2019-03-13 07:43:27.110 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1.
2019-03-13 07:43:27.110 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@7ffa5584.
2019-03-13 07:43:27.110 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:27.110 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:27.110 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-13 07:43:27.110 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-13 07:43:27.136 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 10 02 03 20 01 FF 3D
2019-03-13 07:43:27.137 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 03 20 01 FF
2019-03-13 07:43:27.137 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 03 20 01 FF
2019-03-13 07:43:27.137 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-13 07:43:27.137 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:DONE)
2019-03-13 07:43:27.137 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2019-03-13 07:43:27.137 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_BASIC, endpoint 0
2019-03-13 07:43:27.137 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2019-03-13 07:43:27.137 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_BASIC V1 BASIC_SET
2019-03-13 07:43:27.137 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 2: Basic report, value = 255
2019-03-13 07:43:27.137 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2019-03-13 07:43:27.138 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_BASIC, value=255
2019-03-13 07:43:27.138 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:2f18a74d:node2:switch_binary to ON [OnOffType]
2019-03-13 07:43:27.138 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1.
2019-03-13 07:43:27.138 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@395c1ce6.
2019-03-13 07:43:27.138 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:27.138 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:27.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-13 07:43:27.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-13 07:43:31.968 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 10 08 0A 32 02 21 34 00 00 00 00 00 00 DC
2019-03-13 07:43:31.968 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=16, payload=10 08 0A 32 02 21 34 00 00 00 00 00 00
2019-03-13 07:43:31.969 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=16, payload=10 08 0A 32 02 21 34 00 00 00 00 00 00
2019-03-13 07:43:31.969 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-13 07:43:31.969 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:SUC_ROUTE)
2019-03-13 07:43:31.969 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_METER, endpoint 0
2019-03-13 07:43:31.969 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
2019-03-13 07:43:31.969 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_METER V3 METER_REPORT
2019-03-13 07:43:31.969 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 8: Meter: Type=Electric(1), Scale=W(2), Value=0E+1
2019-03-13 07:43:31.969 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveMeterValueEvent
2019-03-13 07:43:31.969 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=0E+1
2019-03-13 07:43:31.969 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating channel state zwave:device:2f18a74d:node8:meter_watts to 0 [DecimalType]
2019-03-13 07:43:31.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2019-03-13 07:43:31.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@6e107d48.
2019-03-13 07:43:31.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:31.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:31.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-13 07:43:31.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-13 07:43:32.621 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 10 08 0A 32 02 21 34 00 00 00 00 00 00 DC
2019-03-13 07:43:32.621 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=16, payload=10 08 0A 32 02 21 34 00 00 00 00 00 00
2019-03-13 07:43:32.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=16, payload=10 08 0A 32 02 21 34 00 00 00 00 00 00
2019-03-13 07:43:32.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-13 07:43:32.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:SUC_ROUTE)
2019-03-13 07:43:32.622 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_METER, endpoint 0
2019-03-13 07:43:32.622 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
2019-03-13 07:43:32.622 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_METER V3 METER_REPORT
2019-03-13 07:43:32.622 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 8: Meter: Type=Electric(1), Scale=W(2), Value=0E+1
2019-03-13 07:43:32.622 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveMeterValueEvent
2019-03-13 07:43:32.622 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=0E+1
2019-03-13 07:43:32.622 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating channel state zwave:device:2f18a74d:node8:meter_watts to 0 [DecimalType]
2019-03-13 07:43:32.623 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2019-03-13 07:43:32.623 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@13d9365.
2019-03-13 07:43:32.623 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:32.623 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:32.623 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-13 07:43:32.623 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-13 07:43:32.717 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 10 08 0A 32 02 21 34 00 00 00 00 00 00 DC
2019-03-13 07:43:32.717 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=16, payload=10 08 0A 32 02 21 34 00 00 00 00 00 00
2019-03-13 07:43:32.718 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=16, payload=10 08 0A 32 02 21 34 00 00 00 00 00 00
2019-03-13 07:43:32.718 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-13 07:43:32.718 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:SUC_ROUTE)
2019-03-13 07:43:32.718 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Incoming command class COMMAND_CLASS_METER, endpoint 0
2019-03-13 07:43:32.718 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY not supported
2019-03-13 07:43:32.718 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 8: Received COMMAND_CLASS_METER V3 METER_REPORT
2019-03-13 07:43:32.718 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 8: Meter: Type=Electric(1), Scale=W(2), Value=0E+1
2019-03-13 07:43:32.718 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveMeterValueEvent
2019-03-13 07:43:32.718 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=0E+1
2019-03-13 07:43:32.718 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Updating channel state zwave:device:2f18a74d:node8:meter_watts to 0 [DecimalType]
2019-03-13 07:43:32.719 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2019-03-13 07:43:32.719 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@2c46a0b3.
2019-03-13 07:43:32.719 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:32.719 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:32.719 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-13 07:43:32.719 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-13 07:43:47.731 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 10 02 0A 32 02 21 34 00 00 01 70 00 00 A7
2019-03-13 07:43:47.732 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 0A 32 02 21 34 00 00 01 70 00 00
2019-03-13 07:43:47.732 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 0A 32 02 21 34 00 00 01 70 00 00
2019-03-13 07:43:47.732 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-13 07:43:47.732 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:DONE)
2019-03-13 07:43:47.732 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2019-03-13 07:43:47.733 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_METER, endpoint 0
2019-03-13 07:43:47.733 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2019-03-13 07:43:47.733 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_METER V3 METER_REPORT
2019-03-13 07:43:47.733 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 2: Meter: Type=Electric(1), Scale=W(2), Value=36.8
2019-03-13 07:43:47.733 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveMeterValueEvent
2019-03-13 07:43:47.733 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=36.8
2019-03-13 07:43:47.733 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:2f18a74d:node2:meter_watts to 36.8 [DecimalType]
2019-03-13 07:43:47.733 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1.
2019-03-13 07:43:47.733 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@752422f1.
2019-03-13 07:43:47.733 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:47.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:47.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-13 07:43:47.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-13 07:43:47.902 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 10 02 0A 32 02 21 34 00 00 01 70 00 00 A7
2019-03-13 07:43:47.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 0A 32 02 21 34 00 00 01 70 00 00
2019-03-13 07:43:47.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 0A 32 02 21 34 00 00 01 70 00 00
2019-03-13 07:43:47.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-13 07:43:47.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:DONE)
2019-03-13 07:43:47.903 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2019-03-13 07:43:47.903 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_METER, endpoint 0
2019-03-13 07:43:47.904 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2019-03-13 07:43:47.904 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_METER V3 METER_REPORT
2019-03-13 07:43:47.904 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 2: Meter: Type=Electric(1), Scale=W(2), Value=36.8
2019-03-13 07:43:47.904 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveMeterValueEvent
2019-03-13 07:43:47.904 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=36.8
2019-03-13 07:43:47.904 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:2f18a74d:node2:meter_watts to 36.8 [DecimalType]
2019-03-13 07:43:47.904 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1.
2019-03-13 07:43:47.904 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@18b3eb20.
2019-03-13 07:43:47.904 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:47.904 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:47.905 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-13 07:43:47.905 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-13 07:43:47.960 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 10 02 0A 32 02 21 34 00 00 01 70 00 00 A7
2019-03-13 07:43:47.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 0A 32 02 21 34 00 00 01 70 00 00
2019-03-13 07:43:47.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=16, payload=10 02 0A 32 02 21 34 00 00 01 70 00 00
2019-03-13 07:43:47.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-13 07:43:47.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:DONE)
2019-03-13 07:43:47.961 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2019-03-13 07:43:47.961 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_METER, endpoint 0
2019-03-13 07:43:47.962 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2019-03-13 07:43:47.962 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_METER V3 METER_REPORT
2019-03-13 07:43:47.962 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 2: Meter: Type=Electric(1), Scale=W(2), Value=36.8
2019-03-13 07:43:47.962 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveMeterValueEvent
2019-03-13 07:43:47.962 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_METER, value=36.8
2019-03-13 07:43:47.962 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:2f18a74d:node2:meter_watts to 36.8 [DecimalType]
2019-03-13 07:43:47.962 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1.
2019-03-13 07:43:47.962 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@7578f5e8.
2019-03-13 07:43:47.962 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:47.963 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-03-13 07:43:47.963 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-13 07:43:47.964 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-13 07:44:37.432 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion timer at ExcludeStart
2019-03-13 07:44:37.432 [DEBUG] [serialmessage.RemoveNodeMessageClass] - Ending EXCLUSION mode.
2019-03-13 07:44:37.432 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 276 to queue - size 1
2019-03-13 07:44:37.432 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-13 07:44:37.432 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4B 05 27 93
2019-03-13 07:44:37.433 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4B 05 27 93
2019-03-13 07:44:37.433 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-13 07:44:37.433 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-13 07:44:37.433 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 276: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 39
2019-03-13 07:44:37.434 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-13 07:44:37.434 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-13 07:44:37.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 276: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 39
2019-03-13 07:44:37.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-13 07:44:37.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-13 07:44:37.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-13 07:44:37.584 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4B 27 06 0A 00 98
2019-03-13 07:44:37.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=RemoveNodeFromNetwork[75], type=Request[0], dest=6, callback=39, payload=27 06 0A 00
2019-03-13 07:44:37.585 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=RemoveNodeFromNetwork[75], type=Request[0], dest=6, callback=39, payload=27 06 0A 00
2019-03-13 07:44:37.585 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 276: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 39
2019-03-13 07:44:37.585 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-03-13 07:44:37.585 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 276: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 39
2019-03-13 07:44:37.585 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=RemoveNodeFromNetwork[75], type=Request[0], dest=6, callback=39, payload=27 06 0A 00
2019-03-13 07:44:37.585 [DEBUG] [serialmessage.RemoveNodeMessageClass] - Remove Node: Done.
2019-03-13 07:44:37.586 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveInclusionEvent
2019-03-13 07:44:37.597 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state ExcludeFail, new event ExcludeDone
2019-03-13 07:44:37.597 [DEBUG] [serialmessage.RemoveNodeMessageClass] - Ending EXCLUSION mode.
2019-03-13 07:44:37.597 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 277 to queue - size 1
2019-03-13 07:44:37.597 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-13 07:44:37.598 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2019-03-13 07:44:37.598 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2019-03-13 07:44:37.615 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 276: Advanced to DONE
2019-03-13 07:44:37.616 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 183ms
2019-03-13 07:44:37.616 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 276: Transaction completed
2019-03-13 07:44:37.616 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:276 DONE
2019-03-13 07:44:37.617 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

Regards
Stefan