HANK Flood Sensor FLD01 not recognized

mariofrombelgium · March 28, 2019, 10:04am

Hello,

(again a newbee in the world of z-wave and openhab, sorry)

My Aeotec Z-stick Gen5 mounted on my Raspberry Pi 3 has succecfully paired with my Hank Flood Sensor FLD01.

The thing in PaperUI claims that it is an unknown device. It is eaither not in the database or the initialisation has not been fully completed.

As far as I can see it is in the database:
https://www.cd-jackson.com/index.php/zwave/zwave-device-database/zwave-device-list/devicesummary/674

That is why i thought maybe I should give it some time and wake up the sensor a few times but so far no solution.

What is worrying me is that, when I press the button on my sensor (I believe that is one way to wake it up) I don’t see anything happening in the openhab log. I would have expected that the log would mention something like “sensor woke up” and eventually “Inistialisation completed…thing recognised” (I’m inventing these logs myself…I guess you know what I mean.)
But nothing happens. (I know the log works because my Sonos binding is working and actions are logged.)

The fact that nothing gets logged makes me think that there is no contact and thus no way to complete the initialisation???

Leaves the question…what do I do now?

Again, complete newbee so be patience with me…but when we solve this problem I promisse you I will thank you for helping out

Regards,
Mario

mariofrombelgium · March 28, 2019, 1:32pm

Hi, me again.

I want to add that the thing in HabMin also doesn’t mention a manufacturers ID nor TypeID.
I’m not sure that it is supposed to but I thought I’d mention it.

Regards,
Mario

5iver · March 28, 2019, 3:18pm

The manual states that the default wakup interval is 0, so you will need to manually wake it up the device several times to complete initialization. You will not see much in the logs unless you have set the logging level for the zwave binding to debug. Just remeber to set it back to warn or info when done troubleshooting.

mariofrombelgium · March 28, 2019, 8:10pm

Hello,

Since I just started playing around I decide to “exclude” all things en “reset” controller. Afterwards I started with pairing a sirene which works perfectly. Than again the flood sensor but with the same result.
I set the log to debug. The result is many lines that repeat themselves:

2019-03-28 20:04:28.458 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2019-03-28 20:07:59.117 [WARN ] [shd.server.session.ServerSessionImpl] - exceptionCaught(ServerSessionImpl[openhab@/127.0.0.1:59888])[state=Opened] InterruptedByTimeoutException: null

2019-03-28 20:08:30.075 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 03 06 31 05 01 22 00 F5 10

2019-03-28 20:08:30.089 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0&lt;&gt;128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=3, callback=0, payload=00 03 06 31 05 01 22 00 F5

2019-03-28 20:08:30.097 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=3, callback=0, payload=00 03 06 31 05 01 22 00 F5

2019-03-28 20:08:30.100 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2019-03-28 20:08:30.103 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Application Command Request (ALIVE:REQUEST_NIF)

2019-03-28 20:08:30.107 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0

2019-03-28 20:08:30.110 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY not supported

2019-03-28 20:08:30.113 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Received COMMAND_CLASS_SENSOR_MULTILEVEL V0 SENSOR_MULTILEVEL_REPORT

2019-03-28 20:08:30.116 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Type = Temperature(1), Scale = 0

2019-03-28 20:08:30.119 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Value = 24.5

2019-03-28 20:08:30.122 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent

2019-03-28 20:08:30.126 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_SENSOR_MULTILEVEL, value = 24.5

2019-03-28 20:08:30.129 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Commands processed 1.

2019-03-28 20:08:30.132 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@45c6df.

2019-03-28 20:08:30.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0

2019-03-28 20:08:30.138 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0

2019-03-28 20:08:30.141 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-03-28 20:08:30.144 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2019-03-28 20:08:53.060 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling...

2019-03-28 20:08:53.064 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Polling deferred until initialisation complete

5iver · March 28, 2019, 8:15pm

Please use code fences. There are no wakeups in your log. Were you pushing the button to wake up the device?

mariofrombelgium · March 28, 2019, 8:20pm

Well I’m pushing the button of the sensor so that the led lights up. I hope that that wakes up the sensor. But I also was searching for a line that would mention that something was waking up.

5iver · March 28, 2019, 8:20pm

Try a triple press and see if anything gets logged.

mariofrombelgium · March 28, 2019, 8:22pm

Ok that seems to move things!
will be back in a minute. (BTW I editted the post with the log and added the ticks, is that ok like that?)

5iver · March 28, 2019, 8:23pm

Nope… maybe you used single quotes?

3 ticks

‘’’
3 single quotes
‘’’

mariofrombelgium · March 28, 2019, 8:30pm

2019-03-28 20:25:05.979 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Is awake with 1 messages in the queue

2019-03-28 20:25:05.983 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Start sleep timer at 5000ms

2019-03-28 20:25:05.986 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveNodeStatusEvent

2019-03-28 20:25:05.997 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 3: Node Status event - Node is AWAKE

==&gt; /var/log/openhab2/events.log &lt;==

2019-03-28 20:25:06.003 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:d6f8d867:node3' has been updated.

The tripple push did wake up the device (see first line) but than many many line pop up(above are just the first5). What are we looking for?

Grts

mariofrombelgium · March 28, 2019, 8:39pm

I wonder how many times I need the wake up the sensor before it is recognised? (Maybe I will be faster to return the sensor to the shop and buy another brand?)

In other words, after 5 wakeup procedures still no result. The sensor is still not recognised.

Grts
Mario

5iver · March 28, 2019, 8:44pm

When you receive something like this…

2019-02-27 19:46:48.150 [DEBUG] [org.openhab.binding.zwave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 04 00 96 08 72 05 01 38 00 01 00 02 26 
2019-02-27 19:46:48.154 [DEBUG] [org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=150, callback=0, payload=00 96 08 72 05 01 38 00 01 00 02 
2019-02-27 19:46:48.154 [DEBUG] [org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=150, callback=0, payload=00 96 08 72 05 01 38 00 01 00 02 
2019-02-27 19:46:48.155 [DEBUG] [org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-02-27 19:46:48.155 [DEBUG] [org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager] - NODE 150: Application Command Request (ALIVE:MANUFACTURER)
2019-02-27 19:46:48.155 [DEBUG] [org.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 150: Incoming command class COMMAND_CLASS_MANUFACTURER_SPECIFIC, endpoint 0
2019-02-27 19:46:48.155 [DEBUG] [org.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 150: SECURITY not supported
2019-02-27 19:46:48.155 [DEBUG] [org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveCommandClass] - NODE 150: Received COMMAND_CLASS_MANUFACTURER_SPECIFIC V0 MANUFACTURER_SPECIFIC_REPORT
2019-02-27 19:46:48.156 [DEBUG] [org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveManufacturerSpecificCommandClass] - NODE 150: Manufacturer ID = 0x138
2019-02-27 19:46:48.156 [DEBUG] [org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveManufacturerSpecificCommandClass] - NODE 150: Device Type     = 0x1
2019-02-27 19:46:48.156 [DEBUG] [org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveManufacturerSpecificCommandClass] - NODE 150: Device ID       = 0x2
2019-02-27 19:46:48.156 [DEBUG] [org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager] - NODE 150: Commands processed 1.

… the binding will be able to identify the node. Figure out how to use code fences and post more of your log… I can’t tell where it is in the initialization process. It’s possible that there are other issues.

It depends on the device how many times it will need to be woken up. Some devices will need a lot of them. It will need to wake up until you see a message that initialization is complete.

mariofrombelgium · March 28, 2019, 8:58pm

this is the complete log from the moment I initiated a wakeup

2019-03-28 20:52:32.492 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Is awake with 1 messages in the queue

2019-03-28 20:52:32.497 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Start sleep timer at 5000ms

2019-03-28 20:52:32.500 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveNodeStatusEvent

2019-03-28 20:52:32.516 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 3: Node Status event - Node is AWAKE

==> /var/log/openhab2/events.log <==

2019-03-28 20:52:32.527 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:d6f8d867:node3' has been updated.

==> /var/log/openhab2/openhab.log <==

2019-03-28 20:52:34.999 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES

2019-03-28 20:52:37.500 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES

2019-03-28 20:52:40.000 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES

2019-03-28 20:52:42.500 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES

2019-03-28 20:52:44.999 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES

2019-03-28 20:52:47.500 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES

2019-03-28 20:52:50.000 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES

2019-03-28 20:52:52.500 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES

2019-03-28 20:52:55.000 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES

2019-03-28 20:52:57.500 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES

2019-03-28 20:53:00.001 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES

2019-03-28 20:53:02.501 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES

2019-03-28 20:53:05.001 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES

2019-03-28 20:53:07.115 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 03 0A 71 05 00 00 00 FF 07 00 01 09 66 

2019-03-28 20:53:07.126 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=3, callback=0, payload=00 03 0A 71 05 00 00 00 FF 07 00 01 09 

2019-03-28 20:53:07.131 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=3, callback=0, payload=00 03 0A 71 05 00 00 00 FF 07 00 01 09 

2019-03-28 20:53:07.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2019-03-28 20:53:07.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Application Command Request (ALIVE:STATIC_VALUES)

2019-03-28 20:53:07.143 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Incoming command class COMMAND_CLASS_ALARM, endpoint 0

2019-03-28 20:53:07.146 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_ALARM

2019-03-28 20:53:07.150 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Received COMMAND_CLASS_ALARM V5 NOTIFICATION_REPORT

2019-03-28 20:53:07.153 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 3: NOTIFICATION report - 0 = 0, event=0, status=255, plen=1

2019-03-28 20:53:07.157 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 3: Alarm Type = BURGLAR (0)

2019-03-28 20:53:07.160 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveAlarmValueEvent

2019-03-28 20:53:07.164 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_ALARM, value = 255

2019-03-28 20:53:07.168 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Commands processed 1.

2019-03-28 20:53:07.172 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@575676.

2019-03-28 20:53:07.174 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0

2019-03-28 20:53:07.178 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0

2019-03-28 20:53:07.181 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-03-28 20:53:07.185 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2019-03-28 20:53:07.189 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 03 02 5E 01 25 25 BB 

2019-03-28 20:53:07.195 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 09 00 13 03 02 5E 01 25 25 BB 

2019-03-28 20:53:07.198 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2019-03-28 20:53:07.200 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06

2019-03-28 20:53:07.203 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 44: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 37

2019-03-28 20:53:07.204 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2019-03-28 20:53:07.208 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2019-03-28 20:53:07.210 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 

2019-03-28 20:53:07.213 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 44: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 37

2019-03-28 20:53:07.215 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-03-28 20:53:07.217 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

2019-03-28 20:53:07.221 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-03-28 20:53:07.224 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 44: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 37

2019-03-28 20:53:07.225 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 25 00 00 02 CC 

2019-03-28 20:53:07.228 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2019-03-28 20:53:07.232 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 44: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 37

2019-03-28 20:53:07.231 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=37, payload=25 00 00 02 

2019-03-28 20:53:07.235 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-03-28 20:53:07.239 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.

2019-03-28 20:53:07.243 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 44: Advanced to WAIT_REQUEST

2019-03-28 20:53:07.243 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 03 09 5E 02 01 06 00 0C 00 0C 00 A5 

2019-03-28 20:53:07.246 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 44: Transaction not completed

2019-03-28 20:53:07.251 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=37, payload=25 00 00 02 

2019-03-28 20:53:07.252 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=3, callback=0, payload=00 03 09 5E 02 01 06 00 0C 00 0C 00 

2019-03-28 20:53:07.254 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 44: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 37

2019-03-28 20:53:07.257 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2019-03-28 20:53:07.261 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 44: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 37

2019-03-28 20:53:07.264 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 44: (Callback 37)

2019-03-28 20:53:07.269 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!

2019-03-28 20:53:07.271 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 44: callback 37

2019-03-28 20:53:07.276 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=37, payload=25 00 00 02 

2019-03-28 20:53:07.280 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 37, Status = Transmission complete and ACK received(0)

2019-03-28 20:53:07.284 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 44: Advanced to WAIT_DATA

2019-03-28 20:53:07.288 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 44: Transaction not completed

2019-03-28 20:53:07.293 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=3, callback=0, payload=00 03 09 5E 02 01 06 00 0C 00 0C 00 

2019-03-28 20:53:07.297 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2019-03-28 20:53:07.300 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Application Command Request (ALIVE:STATIC_VALUES)

2019-03-28 20:53:07.312 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Incoming command class COMMAND_CLASS_ZWAVEPLUS_INFO, endpoint 0

2019-03-28 20:53:07.315 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_ZWAVEPLUS_INFO

2019-03-28 20:53:07.320 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Received COMMAND_CLASS_ZWAVEPLUS_INFO V1 ZWAVEPLUS_INFO_REPORT

2019-03-28 20:53:07.323 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Commands processed 1.

2019-03-28 20:53:07.328 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@12f5513.

2019-03-28 20:53:07.332 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@12f5513.

2019-03-28 20:53:07.335 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: notifyTransactionResponse TID:44 DONE

2019-03-28 20:53:07.338 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent

2019-03-28 20:53:07.338 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 44: Transaction event listener: DONE: DONE -> 

2019-03-28 20:53:07.341 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1

2019-03-28 20:53:07.349 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0

2019-03-28 20:53:07.349 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@160b9ca

2019-03-28 20:53:07.352 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-03-28 20:53:07.353 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node Init transaction completed with response COMPLETE

2019-03-28 20:53:07.354 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2019-03-28 20:53:07.360 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_FIRMWARE_UPDATE_MD

2019-03-28 20:53:07.363 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_ASSOCIATION

2019-03-28 20:53:07.369 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Found 1 instances of COMMAND_CLASS_ASSOCIATION for endpoint 0

2019-03-28 20:53:07.372 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - NODE 3: Creating new message for application command ASSOCIATIONCMD_GROUPINGSGET

2019-03-28 20:53:07.377 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_ASSOCIATION

2019-03-28 20:53:07.380 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Command Class COMMAND_CLASS_ASSOCIATION is NOT required to be secured

2019-03-28 20:53:07.385 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: ZWaveCommandClassTransactionPayload - send to node

2019-03-28 20:53:07.389 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_ASSOCIATION

2019-03-28 20:53:07.394 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Command Class COMMAND_CLASS_ASSOCIATION is NOT required to be secured

2019-03-28 20:53:07.397 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@144d7c8

2019-03-28 20:53:07.402 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Bump transaction 45 priority from Config to Immediate

2019-03-28 20:53:07.405 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue

2019-03-28 20:53:07.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 45 to queue - size 1

2019-03-28 20:53:07.411 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2019-03-28 20:53:07.416 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 03 02 85 05 25 26 67 

2019-03-28 20:53:07.420 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 09 00 13 03 02 85 05 25 26 67 

2019-03-28 20:53:07.423 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2019-03-28 20:53:07.426 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06

2019-03-28 20:53:07.426 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 45: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 38

2019-03-28 20:53:07.429 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2019-03-28 20:53:07.433 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2019-03-28 20:53:07.436 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 45: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 38

2019-03-28 20:53:07.436 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 

2019-03-28 20:53:07.438 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

2019-03-28 20:53:07.441 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-03-28 20:53:07.445 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2019-03-28 20:53:07.446 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-03-28 20:53:07.449 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-03-28 20:53:07.451 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 45: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 38

2019-03-28 20:53:07.451 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 26 00 00 03 CE 

2019-03-28 20:53:07.455 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2019-03-28 20:53:07.457 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=38, payload=26 00 00 03 

2019-03-28 20:53:07.459 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 45: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 38

2019-03-28 20:53:07.463 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-03-28 20:53:07.466 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 03 03 85 06 02 73 

2019-03-28 20:53:07.466 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.

2019-03-28 20:53:07.470 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 45: Advanced to WAIT_REQUEST

2019-03-28 20:53:07.472 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=3, callback=0, payload=00 03 03 85 06 02 

2019-03-28 20:53:07.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 45: Transaction not completed

2019-03-28 20:53:07.477 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (1): Message: class=SendData[19], type=Request[0], dest=0, callback=38, payload=26 00 00 03 

2019-03-28 20:53:07.480 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 45: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 38

2019-03-28 20:53:07.484 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2019-03-28 20:53:07.487 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 45: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 38

2019-03-28 20:53:07.491 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 45: (Callback 38)

2019-03-28 20:53:07.494 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!

2019-03-28 20:53:07.498 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 45: callback 38

2019-03-28 20:53:07.501 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES

2019-03-28 20:53:07.501 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=38, payload=26 00 00 03 

2019-03-28 20:53:07.505 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 38, Status = Transmission complete and ACK received(0)

2019-03-28 20:53:07.508 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 45: Advanced to WAIT_DATA

2019-03-28 20:53:07.512 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 45: Transaction not completed

2019-03-28 20:53:07.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=3, callback=0, payload=00 03 03 85 06 02 

2019-03-28 20:53:07.520 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2019-03-28 20:53:07.522 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Application Command Request (ALIVE:STATIC_VALUES)

2019-03-28 20:53:07.527 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Incoming command class COMMAND_CLASS_ASSOCIATION, endpoint 0

2019-03-28 20:53:07.529 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_ASSOCIATION

2019-03-28 20:53:07.533 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Received COMMAND_CLASS_ASSOCIATION V2 ASSOCIATIONCMD_GROUPINGS_REPORT

2019-03-28 20:53:07.536 [DEBUG] [ndclass.ZWaveAssociationCommandClass] - NODE 3: processGroupingsReport number of groups 2

2019-03-28 20:53:07.541 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Commands processed 1.

2019-03-28 20:53:07.544 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@198f89a.

2019-03-28 20:53:07.548 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@198f89a.

2019-03-28 20:53:07.551 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: notifyTransactionResponse TID:45 DONE

2019-03-28 20:53:07.556 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent

2019-03-28 20:53:07.556 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 45: Transaction event listener: DONE: DONE -> 

2019-03-28 20:53:07.559 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1

2019-03-28 20:53:07.562 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@11a3eb

2019-03-28 20:53:07.563 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0

2019-03-28 20:53:07.565 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-03-28 20:53:07.565 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node Init transaction completed with response COMPLETE

2019-03-28 20:53:07.571 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_ASSOCIATION_GRP_INFO

2019-03-28 20:53:07.571 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2019-03-28 20:53:07.575 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Found 1 instances of COMMAND_CLASS_ASSOCIATION_GRP_INFO for endpoint 0

2019-03-28 20:53:07.579 [DEBUG] [WaveAssociationGroupInfoCommandClass] - NODE 3: Initialising association group info - 2 groups known

2019-03-28 20:53:07.583 [DEBUG] [WaveAssociationGroupInfoCommandClass] - NODE 3: Creating new message for application command GROUP_NAME_GET for group 1

2019-03-28 20:53:07.588 [DEBUG] [WaveAssociationGroupInfoCommandClass] - NODE 3: Creating new message for application command INFO_GET for group 1

2019-03-28 20:53:07.591 [DEBUG] [WaveAssociationGroupInfoCommandClass] - NODE 3: Creating new message for application command COMMAND_LIST_GET for group 1

2019-03-28 20:53:07.596 [DEBUG] [WaveAssociationGroupInfoCommandClass] - NODE 3: Creating new message for application command GROUP_NAME_GET for group 2

2019-03-28 20:53:07.599 [DEBUG] [WaveAssociationGroupInfoCommandClass] - NODE 3: Creating new message for application command INFO_GET for group 2

2019-03-28 20:53:07.603 [DEBUG] [WaveAssociationGroupInfoCommandClass] - NODE 3: Creating new message for application command COMMAND_LIST_GET for group 2

2019-03-28 20:53:07.606 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_ASSOCIATION_GRP_INFO

2019-03-28 20:53:07.610 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Command Class COMMAND_CLASS_ASSOCIATION_GRP_INFO is NOT required to be secured

2019-03-28 20:53:07.613 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: ZWaveCommandClassTransactionPayload - send to node

2019-03-28 20:53:07.617 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_ASSOCIATION_GRP_INFO

2019-03-28 20:53:07.620 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Command Class COMMAND_CLASS_ASSOCIATION_GRP_INFO is NOT required to be secured

2019-03-28 20:53:07.624 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@1bb1a92

2019-03-28 20:53:07.627 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Bump transaction 46 priority from Config to Immediate

2019-03-28 20:53:07.629 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue

2019-03-28 20:53:07.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 46 to queue - size 1

2019-03-28 20:53:07.634 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2019-03-28 20:53:07.646 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 03 03 59 01 01 25 27 BD 

2019-03-28 20:53:07.652 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0A 00 13 03 03 59 01 01 25 27 BD 

2019-03-28 20:53:07.658 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2019-03-28 20:53:07.660 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06

2019-03-28 20:53:07.664 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 46: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 39

2019-03-28 20:53:07.663 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2019-03-28 20:53:07.667 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2019-03-28 20:53:07.669 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 

2019-03-28 20:53:07.670 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 46: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 39

2019-03-28 20:53:07.672 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

2019-03-28 20:53:07.677 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-03-28 20:53:07.679 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-03-28 20:53:07.680 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2019-03-28 20:53:07.683 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-03-28 20:53:07.685 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 27 00 00 02 CE 

2019-03-28 20:53:07.687 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 46: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 39

2019-03-28 20:53:07.691 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2019-03-28 20:53:07.694 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 46: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 39

2019-03-28 20:53:07.696 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=39, payload=27 00 00 02 

2019-03-28 20:53:07.699 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-03-28 20:53:07.703 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.

2019-03-28 20:53:07.705 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 12 00 04 00 03 0C 59 02 01 08 4C 69 66 65 6C 69 6E 65 9C 

2019-03-28 20:53:07.706 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 46: Advanced to WAIT_REQUEST

2019-03-28 20:53:07.708 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 46: Transaction not completed

2019-03-28 20:53:07.713 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=39, payload=27 00 00 02 

2019-03-28 20:53:07.715 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=3, callback=0, payload=00 03 0C 59 02 01 08 4C 69 66 65 6C 69 6E 65 

2019-03-28 20:53:07.716 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 46: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 39

2019-03-28 20:53:07.719 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2019-03-28 20:53:07.723 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 46: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 39

2019-03-28 20:53:07.726 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 46: (Callback 39)

2019-03-28 20:53:07.730 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!

2019-03-28 20:53:07.732 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 46: callback 39

2019-03-28 20:53:07.737 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=39, payload=27 00 00 02 

2019-03-28 20:53:07.740 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 39, Status = Transmission complete and ACK received(0)

2019-03-28 20:53:07.744 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 46: Advanced to WAIT_DATA

2019-03-28 20:53:07.746 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 46: Transaction not completed

2019-03-28 20:53:07.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=3, callback=0, payload=00 03 0C 59 02 01 08 4C 69 66 65 6C 69 6E 65 

2019-03-28 20:53:07.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2019-03-28 20:53:07.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Application Command Request (ALIVE:STATIC_VALUES)

2019-03-28 20:53:07.763 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Incoming command class COMMAND_CLASS_ASSOCIATION_GRP_INFO, endpoint 0

2019-03-28 20:53:07.766 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_ASSOCIATION_GRP_INFO

2019-03-28 20:53:07.770 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 3: Received COMMAND_CLASS_ASSOCIATION_GRP_INFO V1 ASSOCIATION_GROUP_INFO_NAME_REPORT

2019-03-28 20:53:07.773 [DEBUG] [WaveAssociationGroupInfoCommandClass] - NODE 3: recieved group name: 'Lifeline' for group number: 1

2019-03-28 20:53:07.778 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Commands processed 1.

2019-03-28 20:53:07.783 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@16fe04b.

2019-03-28 20:53:07.788 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@16fe04b.

2019-03-28 20:53:07.790 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: notifyTransactionResponse TID:46 DONE

2019-03-28 20:53:07.795 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent

2019-03-28 20:53:07.796 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 46: Transaction event listener: DONE: DONE -> 

2019-03-28 20:53:07.805 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1e55dc6

2019-03-28 20:53:07.799 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1

2019-03-28 20:53:07.810 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node Init transaction completed with response COMPLETE

2019-03-28 20:53:07.812 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_ASSOCIATION_GRP_INFO

2019-03-28 20:53:07.812 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0

2019-03-28 20:53:07.815 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-03-28 20:53:07.817 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Command Class COMMAND_CLASS_ASSOCIATION_GRP_INFO is NOT required to be secured

2019-03-28 20:53:07.818 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2019-03-28 20:53:07.820 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: ZWaveCommandClassTransactionPayload - send to node

2019-03-28 20:53:07.825 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY NOT required on COMMAND_CLASS_ASSOCIATION_GRP_INFO

2019-03-28 20:53:07.831 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Command Class COMMAND_CLASS_ASSOCIATION_GRP_INFO is NOT required to be secured

2019-03-28 20:53:07.834 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@242ee5

2019-03-28 20:53:07.837 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Bump transaction 47 priority from Config to Immediate

2019-03-28 20:53:07.839 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue

2019-03-28 20:53:07.842 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 47 to queue - size 1

2019-03-28 20:53:07.846 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2019-03-28 20:53:07.850 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 13 03 04 59 03 00 01 25 28 B6 

2019-03-28 20:53:07.854 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0B 00 13 03 04 59 03 00 01 25 28 B6 

2019-03-28 20:53:07.857 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2019-03-28 20:53:07.860 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 47: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 40

2019-03-28 20:53:07.860 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06

2019-03-28 20:53:07.863 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2019-03-28 20:53:07.869 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 

2019-03-28 20:53:07.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2019-03-28 20:53:07.881 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-03-28 20:53:07.887 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 47: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 40

2019-03-28 20:53:07.889 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

2019-03-28 20:53:07.894 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-03-28 20:53:07.896 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 47: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 40

2019-03-28 20:53:07.900 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2019-03-28 20:53:07.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 47: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 40

2019-03-28 20:53:07.907 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 

2019-03-28 20:53:07.910 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.

2019-03-28 20:53:07.914 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 47: Advanced to WAIT_REQUEST

2019-03-28 20:53:07.917 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 47: Transaction not completed

2019-03-28 20:53:07.921 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-03-28 20:53:07.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2019-03-28 20:53:10.001 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES

2019-03-28 20:53:12.103 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 28 01 01 A8 6B 

2019-03-28 20:53:12.109 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=40, payload=28 01 01 A8 

2019-03-28 20:53:12.113 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=40, payload=28 01 01 A8 

2019-03-28 20:53:12.117 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 47: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 40

2019-03-28 20:53:12.119 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1

2019-03-28 20:53:12.123 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 47: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 40

2019-03-28 20:53:12.126 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 47: (Callback 40)

2019-03-28 20:53:12.130 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!

2019-03-28 20:53:12.132 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 47: callback 40

2019-03-28 20:53:12.137 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=40, payload=28 01 01 A8 

2019-03-28 20:53:12.140 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 40, Status = Transmission complete, no ACK received(1)

2019-03-28 20:53:12.143 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 47: Transaction CANCELLED

2019-03-28 20:53:12.146 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent

2019-03-28 20:53:12.150 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Transaction failed waiting for REQUEST, assume sleeping device.

2019-03-28 20:53:12.152 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: CANCEL while sending message. Requeueing - 2 attempts left!

2019-03-28 20:53:12.156 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 47: Transaction RESET with 2 retries remaining.

2019-03-28 20:53:12.159 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue

2019-03-28 20:53:12.163 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 47 to queue - size 1

2019-03-28 20:53:12.165 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2019-03-28 20:53:12.169 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 47: Transaction not completed

2019-03-28 20:53:12.171 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-03-28 20:53:12.175 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

5iver · March 28, 2019, 10:00pm

This looks normal and it appears to be progressing. Just keep waking it up and watching the logs until it is done initilaizing. Just keep an eye on where it is in the initialization. If it doesn’t progress, then there may be an issue.

mariofrombelgium · March 29, 2019, 6:49pm

Hi,

This seems to be leading to nothing.
I have woken up the device at least 20 times now. I even soft resetted the controller(read in another thread that that could maybe help) but not solution yet.

Anybody a briliant idea?

Grts,
Mario

5iver · March 29, 2019, 7:01pm

I have a ZCOMBO device that refuses to complete initialization. I’ve provided logs to @chris, but he’s been focused on other things ATM. You could be experiencing a related issue, but more logs would be needed to determine that.

However, you should update to the most recent version of the binding (if you’re not already), to be sure you’re not fighting something that has already been resolved.

chris · March 29, 2019, 7:07pm

Sorry Scott - things have been a bit busy recently. No real change at the moment, but I will take a look at your log tonight.

mariofrombelgium · March 29, 2019, 8:11pm

I’m working with Openhab 2.4.0-1 (downloaded it last week)
According to a thread from 6/01 from Chris somechare on the forum the 2.4 contains the updated z-wave binding

Should I spend time om an upgrade?

Grts,
Mario

5iver · March 29, 2019, 8:16pm

There have been changes in the binding since 2.4, so you might want to use the most recent. This may help, but wait a bit, as I think Chris may have a fix that will help.

mariofrombelgium · March 30, 2019, 8:28pm

Hi there,

Would it be an option to configure the thing manually?
I have read through the process but I wonder whether or not this could work.

I know that the device is working because I just setup an Openhab alternative on my Raspberry and that worked like a charm. (don’t like the alternative so want to stay in Openhab.)

Regards,
Mario