OH2 nodon CWS-3101 CentralSceneV2 key1 (released) sometime missing

OMR · February 27, 2017, 9:52pm

Hello.

I have just added two NodOn CWS-3101 Z-wave wall-switches (aka remotes) and I observe the same issue with both.

Sometimes after holding a button down continuously receiving multiple scene n at key 2 (=HoldDown) the terminating scene n at key 1 (=Release) is missing.

I wonder if this is an issue with the NodOn remote, the Aeotec Z-stick Gen5 or OH2/Z-wave?

Here is the openhab.log with debug enabled:

Cheers

2017-02-27 21:56:02.788 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 6: Received scene 2 at key 2 [Key Held Down]
2017-02-27 21:56:02.788 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2017-02-27 21:56:02.788 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2017-02-27 21:56:02.788 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got a value event from Z-Wave network, endpoint = 0, command class = CENTRAL_SCENE, value = 2.2
2017-02-27 21:56:02.789 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Updating channel state zwave:device:3f5c8071:node6:scene_number to 2.2 [DecimalType]
2017-02-27 21:56:02.790 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=6, callback=12, payload=06 02 84 08
2017-02-27 21:56:02.790 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 06 05 5B 03 B0 02 02
2017-02-27 21:56:02.791 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=12, expected=SendData, cancelled=false      MISMATCH
2017-02-27 21:56:02.795 [INFO ] [.smarthome.model.script.RemoteNodon6] - Rule: Got: 2.2
2017-02-27 21:56:02.796 [INFO ] [.smarthome.model.script.RemoteNodon6] - Rule: Button2 Hold-down 2.2
2017-02-27 21:56:03.104 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 06 05 5B 03 B1 02 02 1A
2017-02-27 21:56:03.106 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-02-27 21:56:03.107 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 04 00 06 05 5B 03 B1 02 02 1A
2017-02-27 21:56:03.107 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0B 00 04 00 06 05 5B 03 B1 02 02 1A
2017-02-27 21:56:03.108 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 06 05 5B 03 B1 02 02
2017-02-27 21:56:03.108 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Application Command Request (ALIVE:DONE)
2017-02-27 21:56:03.108 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Starting initialisation from DONE
2017-02-27 21:56:03.109 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@69919710 already registered
2017-02-27 21:56:03.109 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Incoming command class CENTRAL_SCENE
2017-02-27 21:56:03.110 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 6: Received CENTRAL_SCENE command V2
2017-02-27 21:56:03.110 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 6: Received scene 2 at key 2 [Key Held Down]
2017-02-27 21:56:03.110 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2017-02-27 21:56:03.110 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2017-02-27 21:56:03.111 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got a value event from Z-Wave network, endpoint = 0, command class = CENTRAL_SCENE, value = 2.2
2017-02-27 21:56:03.111 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Updating channel state zwave:device:3f5c8071:node6:scene_number to 2.2 [DecimalType]
2017-02-27 21:56:03.112 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=6, callback=12, payload=06 02 84 08
2017-02-27 21:56:03.113 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 06 05 5B 03 B1 02 02
2017-02-27 21:56:03.113 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=12, expected=SendData, cancelled=false      MISMATCH
2017-02-27 21:56:03.117 [INFO ] [.smarthome.model.script.RemoteNodon6] - Rule: Got: 2.2
2017-02-27 21:56:03.119 [INFO ] [.smarthome.model.script.RemoteNodon6] - Rule: Button2 Hold-down 2.2
2017-02-27 21:56:03.720 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 06 02 84 07 74
2017-02-27 21:56:03.721 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-02-27 21:56:03.722 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 04 00 06 02 84 07 74
2017-02-27 21:56:03.722 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 08 00 04 00 06 02 84 07 74
2017-02-27 21:56:03.723 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 06 02 84 07
2017-02-27 21:56:03.723 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Application Command Request (ALIVE:DONE)
2017-02-27 21:56:03.723 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Starting initialisation from DONE
2017-02-27 21:56:03.724 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@69919710 already registered
2017-02-27 21:56:03.724 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Incoming command class WAKE_UP
2017-02-27 21:56:03.724 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 6: Received Wake Up Request
2017-02-27 21:56:03.724 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 6: Received WAKE_UP_NOTIFICATION
2017-02-27 21:56:03.725 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 6: Is awake with 0 messages in the wake-up queue.
2017-02-27 21:56:03.725 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveWakeUpEvent
2017-02-27 21:56:03.725 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveWakeUpEvent
2017-02-27 21:56:03.726 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=6, callback=12, payload=06 02 84 08
2017-02-27 21:56:03.727 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 06 02 84 07
2017-02-27 21:56:03.727 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=12, expected=SendData, cancelled=true      MISMATCH
2017-02-27 21:56:04.726 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 6: No more messages, go back to sleep
2017-02-27 21:56:04.727 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 6: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
2017-02-27 21:56:04.727 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2017-02-27 21:56:04.727 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2017-02-27 21:56:04.728 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 06 02 84 08 25 0D 45
2017-02-27 21:56:04.728 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 09 00 13 06 02 84 08 25 0D 45
2017-02-27 21:56:04.738 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2017-02-27 21:56:04.739 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-02-27 21:56:04.740 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2017-02-27 21:56:04.740 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2017-02-27 21:56:04.740 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2017-02-27 21:56:04.741 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: Sent Data successfully placed on stack.
2017-02-27 21:56:04.758 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 0D 00 00 03 E5
2017-02-27 21:56:04.759 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-02-27 21:56:04.760 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 0D 00 00 03 00 00 EB
2017-02-27 21:56:04.760 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 0D 00 00 03 00 00 EB
2017-02-27 21:56:04.761 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=0D 00 00 03
2017-02-27 21:56:04.761 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: SendData Request. CallBack ID = 13, Status = Transmission complete and ACK received(0)
2017-02-27 21:56:04.761 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Starting initialisation from DONE
2017-02-27 21:56:04.762 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@69919710 already registered
2017-02-27 21:56:04.762 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=6, callback=13, payload=06 02 84 08
2017-02-27 21:56:04.762 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=0D 00 00 03
2017-02-27 21:56:04.763 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=13, expected=SendData, cancelled=false        transaction complete!
2017-02-27 21:56:04.763 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-02-27 21:56:04.763 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 6: Went to sleep
2017-02-27 21:56:04.763 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 6: Is sleeping
2017-02-27 21:56:04.763 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-02-27 21:56:04.764 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Response processed after 34ms/4151ms.
^C

Here a snippet from when it works:

2017-02-27 22:48:23.459 [INFO ] [.smarthome.model.script.RemoteNodon6] - Rule: Button2 Hold-down 2.2
2017-02-27 22:48:23.584 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 06 05 5B 03 BD 01 02 15
2017-02-27 22:48:23.586 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-02-27 22:48:23.586 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 04 00 06 05 5B 03 BD 01 02 15
2017-02-27 22:48:23.586 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0B 00 04 00 06 05 5B 03 BD 01 02 15
2017-02-27 22:48:23.587 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 06 05 5B 03 BD 01 02
2017-02-27 22:48:23.587 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Application Command Request (ALIVE:DONE)
2017-02-27 22:48:23.587 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Starting initialisation from DONE
2017-02-27 22:48:23.587 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@69919710 already registered
2017-02-27 22:48:23.587 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Incoming command class CENTRAL_SCENE
2017-02-27 22:48:23.588 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 6: Received CENTRAL_SCENE command V2
2017-02-27 22:48:23.588 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 6: Received scene 2 at key 1 [Key Released]
2017-02-27 22:48:23.588 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2017-02-27 22:48:23.588 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2017-02-27 22:48:23.588 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got a value event from Z-Wave network, endpoint = 0, command class = CENTRAL_SCENE, value = 2.1
2017-02-27 22:48:23.589 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Updating channel state zwave:device:3f5c8071:node6:scene_number to 2.1 [DecimalType]
2017-02-27 22:48:23.590 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=6, callback=89, payload=06 02 84 08
2017-02-27 22:48:23.590 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 06 05 5B 03 BD 01 02
2017-02-27 22:48:23.591 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=89, expected=SendData, cancelled=false      MISMATCH
2017-02-27 22:48:23.595 [INFO ] [.smarthome.model.script.RemoteNodon6] - Rule: Got: 2.1
2017-02-27 22:48:23.597 [INFO ] [.smarthome.model.script.RemoteNodon6] - Rule: Button2 Release 2.1
2017-02-27 22:48:23.609 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 06 02 84 07 74
2017-02-27 22:48:23.611 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-02-27 22:48:23.611 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 04 00 06 02 84 07 74
2017-02-27 22:48:23.612 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 08 00 04 00 06 02 84 07 74

chris · February 27, 2017, 10:02pm

If nothing is received in the log, then either I doubt it’s the binding - there’s no corrupt messages showing, so I see no indication that anything was sent from the stick. I don’t know the device so can’t comment too much about that part of the system…

OMR · February 27, 2017, 10:16pm

Thank you for replying.

I have contacted NodOn and asked them to comment on this topic.

NIUEYE · March 3, 2017, 12:34pm

Dear OMR,
Can you try to change the configuration of parameter 3 to value 1 ?
Is the press release is then detected ?
Thank you.

OMR · March 5, 2017, 12:14pm

I did switch to SCENE_ACTIVATION and it looked good, but when I switched back to CENTRAL_SCENE it also worked fine.
I do have a lot of Timeout errors on my zwave network, so it could be related.
Will sort out those errors first and re-test.

As long as CENTRAL_SCENE is used, a held-down event is received every ~300ms so a timer in the rule can be an easy workaround for detecting key-release as well.

Thanks for coming back to me on this.

I have started a new thread here.