Strange 5s delay after rule triggering and whole group responds. No errors in log

The node is still initialising for some reason - it looks like it’s stuck waiting for a specific response - I’d try waking it up a few times to get it fully initialised.

Thanks @chris.

Keep in mind that it has been this way since my first post mars 9.
This is the state the battery powered remote ends up in.

I just did another test. Hit the remote: 5s before lights started to turn off, just as the last one got dark, pushed it again and it took 5s to turn on again. Repeated it again a few seconds later. Same result.

A thought just hit me, could it be that I’m actually querying a Z-wave node state in the sendCommand?

sendCommand(lights, if (BuildInKjokkenBench.state==OFF) ON else OFF);

I will check that out using a variable instead.
Will have to be later as I’m out to visit the sun outside :slight_smile:

Adding a 50ms delay before the sendCommand() did the trick.
Something fishy with the NodOn CENTRAL_SCENE class?
I also have an Aeon battery powered Multisensor 6. Will check if it has the same ‘problem’.

rule "WallSwitchLivingRoom" 
when
        Item WallSwitchStua received update
then 
    var swState = WallSwitchStua.state 
	logInfo("RemoteNodon22", "Rule: Got: " + swState)
	Thread::sleep(50)
    
    switch swState {
	    case 1.0: {logInfo("RemoteNodon22", "Rule: Button1 SingleClick " + swState) sendCommand(lights, if (BuildInKjokkenBench.state==OFF) ON else OFF);
	    	                                                                        lights.state = if (BuildInKjokkenBench.state==OFF) ON else OFF
                                                                                    logInfo("RemoteNodon22", "lights.state=" + lights.state)
	    																		    All.state=lights.state 
	    																		    AllLR.state=lights.state	    
	    																		    AllK.state=lights.state	    
	    																		    AllDR.state=lights.state	    
    																		   }	    

No timeout anymore:

2017-03-26 11:51:39.096 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 06 05 5B 03 49 00 04 E6
2017-03-26 11:51:39.098 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-03-26 11:51:39.098 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 04 00 06 05 5B 03 49 00 04 E6
2017-03-26 11:51:39.099 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0B 00 04 00 06 05 5B 03 49 00 04 E6
2017-03-26 11:51:39.099 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 06 05 5B 03 49 00 04
2017-03-26 11:51:39.099 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Application Command Request (ALIVE:DONE)
2017-03-26 11:51:39.100 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Starting initialisation from DONE
2017-03-26 11:51:39.100 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@63428cdb already registered
2017-03-26 11:51:39.100 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Incoming command class CENTRAL_SCENE
2017-03-26 11:51:39.100 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 6: Received CENTRAL_SCENE command V2
2017-03-26 11:51:39.100 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 6: Received scene 4 at key 0 [Single Press]
2017-03-26 11:51:39.101 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2017-03-26 11:51:39.101 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2017-03-26 11:51:39.101 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got a value event from Z-Wave network, endpoint = 0, command class = CENTRAL_SCENE, value = 4.0
2017-03-26 11:51:39.102 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Updating channel state zwave:device:3f5c8071:node6:scene_number to 4.0 [DecimalType]
2017-03-26 11:51:39.104 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 12: Transaction not completed: node address inconsistent.  lastSent=12, incoming=255
2017-03-26 11:51:39.107 [INFO ] [.smarthome.model.script.RemoteNodon6] - Rule: Got: 4.0
2017-03-26 11:51:39.121 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 06 02 84 07 74
2017-03-26 11:51:39.123 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-03-26 11:51:39.124 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 04 00 06 02 84 07 74
2017-03-26 11:51:39.124 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 08 00 04 00 06 02 84 07 74
2017-03-26 11:51:39.125 [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-03-26 11:51:39.125 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Application Command Request (ALIVE:DONE)
2017-03-26 11:51:39.125 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Starting initialisation from DONE
2017-03-26 11:51:39.125 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@63428cdb already registered
2017-03-26 11:51:39.125 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Incoming command class WAKE_UP
2017-03-26 11:51:39.126 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 6: Received Wake Up Request
2017-03-26 11:51:39.126 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 6: Received WAKE_UP_NOTIFICATION
2017-03-26 11:51:39.126 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 6: Is awake with 0 messages in the wake-up queue.
2017-03-26 11:51:39.126 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveWakeUpEvent
2017-03-26 11:51:39.126 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveWakeUpEvent
2017-03-26 11:51:39.127 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 12: Transaction not completed: node address inconsistent.  lastSent=12, incoming=255
2017-03-26 11:51:39.159 [INFO ] [.smarthome.model.script.RemoteNodon6] - Rule: Button4 SingleClick 4.0
2017-03-26 11:51:39.162 [INFO ] [.smarthome.model.script.RemoteNodon6] - BuildInKjDiningTableLamp.state=0
2017-03-26 11:51:39.164 [INFO ] [.smarthome.model.script.RemoteNodon6] - diningRoom.state=ON
2017-03-26 11:51:39.165 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: Command received zwave:device:3f5c8071:node19:switch_dimmer --> ON
2017-03-26 11:51:39.165 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 19: Creating new message for command SWITCH_MULTILEVEL_SET
2017-03-26 11:51:39.165 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2017-03-26 11:51:39.167 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 0. Queue={}
2017-03-26 11:51:39.168 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 13 03 26 01 FF 25 B8 B3
2017-03-26 11:51:39.168 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 19: Sending REQUEST Message = 01 0A 00 13 13 03 26 01 FF 25 B8 B3
2017-03-26 11:51:39.172 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Command received zwave:device:3f5c8071:node18:switch_dimmer --> ON
2017-03-26 11:51:39.172 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 18: Creating new message for command SWITCH_MULTILEVEL_SET
2017-03-26 11:51:39.172 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2017-03-26 11:51:39.175 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Command received zwave:device:3f5c8071:node14:switch_dimmer --> ON
2017-03-26 11:51:39.175 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 14: Creating new message for command SWITCH_MULTILEVEL_SET
1 Like

Just for completeness: the Aeon Multisensor 6 does not have this issue with its :sensor_binary item channel.