Has the device created an XML file yet? If so, can you attach it here (or paste it into the message).
Hi @chris,
Yes, it has been created a whila ago and was modified yesterday evening the last time.
So I am just waiting for the node to finish initialization (I guess), because there is no wake up timestamp in habmin yet and the ON/OFF signal from the strip is not yet correct (although it changed last night to OFF, which was correct).
I hope my wake up time of 1 hour will do the job today.
Thanks for your help.
Please find my node8.xml attached.
node8.xml (8.3 KB)
Sometimes a tiny hint helps to check into directions where no one has gone before 
In the xml I have the informatioon available about the last wakeup time:
2016-12-26 20:15:54.614 UTC
However, according to my openhab.log that last wakeup was at 4:59 with some successful communication.
2016-12-27 04:59:16.992 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 8: Application Command Request (ALIVE:DYNAMIC_VALUES)
2016-12-27 04:59:16.994 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 8: Incoming command class WAKE_UP
2016-12-27 04:59:16.995 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Received Wake Up Request
2016-12-27 04:59:16.996 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Received WAKE_UP_NOTIFICATION
2016-12-27 04:59:16.997 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Is awake with 1 messages in the wake-up queue.
2016-12-27 04:59:16.998 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveWakeUpEvent
2016-12-27 04:59:16.999 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Wakeup during initialisation.
2016-12-27 04:59:17.001 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer - DYNAMIC_VALUES: queue length(2), free to send(false)
2016-12-27 04:59:17.002 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: loop - DYNAMIC_VALUES try 1: stageAdvanced(false)
2016-12-27 04:59:17.003 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - checking ZWAVE_PLUS_INFO
2016-12-27 04:59:17.004 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - checking VERSION
2016-12-27 04:59:17.006 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - checking CONFIGURATION
2016-12-27 04:59:17.007 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - checking DEVICE_RESET_LOCALLY
2016-12-27 04:59:17.008 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - checking MANUFACTURER_SPECIFIC
2016-12-27 04:59:17.009 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - checking NO_OPERATION
2016-12-27 04:59:17.010 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - checking ASSOCIATION
2016-12-27 04:59:17.011 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - checking POWERLEVEL
2016-12-27 04:59:17.012 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - found POWERLEVEL
2016-12-27 04:59:17.013 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Found 1 instances of POWERLEVEL
2016-12-27 04:59:17.014 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - checking BATTERY
2016-12-27 04:59:17.015 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - found BATTERY
2016-12-27 04:59:17.016 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Found 1 instances of BATTERY
2016-12-27 04:59:17.017 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - checking SENSOR_BINARY
2016-12-27 04:59:17.018 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - found SENSOR_BINARY
2016-12-27 04:59:17.019 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Found 1 instances of SENSOR_BINARY
2016-12-27 04:59:17.020 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - checking WAKE_UP
2016-12-27 04:59:17.021 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - checking ASSOCIATION_GROUP_INFO
2016-12-27 04:59:17.022 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - checking BASIC
2016-12-27 04:59:17.023 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - checking ALARM
2016-12-27 04:59:17.024 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - found ALARM
2016-12-27 04:59:17.026 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Found 1 instances of ALARM
2016-12-27 04:59:17.027 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 8: Creating new message for application command NOTIFICATION_GET V4
2016-12-27 04:59:17.029 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 8: Creating new message for application command NOTIFICATION_GET V4
2016-12-27 04:59:17.030 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer - queued packet. Queue length is 1
2016-12-27 04:59:17.032 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2016-12-27 04:59:17.032 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2016-12-27 04:59:17.033 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: DYNAMIC_VALUES - queued 2 frames
2016-12-27 04:59:17.034 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveWakeUpEventIt’s possible that the device isn’t responding to one of these requests. Can you send me a full debug log after a few of these wakeups - I’d like to see what’s up - we might need to modify the database if it’s not responding to the notification request (this is actually not uncommon!).
Thanks again for your support, @chris
Here is one wakeup which is hopefully complete:
2016-12-27 01:07:08.571 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 08 02 84 07 7A
2016-12-27 01:07:08.577 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-12-27 01:07:08.580 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 04 00 08 02 84 07 7A
2016-12-27 01:07:08.582 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 08 00 04 00 08 02 84 07 7A
2016-12-27 01:07:08.584 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 08 02 84 07
2016-12-27 01:07:08.585 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 8: Application Command Request (INITIALIZING:PING)
2016-12-27 01:07:08.586 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Node is ALIVE. Init stage is PING.
2016-12-27 01:07:08.587 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNodeStatusEvent
2016-12-27 01:07:08.588 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node Status event during initialisation - Node is ALIVE
2016-12-27 01:07:08.589 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer - PING: queue length(0), free to send(true)
2016-12-27 01:07:08.590 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: loop - PING try 1: stageAdvanced(false)
2016-12-27 01:07:08.591 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer: PING - send NoOperation
2016-12-27 01:07:08.592 [DEBUG] [ndclass.ZWaveNoOperationCommandClass] - NODE 8: Creating new message for command No Operation
2016-12-27 01:07:08.593 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer - queued packet. Queue length is 1
2016-12-27 01:07:08.595 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Putting message SendData in wakeup queue.
2016-12-27 01:07:08.596 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2016-12-27 01:07:08.597 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Setting ONLINE
2016-12-27 01:07:08.599 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 8: Node Status event - Node is ALIVE
2016-12-27 01:07:08.601 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 8: Incoming command class WAKE_UP
2016-12-27 01:07:08.602 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Received Wake Up Request
2016-12-27 01:07:08.603 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Received WAKE_UP_NOTIFICATION
2016-12-27 01:07:08.604 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Is awake with 1 messages in the wake-up queue.
2016-12-27 01:07:08.606 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveWakeUpEvent
2016-12-27 01:07:08.607 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Wakeup during initialisation.
2016-12-27 01:07:08.608 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer - PING: queue length(1), free to send(false)
2016-12-27 01:07:08.609 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer - queued packet. Queue length is 1
2016-12-27 01:07:08.610 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2016-12-27 01:07:08.617 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 08 01 00 25 B3 7B
2016-12-27 01:07:08.619 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 0. Queue={}
2016-12-27 01:07:08.620 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 8: Sending REQUEST Message = 01 08 00 13 08 01 00 25 B3 7B
2016-12-27 01:07:08.623 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveWakeUpEvent
2016-12-27 01:07:08.631 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2016-12-27 01:07:08.633 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2016-12-27 01:07:08.635 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Transaction not completed: node address inconsistent. lastSent=6, incoming=255
2016-12-27 01:07:08.637 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-12-27 01:07:08.641 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2016-12-27 01:07:08.643 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2016-12-27 01:07:08.644 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2016-12-27 01:07:08.645 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 8: Sent Data successfully placed on stack.
2016-12-27 01:07:08.655 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 B3 00 00 02 5A
2016-12-27 01:07:08.659 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-12-27 01:07:08.661 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 B3 00 00 02 00 00 54
2016-12-27 01:07:08.663 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 B3 00 00 02 00 00 54
2016-12-27 01:07:08.665 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=B3 00 00 02
2016-12-27 01:07:08.666 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 8: SendData Request. CallBack ID = 179, Status = Transmission complete and ACK received(0)
2016-12-27 01:07:08.667 [WARN ] [l.serialmessage.SendDataMessageClass] - NODE 8: Already processed another send data request for this callback Id, ignoring.
2016-12-27 01:07:13.622 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 8: Timeout while sending message. Requeueing - 0 attempts left!
2016-12-27 01:07:13.623 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Is sleeping
2016-12-27 01:07:13.625 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Putting message SendData in wakeup queue.
2016-12-27 01:07:13.626 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2016-12-27 01:07:13.627 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Message already on the wake-up queue. Removing original.
2016-12-27 01:07:13.628 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Putting message SendData in wakeup queue.
and another one:
2016-12-27 08:51:11.020 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2016-12-27 08:51:11.022 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2016-12-27 08:51:11.024 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 7: Response processed after 145ms/4760ms.
2016-12-27 08:51:11.433 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 08 02 84 07 7A
2016-12-27 08:51:11.435 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-12-27 08:51:11.437 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 04 00 08 02 84 07 7A
2016-12-27 08:51:11.438 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 08 00 04 00 08 02 84 07 7A
2016-12-27 08:51:11.440 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 08 02 84 07
2016-12-27 08:51:11.440 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 8: Application Command Request (ALIVE:DYNAMIC_VALUES)
2016-12-27 08:51:11.441 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 8: Incoming command class WAKE_UP
2016-12-27 08:51:11.442 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Received Wake Up Request
2016-12-27 08:51:11.442 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Received WAKE_UP_NOTIFICATION
2016-12-27 08:51:11.443 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Is awake with 1 messages in the wake-up queue.
2016-12-27 08:51:11.444 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveWakeUpEvent
2016-12-27 08:51:11.444 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Wakeup during initialisation.
2016-12-27 08:51:11.445 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer - DYNAMIC_VALUES: queue length(2), free to send(false)
2016-12-27 08:51:11.446 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node advancer - queued packet. Queue length is 2
2016-12-27 08:51:11.447 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2016-12-27 08:51:11.447 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2016-12-27 08:51:11.447 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveWakeUpEvent
2016-12-27 08:51:11.448 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 08 03 71 04 07 25 1B A1
2016-12-27 08:51:11.449 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 8: Sending REQUEST Message = 01 0A 00 13 08 03 71 04 07 25 1B A1
2016-12-27 08:51:11.452 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2016-12-27 08:51:11.453 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 7: Transaction not completed: node address inconsistent. lastSent=7, incoming=255
2016-12-27 08:51:11.463 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2016-12-27 08:51:11.465 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-12-27 08:51:11.466 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2016-12-27 08:51:11.467 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2016-12-27 08:51:11.467 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2016-12-27 08:51:11.468 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 8: Sent Data successfully placed on stack.
2016-12-27 08:51:11.485 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 1B 00 00 03 F3
2016-12-27 08:51:11.486 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-12-27 08:51:11.488 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 1B 00 00 03 00 00 FD
2016-12-27 08:51:11.489 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 1B 00 00 03 00 00 FD
2016-12-27 08:51:11.490 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=1B 00 00 03
2016-12-27 08:51:11.491 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 8: SendData Request. CallBack ID = 27, Status = Transmission complete and ACK received(0)
2016-12-27 08:51:11.492 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=8, callback=27, payload=08 03 71 04 07
2016-12-27 08:51:11.493 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=1B 00 00 03
2016-12-27 08:51:11.494 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=27, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2016-12-27 08:51:14.035 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 03 06 31 05 04 22 00 66 86
2016-12-27 08:51:14.037 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-12-27 08:51:14.039 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0C 00 04 00 03 06 31 05 04 22 00 66 86
2016-12-27 08:51:14.040 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0C 00 04 00 03 06 31 05 04 22 00 66 86
2016-12-27 08:51:14.041 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 03 06 31 05 04 22 00 66
2016-12-27 08:51:14.042 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 3: Application Command Request (ALIVE:DONE)
2016-12-27 08:51:14.043 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Starting initialisation from DONE
2016-12-27 08:51:14.043 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@16b69bb already registered
2016-12-27 08:51:14.044 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 3: Incoming command class SENSOR_MULTILEVEL
2016-12-27 08:51:14.045 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Received COMMAND_CLASS_SENSOR_MULTILEVEL command V2
2016-12-27 08:51:14.046 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Multi Level REPORT received
2016-12-27 08:51:14.047 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Type = Power(4), Scale = 0
2016-12-27 08:51:14.047 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Value = 10.2
2016-12-27 08:51:14.048 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveMultiLevelSensorValueEvent
2016-12-27 08:51:14.049 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2016-12-27 08:51:14.050 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_MULTILEVEL, value = 10.2
2016-12-27 08:51:14.052 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Updating channel state zwave:device:49ede2f3:node3:sensor_power to 10.2 [DecimalType]
2016-12-27 08:51:14.058 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 8: Transaction not completed: node address inconsistent. lastSent=8, incoming=255
2016-12-27 08:51:14.390 [ERROR] [ny.internal.simpleip.SimpleIpHandler] - Error connecting: java.net.NoRouteToHostException: No route to host (Host unreachable)
2016-12-27 08:51:14.392 [INFO ] [ny.internal.simpleip.SimpleIpHandler] - Will try to reconnect in 10 seconds
2016-12-27 08:51:15.039 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 03 06 31 05 04 22 22 AB 69
2016-12-27 08:51:15.044 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-12-27 08:51:15.046 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0C 00 04 00 03 06 31 05 04 22 22 AB 69
2016-12-27 08:51:15.047 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0C 00 04 00 03 06 31 05 04 22 22 AB 69
2016-12-27 08:51:15.048 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 03 06 31 05 04 22 22 AB
2016-12-27 08:51:15.049 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 3: Application Command Request (ALIVE:DONE)
2016-12-27 08:51:15.050 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Starting initialisation from DONE
2016-12-27 08:51:15.051 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@16b69bb already registered
2016-12-27 08:51:15.052 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 3: Incoming command class SENSOR_MULTILEVEL
2016-12-27 08:51:15.053 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Received COMMAND_CLASS_SENSOR_MULTILEVEL command V2
2016-12-27 08:51:15.054 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Multi Level REPORT received
2016-12-27 08:51:15.055 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Type = Power(4), Scale = 0
2016-12-27 08:51:15.056 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Value = 887.5
2016-12-27 08:51:15.057 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveMultiLevelSensorValueEvent
2016-12-27 08:51:15.058 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2016-12-27 08:51:15.059 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_MULTILEVEL, value = 887.5
2016-12-27 08:51:15.062 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Updating channel state zwave:device:49ede2f3:node3:sensor_power to 887.5 [DecimalType]
2016-12-27 08:51:15.069 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 8: Transaction not completed: node address inconsistent. lastSent=8, incoming=255
2016-12-27 08:51:16.038 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 03 06 31 05 04 22 37 9B 4C
2016-12-27 08:51:16.043 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-12-27 08:51:16.045 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0C 00 04 00 03 06 31 05 04 22 37 9B 4C
2016-12-27 08:51:16.046 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0C 00 04 00 03 06 31 05 04 22 37 9B 4C
2016-12-27 08:51:16.048 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 03 06 31 05 04 22 37 9B
2016-12-27 08:51:16.049 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 3: Application Command Request (ALIVE:DONE)
2016-12-27 08:51:16.050 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Starting initialisation from DONE
2016-12-27 08:51:16.051 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@16b69bb already registered
2016-12-27 08:51:16.052 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 3: Incoming command class SENSOR_MULTILEVEL
2016-12-27 08:51:16.053 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Received COMMAND_CLASS_SENSOR_MULTILEVEL command V2
2016-12-27 08:51:16.054 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Multi Level REPORT received
2016-12-27 08:51:16.055 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Type = Power(4), Scale = 0
2016-12-27 08:51:16.056 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Value = 1423.5
2016-12-27 08:51:16.058 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveMultiLevelSensorValueEvent
2016-12-27 08:51:16.059 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2016-12-27 08:51:16.060 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_MULTILEVEL, value = 1423.5
2016-12-27 08:51:16.064 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Updating channel state zwave:device:49ede2f3:node3:sensor_power to 1423.5 [DecimalType]
2016-12-27 08:51:16.073 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 8: Transaction not completed: node address inconsistent. lastSent=8, incoming=255
2016-12-27 08:51:16.451 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 8: Timeout while sending message. Requeueing - 1 attempts left!
2016-12-27 08:51:16.453 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Is sleeping
2016-12-27 08:51:16.454 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Putting message SendData in wakeup queue.
2016-12-27 08:51:16.454 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2016-12-27 08:51:16.455 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Message already on the wake-up queue. Removing original.
2016-12-27 08:51:16.456 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Putting message SendData in wakeup queue.
2016-12-27 08:51:21.039 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 03 06 31 05 04 22 00 AF 4F
2016-12-27 08:51:21.044 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-12-27 08:51:21.046 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0C 00 04 00 03 06 31 05 04 22 00 AF 4F
2016-12-27 08:51:21.047 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0C 00 04 00 03 06 31 05 04 22 00 AF 4F
2016-12-27 08:51:21.049 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 03 06 31 05 04 22 00 AF
2016-12-27 08:51:21.050 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 3: Application Command Request (ALIVE:DONE)
2016-12-27 08:51:21.050 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Starting initialisation from DONE
2016-12-27 08:51:21.051 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@16b69bb already registered
2016-12-27 08:51:21.052 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 3: Incoming command class SENSOR_MULTILEVEL
2016-12-27 08:51:21.053 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Received COMMAND_CLASS_SENSOR_MULTILEVEL command V2
2016-12-27 08:51:21.054 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Multi Level REPORT received
2016-12-27 08:51:21.054 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Type = Power(4), Scale = 0
2016-12-27 08:51:21.055 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 3: Sensor Value = 17.5
2016-12-27 08:51:21.056 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveMultiLevelSensorValueEvent
2016-12-27 08:51:21.057 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2016-12-27 08:51:21.058 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_MULTILEVEL, value = 17.5
2016-12-27 08:51:21.060 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Updating channel state zwave:device:49ede2f3:node3:sensor_power to 17.5 [DecimalType]
2016-12-27 08:51:21.070 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 8: Transaction not completed: node address inconsistent. lastSent=8, incoming=255
2016-12-27 08:51:22.036 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 03 06 31 05 04 22 00 19 F9
2016-12-27 08:51:22.040 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0Thanks - this is about what I expected. I’ll do an update to the database to try and resolve this. SensativeAB are sending me a device to help with testing so hopefully I’ll be able to test it out here in the coming days and we can improve the way this device works.
No rush, Thanks a lot for your help, @chris
I am really impressed about this community and the progress I made with the help of all the enthusiastic members.
Looking forward testing your db change.
@NCO I think “NO”, but I can’t remember exactly.
What a pity, but looks like help is on the way. Good luck.
Thanks! 
Note that I’m going to update the binding tonight to change this device configuration - it might break your device - sorry.
This will move to using the channels for notifications, which should be the default configuration. If you’ve previously set “Notification Type” to “Binary Sensor Report”, you will need to change it back to “Notification Report”.
To update, you’ll also need to delete the thing and add it back (don’t exclude it from the network - just delete the thing, click on discovery and it will be immediately added back to the inbox).
I should hopefully also get a couple of devices for testing in the next day or two so will double check everything then.
I’m really keen on your findings 
Since I have 4 of these strips, 2 are mounted but only 1 is running fine and I’m again and again struggling with these devices I hope that your analysis can bring light into the dark.
Chris - thanks a lot for your effort and support.
Regards
John
I’ve received the strip here and have it all working ok. The update I did last night works fine with the notifications, but I’ve made another change tonight that helps with initialisation and the polling of device status. I’ll update the binding tonight, so if you grab tomorrows snapshot, this should be included.
The strip initialised fine - I had to wake it up a couple of times, but it initialised pretty quickly. I was able to set the wakeup interval in HABmin, wake up the device, and it was set in the strip ok.
I should also add that the guys at Sensative AB have been really helpful and responsive so thanks also to them .
Let me know how it looks - if there’s any problems let me know and we can work through it I’m sure.
Cheers
Chris
1 Like
Thanks for your efforts, @chris.
I also recognized that the support of Sensative AB is very quick and helpful.
THIS is how to differentiate nowadays
I will give your latest update a try, because my strip is still not operational.
I agree. It’s really great to see companies supporting their products.
1 Like
Used the newest binding version, deleted the thing and the xml, re-added it.
After that, I had to change the notification type back to Notification report (as Chris already said), but I also had to change the channel definition of my item (was binary_sensor before, now it is sensor_door).
And because of that, the item type has changed from SWITCH to CONTACT.
After I did all this, the sensor was functional again.
2 Likes
If I understand you correctly, the state is ok when openhab is running but not at startup? If so, this is correct for a battery device like the strip. The binding cant update the state until the device wakes. If you want the state to be correct on startup then you need to use persistence to do this.
No 
OH is losing the state of the devices (applies for all 5 devices). Means:
-
OH starts → no state, it is reported as “-” → but I understood that this can be resolved with persistence → no issue anymore
-
when I’m opening/closing a door the state is updated correctly BUT after a while (still don’t know how long this “while” is) the previously correct reported state changes back to “-” without any intervention (neither item updates, neither restart, neither any other intervention)
I guess when I use a persistence this will also not be visible anymore which doesn’t necissarily means that there is no issue anymore. So my question is whether I have a problem with the devices or if my configuration is wrong (didn’t change any of the default values) or if there is any other problem.
Thanks & Regards
John
This guess is wrong. You should configure the persistence to restore the latest value only on startup using mapdb. So when OH is running and then the item is loosing it’s state (for whatever reason), the persistence will not correct this.
I suspect that this might be something outside of the binding as I don’t ever set a state back to undefined. In oh1 if you updated configuration or items files then the state would be reset - I assume it is the same here… maybe it’s something like that that is causing the issue?
Perfect!
That finally solved my issue and the sensative strips works as expected after upgrading to OH2 release 2.0
Thanks a lot (again) Stefan! 