Zwave Garage Tilt Sensor TILT-ZWAVE2.5-ECO Initialization

mccormack · June 15, 2017, 6:19pm

Does anyone have any advice on how to get this working? It’s been over a week and the initialization still hasn’t finished. After checking device information I get the error that it couldn’t be resolved. I have tried removing/re-adding it and manually waking up the device several times. Any help would be greatly appreciated. Thanks.

2017-06-15 10:54:18.680 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 37: Device discovery could not resolve to a thingType! 014A:0004:0003::10.1
2017-06-15 10:54:18.680 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Starting initialisation from EMPTYNODE
2017-06-15 10:54:18.680 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - EMPTYNODE: queue length(1), free to send(false)
2017-06-15 10:54:18.680 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - queued packet. Queue length is 1
2017-06-15 10:54:18.681 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 37: Init node thread finished
2017-06-15 10:54:18.696 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Controller status changed to ONLINE.
2017-06-15 10:54:18.696 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Controller is ONLINE. Starting device initialisation.
2017-06-15 10:54:18.696 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Updating node properties.
2017-06-15 10:54:18.696 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Updating node properties. MAN=330
2017-06-15 10:54:18.696 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Updating node properties. MAN=330. SET. Was 330
2017-06-15 10:54:18.698 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Configuration synchronised
2017-06-15 10:54:18.750 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Initialising Thing Node...
2017-06-15 10:54:18.750 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Polling intialised at 1800 seconds - start in 1800000 milliseconds.
2017-06-15 10:54:19.180 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: ProtocolInfo
2017-06-15 10:54:19.180 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Listening = false
2017-06-15 10:54:19.180 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Routing = true
2017-06-15 10:54:19.180 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Beaming = true
2017-06-15 10:54:19.181 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Version = 4
2017-06-15 10:54:19.181 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: FLIRS = false
2017-06-15 10:54:19.181 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Security = false
2017-06-15 10:54:19.181 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Max Baud = 40000
2017-06-15 10:54:19.182 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Basic = Routing Slave
2017-06-15 10:54:19.182 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Generic = Sensor Notification
2017-06-15 10:54:19.182 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Specific = Notification Sensor
2017-06-15 10:54:19.182 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 37: Creating new instance of command class NO_OPERATION
2017-06-15 10:54:19.182 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 37: Command class NO_OPERATION, endpoint null created
2017-06-15 10:54:19.182 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 37: Version = 1, version set. Enabling extra functionality.
2017-06-15 10:54:19.183 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 37: Creating new instance of command class BASIC
2017-06-15 10:54:19.183 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 37: Command class BASIC, endpoint null created
2017-06-15 10:54:19.184 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - EMPTYNODE: Transaction complete (IdentifyNode:Request) success(true)
2017-06-15 10:54:19.184 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - checking initialisation queue. Queue size 1.
2017-06-15 10:54:19.184 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - message removed from queue. Queue size 0.
2017-06-15 10:54:19.184 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - EMPTYNODE: queue length(0), free to send(true)
2017-06-15 10:54:19.184 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - EMPTYNODE try 1: stageAdvanced(false)
2017-06-15 10:54:19.184 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: Initialisation starting
2017-06-15 10:54:19.185 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - advancing to PROTOINFO
2017-06-15 10:54:19.185 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-06-15 10:54:19.185 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - PROTOINFO try 0: stageAdvanced(true)
2017-06-15 10:54:19.185 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - advancing to INIT_NEIGHBORS
2017-06-15 10:54:19.186 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-06-15 10:54:19.186 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - INIT_NEIGHBORS try 0: stageAdvanced(true)
2017-06-15 10:54:19.186 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: INIT_NEIGHBORS - send RoutingInfo
2017-06-15 10:54:19.186 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 37: Request routing info
2017-06-15 10:54:19.187 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - queued packet. Queue length is 1
2017-06-15 10:54:19.193 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: ProtocolInfo
2017-06-15 10:54:19.193 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Listening = false
2017-06-15 10:54:19.193 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Routing = true
2017-06-15 10:54:19.193 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Beaming = true
2017-06-15 10:54:19.194 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Version = 4
2017-06-15 10:54:19.194 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: FLIRS = false
2017-06-15 10:54:19.194 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Security = false
2017-06-15 10:54:19.194 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Max Baud = 40000
2017-06-15 10:54:19.194 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Basic = Routing Slave
2017-06-15 10:54:19.195 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Generic = Sensor Notification
2017-06-15 10:54:19.195 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 37: Specific = Notification Sensor
2017-06-15 10:54:19.195 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 37: Creating new instance of command class NO_OPERATION
2017-06-15 10:54:19.195 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 37: Command class NO_OPERATION, endpoint null created
2017-06-15 10:54:19.196 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 37: Version = 1, version set. Enabling extra functionality.
2017-06-15 10:54:19.196 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 37: Creating new instance of command class BASIC
2017-06-15 10:54:19.196 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 37: Command class BASIC, endpoint null created
2017-06-15 10:54:19.197 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - INIT_NEIGHBORS: Transaction complete (IdentifyNode:Request) success(true)
2017-06-15 10:54:19.197 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - checking initialisation queue. Queue size 1.
2017-06-15 10:54:19.599 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 37: Got NodeRoutingInfo request.
2017-06-15 10:54:19.600 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 37: Neighbor nodes: 1 3 4 6 7 8 11 12 13 15 16 17 18 19 28 30
2017-06-15 10:54:19.600 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveNetworkEvent
2017-06-15 10:54:19.601 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - INIT_NEIGHBORS: Transaction complete (GetRoutingInfo:Request) success(true)
2017-06-15 10:54:19.601 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - checking initialisation queue. Queue size 1.
2017-06-15 10:54:19.601 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - message removed from queue. Queue size 0.
2017-06-15 10:54:19.601 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - INIT_NEIGHBORS: queue length(0), free to send(true)
2017-06-15 10:54:19.602 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - INIT_NEIGHBORS try 1: stageAdvanced(false)
2017-06-15 10:54:19.602 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - advancing to FAILED_CHECK
2017-06-15 10:54:19.602 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-06-15 10:54:19.602 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - FAILED_CHECK try 0: stageAdvanced(true)
2017-06-15 10:54:19.603 [DEBUG] [rialmessage.IsFailedNodeMessageClass] - NODE 37: Requesting IsFailedNode status from controller.
2017-06-15 10:54:19.603 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - queued packet. Queue length is 1
2017-06-15 10:54:19.818 [DEBUG] [rialmessage.IsFailedNodeMessageClass] - NODE 37: Is currently marked as healthy by the controller
2017-06-15 10:54:19.818 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - FAILED_CHECK: Transaction complete (IsFailedNodeID:Request) success(true)
2017-06-15 10:54:19.818 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - checking initialisation queue. Queue size 1.
2017-06-15 10:54:19.819 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - message removed from queue. Queue size 0.
2017-06-15 10:54:19.819 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - FAILED_CHECK: queue length(0), free to send(true)
2017-06-15 10:54:19.819 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - FAILED_CHECK try 1: stageAdvanced(false)
2017-06-15 10:54:19.819 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - advancing to WAIT
2017-06-15 10:54:19.819 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-06-15 10:54:19.819 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - WAIT try 0: stageAdvanced(true)
2017-06-15 10:54:19.819 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: WAIT - Listening=false, FrequentlyListening=false
2017-06-15 10:54:19.820 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: WAIT - Still waiting!
2017-06-15 10:56:29.269 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - WAIT: The WAIT is over!
2017-06-15 10:56:29.269 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - checking initialisation queue. Queue size 0.
2017-06-15 10:59:46.150 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Application Command Request (INITIALIZING:PING)
2017-06-15 10:59:46.150 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 37: Node is ALIVE. Init stage is PING.
2017-06-15 10:59:46.150 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node Status event during initialisation - Node is ALIVE
2017-06-15 10:59:46.150 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - PING: queue length(0), free to send(true)
2017-06-15 10:59:46.150 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - PING try 1: stageAdvanced(false)
2017-06-15 10:59:46.150 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: PING - send NoOperation
2017-06-15 10:59:46.150 [DEBUG] [ndclass.ZWaveNoOperationCommandClass] - NODE 37: Creating new message for command No Operation
2017-06-15 10:59:46.150 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - queued packet. Queue length is 1
2017-06-15 10:59:46.150 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 37: Putting message SendData in wakeup queue.
2017-06-15 10:59:46.150 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2017-06-15 10:59:46.150 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Setting ONLINE
2017-06-15 10:59:46.150 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 37: Node Status event - Node is ALIVE
2017-06-15 10:59:46.150 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Incoming command class ALARM
2017-06-15 10:59:46.151 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: Received ALARM command V5
2017-06-15 10:59:46.151 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: Process NOTIFICATION_REPORT V5
2017-06-15 10:59:46.151 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: NOTIFICATION report - 0 = 0, event=22, status=255
2017-06-15 10:59:46.151 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: Alarm Type = ACCESS_CONTROL (0)
2017-06-15 10:59:46.151 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: CC event during initialisation stage IDLE
2017-06-15 10:59:46.151 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2017-06-15 10:59:46.151 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got a value event from Z-Wave network, endpoint = 0, command class = ALARM, value = 255
2017-06-15 10:59:46.167 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Application Command Request (ALIVE:DETAILS)
2017-06-15 10:59:46.167 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Incoming command class SENSOR_BINARY
2017-06-15 10:59:46.167 [DEBUG] [dclass.ZWaveBinarySensorCommandClass] - NODE 37: Received SENSOR_BINARY command V2
2017-06-15 10:59:46.167 [DEBUG] [dclass.ZWaveBinarySensorCommandClass] - NODE 37: Sensor Binary report, type=Unknown, value=255
2017-06-15 10:59:46.167 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveBinarySensorValueEvent
2017-06-15 10:59:46.167 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_BINARY, value = 255
2017-06-15 10:59:46.827 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Application Command Request (ALIVE:DETAILS)
2017-06-15 10:59:46.827 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Incoming command class ALARM
2017-06-15 10:59:46.827 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: Received ALARM command V5
2017-06-15 10:59:46.827 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: Process NOTIFICATION_REPORT V5
2017-06-15 10:59:46.827 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: NOTIFICATION report - 0 = 0, event=23, status=255
2017-06-15 10:59:46.827 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: Alarm Type = ACCESS_CONTROL (0)
2017-06-15 10:59:46.827 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2017-06-15 10:59:46.827 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got a value event from Z-Wave network, endpoint = 0, command class = ALARM, value = 255
2017-06-15 10:59:46.844 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Application Command Request (ALIVE:DETAILS)
2017-06-15 10:59:46.844 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Incoming command class SENSOR_BINARY
2017-06-15 10:59:46.844 [DEBUG] [dclass.ZWaveBinarySensorCommandClass] - NODE 37: Received SENSOR_BINARY command V2
2017-06-15 10:59:46.844 [DEBUG] [dclass.ZWaveBinarySensorCommandClass] - NODE 37: Sensor Binary report, type=Unknown, value=0
2017-06-15 10:59:46.844 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveBinarySensorValueEvent
2017-06-15 10:59:46.844 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_BINARY, value = 0
2017-06-15 11:11:40.899 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Application Command Request (ALIVE:DETAILS)
2017-06-15 11:11:40.899 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Incoming command class ALARM
2017-06-15 11:11:40.899 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: Received ALARM command V5
2017-06-15 11:11:40.899 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: Process NOTIFICATION_REPORT V5
2017-06-15 11:11:40.899 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: NOTIFICATION report - 0 = 0, event=3, status=255
2017-06-15 11:11:40.899 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: Alarm Type = BURGLAR (0)
2017-06-15 11:11:40.900 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2017-06-15 11:11:40.900 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got a value event from Z-Wave network, endpoint = 0, command class = ALARM, value = 255

chris · June 15, 2017, 6:25pm

I don’t see any wakeup in the logs - have you tried to wake the device up? This is needed to allow the binding to initialise the device.

Normally there’s a button you can press a few times to wake it up - check the manual as it will depend on the device…

mccormack · June 15, 2017, 6:49pm

Hi Chris,

I have tried to wake up the device numerous times. Right now it’s sitting right next to the controller. Look below at the log.

Thanks for the quick response!

This is the output when I press the button on the device:

2017-06-15 11:40:35.445 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Application Command Request (ALIVE:DETAILS)
2017-06-15 11:40:35.445 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Incoming command class WAKE_UP
2017-06-15 11:40:35.445 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 37: Received Wake Up Request
2017-06-15 11:40:35.445 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 37: Received WAKE_UP_NOTIFICATION
2017-06-15 11:40:35.445 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 37: Is awake with 1 messages in the wake-up queue.
2017-06-15 11:40:35.445 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Wakeup during initialisation.
2017-06-15 11:40:35.445 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - DETAILS: queue length(1), free to send(false)
2017-06-15 11:40:35.445 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - queued packet. Queue length is 1
2017-06-15 11:40:35.445 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveWakeUpEvent
2017-06-15 11:40:35.446 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 37: Sending REQUEST Message = 01 08 00 13 25 01 00 25 24 C1 
2017-06-15 11:40:35.456 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 37: Sent Data successfully placed on stack.
2017-06-15 11:40:35.472 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 37: SendData Request. CallBack ID = 36, Status = Transmission complete and ACK received(0)
2017-06-15 11:40:35.472 [WARN ] [l.serialmessage.SendDataMessageClass] - NODE 37: Already processed another send data request for this callback Id, ignoring.
2017-06-15 11:40:40.447 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 37: Timeout while sending message. Requeueing - 0 attempts left!
2017-06-15 11:40:40.447 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 37: Is sleeping
2017-06-15 11:40:40.447 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 37: Putting message SendData in wakeup queue.
2017-06-15 11:40:40.447 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 37: Message already on the wake-up queue. Removing original.
2017-06-15 11:40:40.447 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 37: Putting message SendData in wakeup queue.

mccormack · June 15, 2017, 6:49pm

And this is what happens when I remove and reinsert the battery:

2017-06-15 11:43:14.684 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 37: Application update request. Node information received.
2017-06-15 11:43:14.684 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 37: Is awake with 1 messages in the wake-up queue.
2017-06-15 11:43:14.684 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Wakeup during initialisation.
2017-06-15 11:43:14.684 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - DETAILS: queue length(1), free to send(false)
2017-06-15 11:43:14.684 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - queued packet. Queue length is 1
2017-06-15 11:43:14.684 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveWakeUpEvent
2017-06-15 11:43:14.685 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 37: Sending REQUEST Message = 01 08 00 13 25 01 00 25 38 DD 
2017-06-15 11:43:14.695 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 37: Sent Data successfully placed on stack.
2017-06-15 11:43:14.711 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 37: SendData Request. CallBack ID = 56, Status = Transmission complete and ACK received(0)
2017-06-15 11:43:14.711 [WARN ] [l.serialmessage.SendDataMessageClass] - NODE 37: Already processed another send data request for this callback Id, ignoring.
2017-06-15 11:43:16.510 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Application Command Request (ALIVE:DETAILS)
2017-06-15 11:43:16.510 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Incoming command class ALARM
2017-06-15 11:43:16.511 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: Received ALARM command V5
2017-06-15 11:43:16.511 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: Process NOTIFICATION_REPORT V5
2017-06-15 11:43:16.511 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: NOTIFICATION report - 0 = 0, event=3, status=255
2017-06-15 11:43:16.511 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: Alarm Type = BURGLAR (0)
2017-06-15 11:43:16.511 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2017-06-15 11:43:16.511 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got a value event from Z-Wave network, endpoint = 0, command class = ALARM, value = 255
2017-06-15 11:43:19.686 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 37: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=37, callback=57, payload=25 01 00 
2017-06-15 11:43:19.686 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 37: Sending REQUEST Message = 01 08 00 13 25 01 00 25 39 DC 
2017-06-15 11:43:19.696 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 37: Sent Data successfully placed on stack.
2017-06-15 11:43:19.712 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 37: SendData Request. CallBack ID = 57, Status = Transmission complete and ACK received(0)
2017-06-15 11:43:19.712 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - DETAILS: Transaction complete (SendData:Request) success(true)
2017-06-15 11:43:19.712 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - checking initialisation queue. Queue size 1.
2017-06-15 11:43:19.712 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - message removed from queue. Queue size 0.
2017-06-15 11:43:19.712 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - DETAILS: queue length(0), free to send(true)
2017-06-15 11:43:19.712 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - DETAILS try 2: stageAdvanced(false)
2017-06-15 11:43:19.712 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: Restored from file - skipping static initialisation
2017-06-15 11:43:19.712 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - advancing to GET_CONFIGURATION
2017-06-15 11:43:19.713 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-06-15 11:43:19.713 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - GET_CONFIGURATION try 0: stageAdvanced(true)
2017-06-15 11:43:19.713 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: GET_CONFIGURATION - thing is null!
2017-06-15 11:43:19.713 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - advancing to DYNAMIC_VALUES
2017-06-15 11:43:19.713 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-06-15 11:43:19.713 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - DYNAMIC_VALUES try 0: stageAdvanced(true)
2017-06-15 11:43:19.713 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking SENSOR_BINARY
2017-06-15 11:43:19.713 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - found    SENSOR_BINARY
2017-06-15 11:43:19.713 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Found 1 instances of SENSOR_BINARY
2017-06-15 11:43:19.713 [DEBUG] [dclass.ZWaveBinarySensorCommandClass] - NODE 37: Creating new message for application command SENSOR_BINARY_GET for DOORWINDOW
2017-06-15 11:43:19.713 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - queued packet. Queue length is 1
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking CONFIGURATION
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking ASSOCIATION_GROUP_INFO
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking WAKE_UP
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking DEVICE_RESET_LOCALLY
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking ZWAVE_PLUS_INFO
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking BATTERY
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - found    BATTERY
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Found 1 instances of BATTERY
2017-06-15 11:43:19.714 [DEBUG] [ommandclass.ZWaveBatteryCommandClass] - NODE 37: Creating new message for application command BATTERY_GET
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking POWERLEVEL
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - found    POWERLEVEL
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Found 1 instances of POWERLEVEL
2017-06-15 11:43:19.714 [DEBUG] [andclass.ZWavePowerLevelCommandClass] - NODE 37: Creating new message for application command POWERLEVEL_GET
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking NO_OPERATION
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking BASIC
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking MANUFACTURER_SPECIFIC
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking ASSOCIATION
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking VERSION
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking ALARM
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - found    ALARM
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Found 1 instances of ALARM
2017-06-15 11:43:19.714 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: Creating new message for application command NOTIFICATION_GET V5
2017-06-15 11:43:19.714 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - queued 4 frames
2017-06-15 11:43:19.714 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-06-15 11:43:19.715 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 37: Response processed after 27ms/3127ms.
2017-06-15 11:43:19.715 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 37: Sending REQUEST Message = 01 0A 00 13 25 03 30 02 0A 25 3B E6 
2017-06-15 11:43:19.725 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 37: Sent Data successfully placed on stack.
2017-06-15 11:43:19.741 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 37: SendData Request. CallBack ID = 59, Status = Transmission complete and ACK received(0)
2017-06-15 11:43:19.752 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Application Command Request (ALIVE:DYNAMIC_VALUES)
2017-06-15 11:43:19.752 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Incoming command class SENSOR_BINARY
2017-06-15 11:43:19.752 [DEBUG] [dclass.ZWaveBinarySensorCommandClass] - NODE 37: Received SENSOR_BINARY command V2
2017-06-15 11:43:19.752 [DEBUG] [dclass.ZWaveBinarySensorCommandClass] - NODE 37: Sensor Binary report, type=Unknown, value=0
2017-06-15 11:43:19.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveBinarySensorValueEvent
2017-06-15 11:43:19.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_BINARY, value = 0
2017-06-15 11:43:19.752 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - DYNAMIC_VALUES: Transaction complete (SendData:Request) success(true)
2017-06-15 11:43:19.753 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - checking initialisation queue. Queue size 4.
2017-06-15 11:43:19.753 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - message removed from queue. Queue size 3.
2017-06-15 11:43:19.753 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - DYNAMIC_VALUES: queue length(3), free to send(true)
2017-06-15 11:43:19.753 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - queued packet. Queue length is 3
2017-06-15 11:43:19.753 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-06-15 11:43:19.753 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 37: Response processed after 37ms/3127ms.
2017-06-15 11:43:19.753 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 37: Sending REQUEST Message = 01 09 00 13 25 02 80 02 25 3C 59 
2017-06-15 11:43:19.763 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 37: Sent Data successfully placed on stack.
2017-06-15 11:43:19.779 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 37: SendData Request. CallBack ID = 60, Status = Transmission complete and ACK received(0)
2017-06-15 11:43:19.790 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Application Command Request (ALIVE:DYNAMIC_VALUES)
2017-06-15 11:43:19.790 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Incoming command class BATTERY
2017-06-15 11:43:19.790 [DEBUG] [ommandclass.ZWaveBatteryCommandClass] - NODE 37: Received Battery Request
2017-06-15 11:43:19.790 [DEBUG] [ommandclass.ZWaveBatteryCommandClass] - NODE 37: Battery report value = 99
2017-06-15 11:43:19.790 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2017-06-15 11:43:19.790 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got a value event from Z-Wave network, endpoint = 0, command class = BATTERY, value = 99
2017-06-15 11:43:19.791 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - DYNAMIC_VALUES: Transaction complete (SendData:Request) success(true)
2017-06-15 11:43:19.791 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - checking initialisation queue. Queue size 3.
2017-06-15 11:43:19.791 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - message removed from queue. Queue size 2.
2017-06-15 11:43:19.791 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - DYNAMIC_VALUES: queue length(2), free to send(true)
2017-06-15 11:43:19.791 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - queued packet. Queue length is 2
2017-06-15 11:43:19.791 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-06-15 11:43:19.791 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 37: Response processed after 37ms/3127ms.
2017-06-15 11:43:19.791 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 37: Sending REQUEST Message = 01 09 00 13 25 02 73 02 25 3D AB 
2017-06-15 11:43:19.801 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 37: Sent Data successfully placed on stack.
2017-06-15 11:43:19.817 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 37: SendData Request. CallBack ID = 61, Status = Transmission complete and ACK received(0)
2017-06-15 11:43:19.828 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Application Command Request (ALIVE:DYNAMIC_VALUES)
2017-06-15 11:43:19.828 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Incoming command class POWERLEVEL
2017-06-15 11:43:19.828 [DEBUG] [andclass.ZWavePowerLevelCommandClass] - NODE 37: Received POWERLEVEL command V1
2017-06-15 11:43:19.828 [DEBUG] [andclass.ZWavePowerLevelCommandClass] - NODE 37: Received POWERLEVEL report -0dB with 0 second timeout
2017-06-15 11:43:19.829 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWavePowerLevelCommandClassChangeEvent
2017-06-15 11:43:19.829 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got a value event from Z-Wave network, endpoint = 0, command class = POWERLEVEL, value = 0
2017-06-15 11:43:19.829 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Config updated
2017-06-15 11:43:19.830 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - DYNAMIC_VALUES: Transaction complete (SendData:Request) success(true)
2017-06-15 11:43:19.830 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - checking initialisation queue. Queue size 2.
2017-06-15 11:43:19.830 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - message removed from queue. Queue size 1.
2017-06-15 11:43:19.830 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - DYNAMIC_VALUES: queue length(1), free to send(true)
2017-06-15 11:43:19.830 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - queued packet. Queue length is 1
2017-06-15 11:43:19.830 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-06-15 11:43:19.830 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 37: Response processed after 38ms/3127ms.
2017-06-15 11:43:19.830 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 37: Sending REQUEST Message = 01 0C 00 13 25 05 71 04 00 07 03 25 3E AA 
2017-06-15 11:43:19.840 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 37: Sent Data successfully placed on stack.
2017-06-15 11:43:19.857 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 37: SendData Request. CallBack ID = 62, Status = Transmission complete and ACK received(0)
2017-06-15 11:43:19.869 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Application Command Request (ALIVE:DYNAMIC_VALUES)
2017-06-15 11:43:19.869 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 37: Incoming command class ALARM
2017-06-15 11:43:19.869 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: Received ALARM command V5
2017-06-15 11:43:19.870 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: Process NOTIFICATION_REPORT V5
2017-06-15 11:43:19.870 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: NOTIFICATION report - 0 = 0, event=3, status=255
2017-06-15 11:43:19.870 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 37: Alarm Type = BURGLAR (0)
2017-06-15 11:43:19.870 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2017-06-15 11:43:19.870 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got a value event from Z-Wave network, endpoint = 0, command class = ALARM, value = 255
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - DYNAMIC_VALUES: Transaction complete (SendData:Request) success(true)
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - checking initialisation queue. Queue size 1.
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - message removed from queue. Queue size 0.
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - DYNAMIC_VALUES: queue length(0), free to send(true)
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - DYNAMIC_VALUES try 1: stageAdvanced(false)
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking SENSOR_BINARY
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - found    SENSOR_BINARY
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Found 1 instances of SENSOR_BINARY
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking CONFIGURATION
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking ASSOCIATION_GROUP_INFO
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking WAKE_UP
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking DEVICE_RESET_LOCALLY
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking ZWAVE_PLUS_INFO
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking BATTERY
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - found    BATTERY
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Found 1 instances of BATTERY
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking POWERLEVEL
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - found    POWERLEVEL
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Found 1 instances of POWERLEVEL
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking NO_OPERATION
2017-06-15 11:43:19.870 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking BASIC
2017-06-15 11:43:19.871 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking MANUFACTURER_SPECIFIC
2017-06-15 11:43:19.871 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking ASSOCIATION
2017-06-15 11:43:19.871 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking VERSION
2017-06-15 11:43:19.871 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - checking ALARM
2017-06-15 11:43:19.871 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - found    ALARM
2017-06-15 11:43:19.871 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Found 1 instances of ALARM
2017-06-15 11:43:19.871 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: DYNAMIC_VALUES - queued 0 frames
2017-06-15 11:43:19.871 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - advancing to DYNAMIC_END
2017-06-15 11:43:19.871 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-06-15 11:43:19.871 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - DYNAMIC_END try 0: stageAdvanced(true)
2017-06-15 11:43:19.871 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 37: Serializing to file C:\OpenHab2\userdata\zwave\node37.xml
2017-06-15 11:43:19.877 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - advancing to HEAL_START
2017-06-15 11:43:19.878 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-06-15 11:43:19.878 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - HEAL_START try 0: stageAdvanced(true)
2017-06-15 11:43:19.878 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - advancing to DELETE_ROUTES
2017-06-15 11:43:19.878 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-06-15 11:43:19.878 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - DELETE_ROUTES try 0: stageAdvanced(true)
2017-06-15 11:43:19.878 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 37: Generate return routes list
2017-06-15 11:43:19.878 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer is deleting return routes.
2017-06-15 11:43:19.878 [DEBUG] [essage.DeleteReturnRouteMessageClass] - NODE 37: Deleting return routes
2017-06-15 11:43:19.878 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - queued packet. Queue length is 1
2017-06-15 11:43:19.878 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-06-15 11:43:19.878 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 37: Response processed after 47ms/3127ms.
2017-06-15 11:43:19.887 [DEBUG] [essage.DeleteReturnRouteMessageClass] - NODE 37: Got DeleteReturnRoute response.
2017-06-15 11:43:19.887 [DEBUG] [essage.DeleteReturnRouteMessageClass] - NODE 37: DeleteReturnRoute command in progress.
2017-06-15 11:43:19.966 [DEBUG] [essage.DeleteReturnRouteMessageClass] - NODE 37: Got DeleteReturnRoute request.
2017-06-15 11:43:19.966 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveNetworkEvent
2017-06-15 11:43:19.967 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - DELETE_ROUTES: Transaction complete (DeleteReturnRoute:Request) success(true)
2017-06-15 11:43:19.967 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - checking initialisation queue. Queue size 1.
2017-06-15 11:43:19.967 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - message removed from queue. Queue size 0.
2017-06-15 11:43:19.967 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - DELETE_ROUTES: queue length(0), free to send(true)
2017-06-15 11:43:19.967 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - DELETE_ROUTES try 1: stageAdvanced(false)
2017-06-15 11:43:19.967 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - advancing to RETURN_ROUTES
2017-06-15 11:43:19.967 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-06-15 11:43:19.967 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - RETURN_ROUTES try 0: stageAdvanced(true)
2017-06-15 11:43:19.967 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 37: Generate return routes list
2017-06-15 11:43:19.967 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Adding return route to 1
2017-06-15 11:43:19.967 [DEBUG] [essage.AssignReturnRouteMessageClass] - NODE 37: Assigning return route to node 1
2017-06-15 11:43:19.967 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - queued packet. Queue length is 1
2017-06-15 11:43:19.982 [DEBUG] [essage.AssignReturnRouteMessageClass] - NODE 37: Got AssignReturnRoute response.
2017-06-15 11:43:19.982 [DEBUG] [essage.AssignReturnRouteMessageClass] - NODE 37: AssignReturnRoute command in progress.
2017-06-15 11:43:20.695 [DEBUG] [essage.AssignReturnRouteMessageClass] - NODE 37: Got AssignReturnRoute request.
2017-06-15 11:43:20.695 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveNetworkEvent
2017-06-15 11:43:20.695 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - RETURN_ROUTES: Transaction complete (AssignReturnRoute:Request) success(true)
2017-06-15 11:43:20.696 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - checking initialisation queue. Queue size 1.
2017-06-15 11:43:20.696 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - message removed from queue. Queue size 0.
2017-06-15 11:43:20.696 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - RETURN_ROUTES: queue length(0), free to send(true)
2017-06-15 11:43:20.696 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - RETURN_ROUTES try 1: stageAdvanced(false)
2017-06-15 11:43:20.696 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - advancing to NEIGHBORS
2017-06-15 11:43:20.696 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-06-15 11:43:20.696 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - NEIGHBORS try 0: stageAdvanced(true)
2017-06-15 11:43:20.696 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: NEIGHBORS - get RoutingInfo
2017-06-15 11:43:20.696 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 37: Request routing info
2017-06-15 11:43:20.696 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - queued packet. Queue length is 1
2017-06-15 11:43:20.703 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 37: Got NodeRoutingInfo request.
2017-06-15 11:43:20.703 [DEBUG] [almessage.GetRoutingInfoMessageClass] - NODE 37: Neighbor nodes: 1 3 4 6 7 8 11 12 13 15 16 17 18 19 28 30
2017-06-15 11:43:20.703 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveNetworkEvent
2017-06-15 11:43:20.704 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - NEIGHBORS: Transaction complete (GetRoutingInfo:Request) success(true)
2017-06-15 11:43:20.704 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - checking initialisation queue. Queue size 1.
2017-06-15 11:43:20.704 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - message removed from queue. Queue size 0.
2017-06-15 11:43:20.704 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - NEIGHBORS: queue length(0), free to send(true)
2017-06-15 11:43:20.704 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - NEIGHBORS try 1: stageAdvanced(false)
2017-06-15 11:43:20.704 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer - advancing to DONE
2017-06-15 11:43:20.704 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-06-15 11:43:20.704 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Updating node properties.
2017-06-15 11:43:20.704 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Updating node properties. MAN=330
2017-06-15 11:43:20.704 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Updating node properties. MAN=330. SET. Was 330
2017-06-15 11:43:20.705 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: loop - DONE try 0: stageAdvanced(true)
2017-06-15 11:43:20.705 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 37: Serializing to file C:\OpenHab2\userdata\zwave\node37.xml
2017-06-15 11:43:20.711 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Node advancer: Initialisation complete!
2017-06-15 11:43:20.711 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveInitializationStateEvent
2017-06-15 11:43:20.711 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Updating node properties.
2017-06-15 11:43:20.711 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Updating node properties. MAN=330
2017-06-15 11:43:20.711 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Updating node properties. MAN=330. SET. Was 330
2017-06-15 11:43:21.711 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 37: No more messages, go back to sleep
2017-06-15 11:43:21.711 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 37: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
2017-06-15 11:43:21.712 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 37: Sending REQUEST Message = 01 09 00 13 25 02 84 08 25 41 2A 
2017-06-15 11:43:21.722 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 37: Sent Data successfully placed on stack.
2017-06-15 11:43:21.738 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 37: SendData Request. CallBack ID = 65, Status = Transmission complete and ACK received(0)
2017-06-15 11:43:21.738 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 37: Starting initialisation from DONE
2017-06-15 11:43:21.738 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 37: Went to sleep
2017-06-15 11:43:21.738 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 37: Is sleeping
2017-06-15 11:43:21.738 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 37: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent

chris · June 16, 2017, 10:24am

Initialisation looks fine now. What is the problem you’re having specifically? Is it showing as unknown or something?

If so, please provide the device type/id that HABmin / PaperUI provides and we can check if it’s the same as in the database.

Also, what version of the binding are you running (or what version of OH2 are you running)?

mccormack · June 16, 2017, 1:59pm

Hi Chris,

Running OH2 2.0.0. and ZWave 2.0.0. See screenshots for details.

Thanks,

chris · June 16, 2017, 2:42pm

I would suggest to change to using the snapshot binding as the device should be supported in that.

mccormack · June 16, 2017, 2:47pm

Can you advise me on the best way to upgrade on a Windows machine?

Thanks

chris · June 16, 2017, 3:02pm

Sorry - not really as I don’t have a Windows machine. I would guess it’s a case of downloading the snapshot runtime and installing that over your existing installation - it shouldn’t impact your configuration…

Probably best is to check the docs, and if there’s nothing there then check or ask on the forum.

mccormack · June 16, 2017, 7:42pm

Hey Chris,

You were right. I upgraded to 2.1.0 and it is now recognized. A lot of other stuff broke in the upgrade but that’s for another topic.

Thanks again for the help!