[Solved] NEO (Shenzen) Z-Wave Motion Sensor in Openhab 3 does not work

[apella12 (Bob Eckhoff)]

Generally, for battery devices, this means they are not fully configured. Do you have an XML file for the node in userdata/zwave? Also are there five lines at the bottom of the UI page for the device?

If not try to wake the device a few times until you get those signs. The other channels should work then

Bob

Edit: I also could not find the device in the database (with the number you provided, but a similar one has undergone recent modifications, so that could be an issue as well.
Under thing properties this information would be helpful to see what device it is

[krishkal (Kal Krishnan)]

Hi Bob, thanks for jumping on this.

As you suspected, the XML does NOT exist for Node 23, and there are only 4 lines at the bottom of the UI page (missing “Reinitialize the device”). I tried waking it up a number of times, to no avail. It does not seem to want to get fully configured. Attached is the manufactureid reference information:

[chris (Chris Jackson)]

The device is in the database -:

Shenzhen Neo Electronics Co., Ltd Motion Sensor 2

From the small log above we can see that the binding is waiting for the device to wake up - it is right at the beginning of the initialisation phase and needs waking. If you’re trying to wake it, then you might try different sequences as some of these chinese devices don’t always wake up as the manual states.

[krishkal (Kal Krishnan)]

Here is a more extended log from when I wake up the device… does this give any clues as to what is going wrong?

2021-12-06 02:59:22.383 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2021-12-06 02:59:22.384 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2021-12-06 02:59:22.384 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-12-06 02:59:22.385 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-12-06 02:59:39.968 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 16 00 49 84 17 10 04 07 01 5E 86 72 5A 73 80 31 71 30 70 85 59 84 7A 
2021-12-06 02:59:39.976 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=23, callback=132, payload=84 17 10 04 07 01 5E 86 72 5A 73 80 31 71 30 70 85 59 84 
2021-12-06 02:59:39.978 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=23, callback=132, payload=84 17 10 04 07 01 5E 86 72 5A 73 80 31 71 30 70 85 59 84 
2021-12-06 02:59:39.980 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2021-12-06 02:59:39.981 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2021-12-06 02:59:39.981 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2021-12-06 02:59:39.983 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=23, callback=132, payload=84 17 10 04 07 01 5E 86 72 5A 73 80 31 71 30 70 85 59 84 
2021-12-06 02:59:39.985 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 23: Application update request. Node information received. Transaction null
2021-12-06 02:59:39.986 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 23: Application update - no transaction.
2021-12-06 02:59:39.989 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-12-06 02:59:39.990 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-12-06 02:59:40.239 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 23: Is awake with 1 messages in the queue
2021-12-06 02:59:40.241 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 23: Start sleep timer at 5000ms
2021-12-06 02:59:40.242 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2021-12-06 02:59:40.253 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 23: Node Status event - Node is AWAKE
2021-12-06 02:59:42.743 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 23: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES
2021-12-06 02:59:45.243 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 23: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES
2021-12-06 02:59:45.246 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 23: No more messages, go back to sleep
2021-12-06 02:59:45.247 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 23: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
2021-12-06 02:59:45.247 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 23: SECURITY not supported
2021-12-06 02:59:45.249 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 23: Command Class COMMAND_CLASS_WAKE_UP is NOT required to be secured
2021-12-06 02:59:45.249 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@508733
2021-12-06 02:59:45.251 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: Bump transaction 2012 priority from Immediate to Immediate
2021-12-06 02:59:45.253 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: Adding to device queue
2021-12-06 02:59:45.255 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: Added 2012 to queue - size 11
2021-12-06 02:59:45.256 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-12-06 02:59:45.257 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 13 17 04 59 05 00 01 25 37 BB 
2021-12-06 02:59:45.260 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 23: Sending REQUEST Message = 01 0B 00 13 17 04 59 05 00 01 25 37 BB 
2021-12-06 02:59:45.264 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2021-12-06 02:59:45.265 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-12-06 02:59:45.266 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-12-06 02:59:45.266 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2021-12-06 02:59:45.267 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2021-12-06 02:59:45.268 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-12-06 02:59:45.282 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2021-12-06 02:59:45.283 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 1966: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 55
2021-12-06 02:59:45.285 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-12-06 02:59:45.471 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2021-12-06 02:59:45.475 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2021-12-06 02:59:45.476 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2021-12-06 02:59:45.477 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1966: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 55
2021-12-06 02:59:45.478 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2021-12-06 02:59:45.479 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 1966: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 55
2021-12-06 02:59:45.480 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2021-12-06 02:59:45.482 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 23: sentData successfully placed on stack.
2021-12-06 02:59:45.483 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 1966: Advanced to WAIT_REQUEST
2021-12-06 02:59:45.484 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: TID 1966: Transaction not completed
2021-12-06 02:59:45.485 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-12-06 02:59:45.486 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-12-06 02:59:45.537 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 37 00 DE 
2021-12-06 02:59:45.541 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=55, payload=37 00 
2021-12-06 02:59:45.542 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=55, payload=37 00 
2021-12-06 02:59:45.543 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1966: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 55
2021-12-06 02:59:45.544 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2021-12-06 02:59:45.545 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 1966: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 55
2021-12-06 02:59:45.546 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 1966: (Callback 55)
2021-12-06 02:59:45.547 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2021-12-06 02:59:45.548 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 1966: callback 55
2021-12-06 02:59:45.549 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=55, payload=37 00 
2021-12-06 02:59:45.551 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 23: SendData Request. CallBack ID = 55, Status = Transmission complete and ACK received(0)
2021-12-06 02:59:45.552 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 1966: Advanced to WAIT_DATA
2021-12-06 02:59:45.553 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: TID 1966: Transaction not completed
2021-12-06 02:59:45.554 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-12-06 02:59:45.555 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-12-06 02:59:45.616 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 17 0E 59 06 01 0A 80 03 71 05 30 03 31 05 5A 01 09 
2021-12-06 02:59:45.620 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=23, callback=0, payload=00 17 0E 59 06 01 0A 80 03 71 05 30 03 31 05 5A 01 
2021-12-06 02:59:45.621 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=23, callback=0, payload=00 17 0E 59 06 01 0A 80 03 71 05 30 03 31 05 5A 01 
2021-12-06 02:59:45.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2021-12-06 02:59:45.623 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: Application Command Request (ALIVE:STATIC_VALUES)
2021-12-06 02:59:45.624 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 23: Incoming command class COMMAND_CLASS_ASSOCIATION_GRP_INFO, endpoint 0
2021-12-06 02:59:45.625 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 23: SECURITY not supported
2021-12-06 02:59:45.626 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 23: Received COMMAND_CLASS_ASSOCIATION_GRP_INFO V1 ASSOCIATION_GROUP_INFO_LIST_REPORT
2021-12-06 02:59:45.627 [DEBUG] [WaveAssociationGroupInfoCommandClass] - NODE 23: Supported Command classes and commands for group:1 ->
2021-12-06 02:59:45.629 [DEBUG] [WaveAssociationGroupInfoCommandClass] - NODE 23:   COMMAND_CLASS_BATTERY command:3
2021-12-06 02:59:45.630 [DEBUG] [WaveAssociationGroupInfoCommandClass] - NODE 23:   COMMAND_CLASS_ALARM command:5
2021-12-06 02:59:45.634 [DEBUG] [WaveAssociationGroupInfoCommandClass] - NODE 23:   COMMAND_CLASS_SENSOR_BINARY command:3
2021-12-06 02:59:45.635 [DEBUG] [WaveAssociationGroupInfoCommandClass] - NODE 23:   COMMAND_CLASS_SENSOR_MULTILEVEL command:5
2021-12-06 02:59:45.636 [DEBUG] [WaveAssociationGroupInfoCommandClass] - NODE 23:   COMMAND_CLASS_DEVICE_RESET_LOCALLY command:1
2021-12-06 02:59:45.637 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: Commands processed 1.
2021-12-06 02:59:45.637 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@18f6a0a.
2021-12-06 02:59:45.638 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@18f6a0a.
2021-12-06 02:59:45.639 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: notifyTransactionResponse TID:1966 DONE
2021-12-06 02:59:45.640 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2021-12-06 02:59:45.640 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 1966: Transaction event listener: DONE: DONE -> 
2021-12-06 02:59:45.641 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2021-12-06 02:59:45.642 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 23: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@173c4aa
2021-12-06 02:59:45.642 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2021-12-06 02:59:45.642 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 23: Node Init transaction completed with response COMPLETE
2021-12-06 02:59:45.643 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-12-06 02:59:45.643 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 23: SECURITY not supported
2021-12-06 02:59:45.644 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 23: Command Class COMMAND_CLASS_ASSOCIATION_GRP_INFO is NOT required to be secured
2021-12-06 02:59:45.644 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2021-12-06 02:59:45.645 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 23: ZWaveCommandClassTransactionPayload - send to node
2021-12-06 02:59:45.645 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 17 02 84 08 25 38 61 
2021-12-06 02:59:45.646 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 23: SECURITY not supported
2021-12-06 02:59:45.646 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 23: Command Class COMMAND_CLASS_ASSOCIATION_GRP_INFO is NOT required to be secured
2021-12-06 02:59:45.646 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 23: Sending REQUEST Message = 01 09 00 13 17 02 84 08 25 38 61 
2021-12-06 02:59:45.647 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@14cc4a2
2021-12-06 02:59:45.648 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: Bump transaction 2013 priority from Config to Immediate
2021-12-06 02:59:45.649 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2021-12-06 02:59:45.650 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-12-06 02:59:45.652 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2021-12-06 02:59:45.663 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2021-12-06 02:59:45.664 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 2012: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 56
2021-12-06 02:59:45.665 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2021-12-06 02:59:45.665 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: Adding to device queue
2021-12-06 02:59:45.665 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2021-12-06 02:59:45.666 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: Added 2013 to queue - size 10
2021-12-06 02:59:45.666 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2012: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 56
2021-12-06 02:59:45.667 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2021-12-06 02:59:45.667 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-12-06 02:59:45.668 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2021-12-06 02:59:45.668 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2012: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 56
2021-12-06 02:59:45.669 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2021-12-06 02:59:45.669 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 2012: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 56
2021-12-06 02:59:45.670 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2021-12-06 02:59:45.671 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 23: sentData successfully placed on stack.
2021-12-06 02:59:45.672 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 2012: Advanced to WAIT_REQUEST
2021-12-06 02:59:45.672 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: TID 2012: Transaction not completed
2021-12-06 02:59:45.673 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-12-06 02:59:45.673 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2021-12-06 02:59:45.718 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 38 00 D1 
2021-12-06 02:59:45.722 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=56, payload=38 00 
2021-12-06 02:59:45.724 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=56, payload=38 00 
2021-12-06 02:59:45.725 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 2012: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 56
2021-12-06 02:59:45.726 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2021-12-06 02:59:45.726 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 2012: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 56
2021-12-06 02:59:45.727 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 2012: (Callback 56)
2021-12-06 02:59:45.728 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2021-12-06 02:59:45.729 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 2012: callback 56
2021-12-06 02:59:45.730 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=56, payload=38 00 
2021-12-06 02:59:45.731 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 23: SendData Request. CallBack ID = 56, Status = Transmission complete and ACK received(0)
2021-12-06 02:59:45.732 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 2012: Transaction COMPLETED
2021-12-06 02:59:45.733 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: Response processed after 69ms
2021-12-06 02:59:45.734 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: TID 2012: Transaction completed
2021-12-06 02:59:45.735 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: notifyTransactionResponse TID:2012 DONE
2021-12-06 02:59:45.736 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2021-12-06 02:59:45.736 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 2012: Transaction event listener: DONE: DONE -> 
2021-12-06 02:59:45.737 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2021-12-06 02:59:45.737 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 23: Went to sleep COMPLETE
2021-12-06 02:59:45.738 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

[apella12 (Bob Eckhoff)]

The good news is you generated an “awake” message. I have seen what Chris reports as well

@chris

If you’re trying to wake it, then you might try different sequences as some of these chinese devices don’t always wake up as the manual states.

However, despite having an initialization message in the node queue, nothing happens for about 5 seconds, but one configuration message gets through (presumably the one in the queue) right before the “go back to Sleep” message is generated (also despite a message in the queue) and sent, and the node is asleep again.

I don’t see (in the log) why the message in the queue takes so long to get sent, but at one command per “wake”, configuration will take a while. Hopefully after one of the “wakes” the full 5 seconds can be used to send initialization messages. Five seconds of continuous initialization messages is enough to configure most battery devices (based on my testing).

At this point try to wake the device a few more times. It will only take one “wake” without the delay to get configured (IMO).

Bob

edit: As to the delay, it almost seems like the “Go to Sleep” message being created prompts the queued initialization message to be sent. @chris Is that possible??

[krishkal (Kal Krishnan)]

Thanks, Bob. The problem is that there is only 1 physical button in the device. And, according to documentation, you push it quickly 3 consecutive times to start the initialization process (either include or exclude mode on the controller), and you push it just once to “wake up”.

When I do the “push once to wake up”, while tailing the log, I see the red led flash once (consistent with documentation), but I see NO activity in the log whatsoever. The only way I have found to generate any activity in the log is to push 3 times quickly and then I get stuff as posted above. But, I am afraid that pushing 3 times on the device “initializes” the device, and previous commands are lost? I have been at this for more than a day now, and it is getting frustrating for sure!

Is it possible that something went wrong somewhere along the way, and the only way to recover is to delete and re-add the device? What would be the safest way to delete it completely and start fresh?

[krishkal (Kal Krishnan)]

OK, I have tried the following things:

1. First removed the device from controller, then delete device, then re-add it using the usual inclusion. It just gets to the same spot as before and is stuck. “Waking” by pressing the button 3 times again goes through the same 5 second process, and ends up at the same place, no matter how many times I do it.

2. Then I tried going into “exclusion” mode, and excluded the device (hoping that will reset something in the device itself). Then deleted the thing, and re-added it with the usual inclusion procedure. No joy, get to the exact same spot (except that this time it got added as Node 24 instead of Node 23 that it was previously).

To summarize various things I have said before -

1. “Waking” the device by the documentation suggested method (single press of button) flashes the LED once (consistent with documentation), but produces nothing in the log.
2. “Waking” by the triple press of the button does produced stuff in the log, but ends up in the same spot where it began, nothing appears to progress to a state of completion.
3. The temperature reading does reliably get sent periodically to the controller and can be seen on the GUI and in the logs. Question, when the temperature reading is received, why is that not considered a “wake up” event? Is the assumption that the device wakes up, sends that message, and quickly goes back to sleep?

Is there a back-door way to see what kinds of messages are in the queue that do not get delivered to the device? I am wondering if those are really necessary messages, or some “nice to have” things that are keeping the device initialization from completing.

Any other suggestions, before I just give up on this device?

[apella12 (Bob Eckhoff)]

Without dragging this issue into the back and forth I have had with @chris regarding battery devices, I can’t suggest anything more than the wake-up suggestion. Maybe Chris with far deeper expertise will have another idea.

Without seeing the additional logs, it hard to assess whether the device is at the exact same spot or just making very slow progress. Some messages have to be sent twice so could appear to be the same. I was out and about, so could not respond to the retry idea, but I’m not surprised by the results. There is not enough time allowed after discovery to configure the device completely, so rewaking is needed.

@krishkal

Question, when the temperature reading is received, why is that not considered a “wake up” event? Is the assumption that the device wakes up, sends that message, and quickly goes back to sleep?

Short answer is that the sensor does not wakeup to send readings. That raises a question are you far enough in the initialization that the lifeline & wake-up interval is set? If yes, it should eventually configure itself on its own.

@krishkal

Is there a back-door way to see what kinds of messages are in the queue that do not get delivered to the device? I am wondering if those are really necessary messages, or some “nice to have” things that are keeping the device initialization from completing

I do not know of any backdoors. I believe that the messages are basically predetermined after the discovery (scan) reads the node Information frame (NIF) and all are needed based on that.

Sorry I can’t help more.

Bob

[krishkal (Kal Krishnan)]

I manually set the Association Groups to Controller, and it seemed to work fine:

Also, when I did that, I found the following snippet in the log:

2021-12-06 20:40:56.018 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Handler disposed. Unregistering listener.
2021-12-06 20:40:56.088 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 24: Serialise aborted as static stages not complete
2021-12-06 20:40:56.089 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:ZStickS2:node24.
2021-12-06 20:40:56.091 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Controller status changed to ONLINE.
2021-12-06 20:40:56.092 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Controller is ONLINE. Starting device initialisation.
2021-12-06 20:40:56.096 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Updating node properties.
2021-12-06 20:40:56.097 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Updating node properties. MAN=600
2021-12-06 20:40:56.098 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Updating node properties. MAN=600. SET. Was 600
2021-12-06 20:40:56.099 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Properties synchronised
2021-12-06 20:40:56.328 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2021-12-06 20:40:56.329 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Initialising Thing Node...
2021-12-06 20:40:56.330 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Initialising cmd channel zwave:device:ZStickS2:node24:sensor_binary for OnOffType
2021-12-06 20:40:56.330 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Initialising state channel zwave:device:ZStickS2:node24:sensor_binary for OnOffType
2021-12-06 20:40:56.332 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Initialising cmd channel zwave:device:ZStickS2:node24:sensor_luminance for DecimalType
2021-12-06 20:40:56.332 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Initialising state channel zwave:device:ZStickS2:node24:sensor_luminance for DecimalType
2021-12-06 20:40:56.333 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Initialising cmd channel zwave:device:ZStickS2:node24:sensor_temperature for QuantityType
2021-12-06 20:40:56.334 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Initialising state channel zwave:device:ZStickS2:node24:sensor_temperature for QuantityType
2021-12-06 20:40:56.335 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Initialising cmd channel zwave:device:ZStickS2:node24:alarm_burglar for OnOffType
2021-12-06 20:40:56.336 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Initialising state channel zwave:device:ZStickS2:node24:alarm_burglar for OnOffType
2021-12-06 20:40:56.336 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Initialising cmd channel zwave:device:ZStickS2:node24:battery-level for PercentType
2021-12-06 20:40:56.337 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Initialising state channel zwave:device:ZStickS2:node24:battery-level for PercentType
2021-12-06 20:40:56.338 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Polling initialised at 1800 seconds - start in 214200 milliseconds.
2021-12-06 20:40:56.339 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Device initialisation complete.

So, does the “Device initialization complete” mean something? I still don’t find the 5 entries at the bottom of the Thing page, so not sure what it means.

[krishkal (Kal Krishnan)]

Hi @chris , any suggestions or comments? I am especially interested in the observation that the documented “wake up” procedure does nothing while the “triple click” does produce some effect in the log. Should I be continuing to use multiple triple clicks to do things? How do I know if any progress is actually being made in terms of the queue of messages (supposedly) waiting to be sent? I am not able to figure it out from the log.

[apella12 (Bob Eckhoff)]

That is an intermediate “Device initialization complete”. The problem message is at 20:40:56.088 "static stages not complete.

So I have to ask based on another thread. You are not pairing the node using a Zstick button and then sticking in OH right? The pairing needs to be done while the zstick is in the OH server.

Bob

[krishkal (Kal Krishnan)]

Correct. I am pairing using the GUI Add, then Scan, then select the discovered device to add. The ZStick is firmly planted in the Raspbian server!

[apella12 (Bob Eckhoff)]

It was worth a shot. The referenced thread had similar Debug entries when setting the lifeline to the controller and that was the problem on that one.

Nothing else from me, sorry

Bob

[krishkal (Kal Krishnan)]

I am trying to upload the whole openhab.log file, but it is too big (>3MB). I can zip it, and it is smaller, but this interface won’t allow me to upload zips. Is there a way to solve this? Would it even be helpful to get the whole log file up there?

[krishkal (Kal Krishnan)]

I saw the following in an Amazon review of the product. This has to do with Domoticz software, but I am wondering if what he says has some relevance for Openhab. @apella12 or @chris does this make any sense to you?

Updated Review July 2019:
I bought 2 more to add to my security network. The name changed when I added it to my Domoticz V4.10717; the new “Shenzhen Neo Electronics Co Ltd Battery Powered PIR Sensor V2+” the old “Neo CoolCam Battery Powered PIR Sensor+”. Shenzen-Neo updated the Open Zwave xml file incorrectly in Dec 2018. I updated the “manufacturer_specific.xml” file by changing the coding "Product type=“0003” id=“108d” name=“Battery Powered PIR Sensor V2” config=“shenzen_neo/nas-pd02z.xml”/> to "Product type=“0003” id=“008d” name=“Battery Powered PIR Sensor V2” config=“shenzen_neo/nas-pd02z.xml”/> when I noticed it added as ID=008d to Domoticz instead of ID=108d. This change made it work. If you are not tech savvy enough to make this change then I doubt it will work for you. This could also be a Domoticz error instead of Shenzen-Neo, but I doubt it. The newer version does not update from the queue as easily as the previous version. If you press the wake up button then send updates it works OK, but may take a few tries.

[apella12 (Bob Eckhoff)]

@krishkal 1) As to the big file, some use some kind of service. I have not done that to date, so cannot advise. I did see in this post a 10MB file using a google drive of some sort. 2) As to the need, it would be to determine if it is really stuck or just moving one message at a time. In my limited experience it seems all battery devices eventually are configured, but it can be quite an adventure. 3) As to the Amazon review, I don’t think that is an issue since you have the product codes the reviewer changed to. I also do not think it would cause the problem you are seeing anyway

4. After some overnight reflection re: wakeup. Try the one button press but hold for a bit (if you haven’t tried this already). Try for 0.5 sec, 1 sec, etc up to 3 seconds (about 30 seconds apart) and see if that works to get the log going. The amazon review implies this function does work. The three presses might be sending a (NIF) that gums up the works (although I have not seen that in the logs). My other wake-up suggestion is to pull the battery, wait 30 seconds and reinstall. One of my devices will wake that way.

Bob

[krishkal (Kal Krishnan)]

Hey, it got done! What did I do differently? I can’t say for sure. For some reason, today, when I clicked the button once, and got the light to flash, the log started to produce something. I can swear I did the same the last two days to no avail, but what good will that do me hah.

I had to do this a couple of times and everything seemed to advance to its completion. I found that the thing to watch is “Node advancer” messages. This should be documented somewhere if possible. If I watch those messages, I can see real progress being made, and know when I am done. For reference, here are the set of Node advancer messages for this node initialization:

2021-12-07 17:53:34.292 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to IDENTIFY_NODE
2021-12-07 17:53:34.293 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: Initialisation starting
2021-12-07 17:53:34.739 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to REQUEST_NIF
2021-12-07 22:37:45.460 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to SECURITY_REPORT
2021-12-07 22:37:45.465 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to MANUFACTURER
2021-12-07 22:37:45.468 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: MANUFACTURER - send ManufacturerSpecific
2021-12-07 22:37:45.616 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to APP_VERSION
2021-12-07 22:37:45.620 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: APP_VERSION - send VersionMessage
2021-12-07 22:37:46.339 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to DISCOVERY_COMPLETE
2021-12-07 22:37:46.353 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to VERSION
2021-12-07 22:37:46.363 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - checking COMMAND_CLASS_NO_OPERATION, version is 1
2021-12-07 22:37:46.364 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - checking COMMAND_CLASS_ASSOCIATION_GRP_INFO, version is 0
2021-12-07 22:37:46.365 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - queued   COMMAND_CLASS_ASSOCIATION_GRP_INFO
2021-12-07 22:37:46.748 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - checking COMMAND_CLASS_VERSION, version is 0
2021-12-07 22:37:46.749 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - queued   COMMAND_CLASS_VERSION
2021-12-07 22:37:46.893 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - checking COMMAND_CLASS_ALARM, version is 0
2021-12-07 22:37:46.894 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - queued   COMMAND_CLASS_ALARM
2021-12-07 22:37:47.819 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - checking COMMAND_CLASS_POWERLEVEL, version is 0
2021-12-07 22:37:47.819 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - queued   COMMAND_CLASS_POWERLEVEL
2021-12-07 22:37:48.029 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - checking COMMAND_CLASS_CONFIGURATION, version is 0
2021-12-07 22:37:48.030 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - queued   COMMAND_CLASS_CONFIGURATION
2021-12-07 22:37:48.393 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - checking COMMAND_CLASS_MANUFACTURER_SPECIFIC, version is 0
2021-12-07 22:37:48.394 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - queued   COMMAND_CLASS_MANUFACTURER_SPECIFIC
2021-12-07 22:37:48.559 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - checking COMMAND_CLASS_BATTERY, version is 0
2021-12-07 22:37:48.560 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - queued   COMMAND_CLASS_BATTERY
2021-12-07 22:37:48.728 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - checking COMMAND_CLASS_SENSOR_BINARY, version is 0
2021-12-07 22:37:48.729 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - queued   COMMAND_CLASS_SENSOR_BINARY
2021-12-07 22:37:48.898 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - checking COMMAND_CLASS_BASIC, version is 0
2021-12-07 22:37:48.899 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - queued   COMMAND_CLASS_BASIC
2021-12-07 22:37:49.067 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - checking COMMAND_CLASS_ZWAVEPLUS_INFO, version is 0
2021-12-07 22:37:49.068 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - queued   COMMAND_CLASS_ZWAVEPLUS_INFO
2021-12-07 22:37:49.239 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - checking COMMAND_CLASS_WAKE_UP, version is 0
2021-12-07 22:37:49.240 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - queued   COMMAND_CLASS_WAKE_UP
2021-12-07 22:37:49.411 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - checking COMMAND_CLASS_DEVICE_RESET_LOCALLY, version is 0
2021-12-07 22:37:49.412 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - queued   COMMAND_CLASS_DEVICE_RESET_LOCALLY
2021-12-07 22:37:49.574 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - checking COMMAND_CLASS_ASSOCIATION, version is 0
2021-12-07 22:37:49.574 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - queued   COMMAND_CLASS_ASSOCIATION
2021-12-07 22:37:49.749 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - checking COMMAND_CLASS_SENSOR_MULTILEVEL, version is 0
2021-12-07 22:37:49.750 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: VERSION - queued   COMMAND_CLASS_SENSOR_MULTILEVEL
2021-12-07 22:37:49.899 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to ENDPOINTS
2021-12-07 22:37:49.901 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: ENDPOINTS - MultiInstance not supported.
2021-12-07 22:37:49.906 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to UPDATE_DATABASE
2021-12-07 22:37:49.908 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: UPDATE_DATABASE
2021-12-07 22:37:49.915 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: UPDATE_DATABASE - check properties
2021-12-07 22:37:49.916 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: UPDATE_DATABASE - property modelId == Motion Sensor 2
2021-12-07 22:37:49.916 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: UPDATE_DATABASE - property vendor == Shenzhen Neo Electronics Co., Ltd
2021-12-07 22:37:49.917 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: UPDATE_DATABASE - property defaultAssociations == 1
2021-12-07 22:37:49.917 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: UPDATE_DATABASE - property manufacturerId == 0258
2021-12-07 22:37:49.918 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: UPDATE_DATABASE - property manufacturerRef == 0003:008D
2021-12-07 22:37:49.918 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: UPDATE_DATABASE - property dbReference == 1395
2021-12-07 22:37:49.919 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to STATIC_VALUES
2021-12-07 22:37:49.921 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_NO_OPERATION
2021-12-07 22:37:49.922 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_ASSOCIATION_GRP_INFO
2021-12-07 22:37:49.924 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_VERSION
2021-12-07 22:37:49.925 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_ALARM
2021-12-07 22:37:50.089 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_POWERLEVEL
2021-12-07 22:37:50.090 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_CONFIGURATION
2021-12-07 22:37:50.090 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_MANUFACTURER_SPECIFIC
2021-12-07 22:37:50.092 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_BATTERY
2021-12-07 22:37:50.093 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_SENSOR_BINARY
2021-12-07 22:37:50.254 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_BASIC
2021-12-07 22:37:50.255 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_ZWAVEPLUS_INFO
2021-12-07 22:41:21.409 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_WAKE_UP
2021-12-07 22:41:21.786 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_DEVICE_RESET_LOCALLY
2021-12-07 22:41:21.786 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_ASSOCIATION
2021-12-07 22:41:21.937 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_SENSOR_MULTILEVEL
2021-12-07 22:41:22.183 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to ASSOCIATIONS
2021-12-07 22:41:22.193 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: ASSOCIATIONS request group 1
2021-12-07 22:41:22.516 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: ASSOCIATIONS request group 2
2021-12-07 22:41:22.692 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: ASSOCIATIONS request group 3
2021-12-07 22:41:22.837 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: ASSOCIATIONS request group 4
2021-12-07 22:41:22.988 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to SET_WAKEUP
2021-12-07 22:41:22.991 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: SET_WAKEUP - TargetNode is set to controller
2021-12-07 22:41:22.992 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to SET_ASSOCIATION
2021-12-07 22:41:23.002 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: SET_ASSOCIATION - Adding ASSOCIATION node_1 to group 1
2021-12-07 22:41:23.233 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to SET_LIFELINE
2021-12-07 22:41:23.235 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: SET_LIFELINE - Checking group 1
2021-12-07 22:41:23.236 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: SET_LIFELINE - Checking group 2
2021-12-07 22:41:23.237 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: SET_LIFELINE - Checking group 3
2021-12-07 22:41:23.238 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: SET_LIFELINE - Checking group 4
2021-12-07 22:41:23.239 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to GET_CONFIGURATION
2021-12-07 22:41:23.247 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_1_1 - config
2021-12-07 22:41:23.248 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_1_1 - index 1
2021-12-07 22:41:23.471 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_2_2 - config
2021-12-07 22:41:23.472 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_2_2 - index 2
2021-12-07 22:41:23.688 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_3_1 - config
2021-12-07 22:41:23.689 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_3_1 - index 3
2021-12-07 22:41:23.990 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_4_1 - config
2021-12-07 22:41:23.990 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_4_1 - index 4
2021-12-07 22:41:24.145 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_5_2 - config
2021-12-07 22:41:24.146 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_5_2 - index 5
2021-12-07 22:41:24.468 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_6_1 - config
2021-12-07 22:41:24.469 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_6_1 - index 6
2021-12-07 22:41:24.646 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_7_2 - config
2021-12-07 22:41:24.646 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_7_2 - index 7
2021-12-07 22:41:24.917 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_8_1 - config
2021-12-07 22:41:24.917 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_8_1 - index 8
2021-12-07 22:41:25.063 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_9_1 - config
2021-12-07 22:41:25.064 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_9_1 - index 9
2021-12-07 22:41:25.214 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_10_1 - config
2021-12-07 22:41:25.215 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_10_1 - index 10
2021-12-07 22:41:25.825 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_11_1 - config
2021-12-07 22:41:25.826 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_11_1 - index 11
2021-12-07 22:41:25.975 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_99_2 - config
2021-12-07 22:41:25.976 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: GET_CONFIGURATION - checking config_99_2 - index 99
2021-12-07 22:48:59.015 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to STATIC_END
2021-12-07 22:48:59.275 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to DYNAMIC_VALUES
2021-12-07 22:48:59.277 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_NO_OPERATION
2021-12-07 22:48:59.277 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_ASSOCIATION_GRP_INFO
2021-12-07 22:48:59.278 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_VERSION
2021-12-07 22:48:59.278 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_ALARM
2021-12-07 22:48:59.279 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_POWERLEVEL
2021-12-07 22:48:59.429 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_CONFIGURATION
2021-12-07 22:48:59.429 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_MANUFACTURER_SPECIFIC
2021-12-07 22:48:59.430 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_BATTERY
2021-12-07 22:48:59.582 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_SENSOR_BINARY
2021-12-07 22:48:59.796 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_BASIC
2021-12-07 22:48:59.797 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_ZWAVEPLUS_INFO
2021-12-07 22:48:59.797 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_WAKE_UP
2021-12-07 22:48:59.798 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_DEVICE_RESET_LOCALLY
2021-12-07 22:48:59.799 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_ASSOCIATION
2021-12-07 22:48:59.799 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: DYNAMIC_VALUES - checking COMMAND_CLASS_SENSOR_MULTILEVEL
2021-12-07 22:49:00.118 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer: Initialisation complete!
2021-12-07 22:49:00.119 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to DYNAMIC_END
2021-12-07 22:49:00.136 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 24: Node advancer - advancing to DONE

Once you see ‘advancing to DONE’ this is when you know you are actually done. But, seeing the intermediate ones gives you hope and encouragement. Interestingly, when it did go through, it did not take long at all. It’s just voodoo - when it works, it works, when it doesn’t it doesn’t.

[Andrew_Rowe]

@krishkal

Hey, it got done! What did I do differently? I can’t say for sure… I can swear I did the same the last two days to no avail

ya gotta keep trying… sometimes for what seems way to many times

@apella12

re: wakeup. Try the one button press but hold for a bit (if you haven’t tried this already). Try for 0.5 sec, 1 sec, etc up to 3 seconds (about 30 seconds apart) and see if that works to get the log going… My other wake-up suggestion is to pull the battery, wait 30 seconds and reinstall. One of my devices will wake that way.

I’ve had ones I triple pressed or unplug battery, often manual is wrong, ya gotta just keep trying until it works. Some are worse then others
Anyhow great job Bob @apella12 at the zwave stuff, great help here in the forum and good on ya Kal for getting it going

[krishkal (Kal Krishnan)]

Yeah, definitely thanks to Bob @apella12 for the encouragement to keep trying. Without that I would have just given up for sure.

[apella12 (Bob Eckhoff)]

As I said above it eventually works. The directions on waking a device are not always clear or correct. Glad this works now, it was a very stubborn one.

Enjoy

Bob