My Fibaro Button (FGPB-1 ZW5 v3.2) doesen’t send the scene reliably. Only the “hold action” (state = 1.2 ) will send reliably on the first hold click. If I click shortly on the button the device won’t send a scene number to the controller. After many attempts with short clicks I get sometines a scene number for a short click, But after next few second the device doesen’t send any scene number anymore.
Are you sure that this is correct? How are you actually confirming this - is it using the ZWave debug log, or something else? It just seems a bit strange to me, and in the past when people have reported this sort of function, it’s because they are misinterpreting something.
I would recommend to use the zwave debug log to confirm this functionality.
I have put a logInfo to my rule and
rule "TestButton"
when
Item ButtonX received update
then
logInfo ("TestButton", " State: " + ButtonX.state)
if (ButtonX.state == 1.2) {
if (StehlampeSwitch.state == OFF){
StehlampeSwitch.sendCommand(ON)
}else{
StehlampeSwitch.sendCommand(OFF)
}
}
end
Maybe the button has bug. I have contact the fibaro support too.
As I suggested above, I would use the debug log in the zwave binding to check this sort of thing. I’ve had other people do what you have tried, and then found that there’s an issue with their rule - if you check the zwave log before complaining to the supplier, then you are really checking that the problem is with the device, and not with your rule, or elsewhere in OH.
I have now debug the short click event and I can not find an entry for sending scene number
2017-06-30 17:27:55.956 [Handler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 31 03 80 03 64 27
2017-06-30 17:27:55.958 [ZWaveController ] - Receive queue TAKE: Length=0
2017-06-30 17:27:55.959 [SerialMessage ] - Assembled message buffer = 01 09 00 04 00 31 03 80 03 64 27
2017-06-30 17:27:55.961 [ZWaveController ] - Process Message = 01 09 00 04 00 31 03 80 03 64 27
2017-06-30 17:27:55.962 [ZWaveController ] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 31 03 80 03 64
2017-06-30 17:27:55.963 [icationCommandMessageClass] - NODE 49: Application Command Request (ALIVE:DONE)
2017-06-30 17:27:55.963 [ZWaveNodeInitStageAdvancer] - NODE 49: Starting initialisation from DONE
2017-06-30 17:27:55.964 [ZWaveController ] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@b72ed already registered
2017-06-30 17:27:55.965 [icationCommandMessageClass] - NODE 49: Incoming command class BATTERY
2017-06-30 17:27:55.966 [ZWaveBatteryCommandClass ] - NODE 49: Received Battery Request
2017-06-30 17:27:55.966 [ZWaveBatteryCommandClass ] - NODE 49: Battery report value = 100
2017-06-30 17:27:55.967 [ZWaveController ] - Notifying event listeners: ZWaveCommandClassValueEvent
2017-06-30 17:27:55.968 [ZWaveThingHandler ] - NODE 49: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2017-06-30 17:27:55.969 [ZWaveThingHandler ] - NODE 49: Got a value event from Z-Wave network, endpoint = 0, command class = BATTERY, value = 100
2017-06-30 17:27:55.970 [ZWaveThingHandler ] - NODE 49: Updating channel state zwave:device:21023552:node49:battery-level to 100 [DecimalType]
2017-06-30 17:27:55.974 [icationCommandMessageClass] - NODE 23: Transaction not completed: node address inconsistent. lastSent=23, incoming=255
2017-06-30 17:27:56.055 [Handler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 31 02 84 07 43
2017-06-30 17:27:56.056 [ZWaveController ] - Receive queue TAKE: Length=0
2017-06-30 17:27:56.058 [SerialMessage ] - Assembled message buffer = 01 08 00 04 00 31 02 84 07 43
2017-06-30 17:27:56.059 [ZWaveController ] - Process Message = 01 08 00 04 00 31 02 84 07 43
2017-06-30 17:27:56.060 [ZWaveController ] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 31 02 84 07
2017-06-30 17:27:56.061 [icationCommandMessageClass] - NODE 49: Application Command Request (ALIVE:DONE)
2017-06-30 17:27:56.062 [ZWaveNodeInitStageAdvancer] - NODE 49: Starting initialisation from DONE
2017-06-30 17:27:56.063 [ZWaveController ] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@b72ed already registered
2017-06-30 17:27:56.064 [icationCommandMessageClass] - NODE 49: Incoming command class WAKE_UP
2017-06-30 17:27:56.064 [ZWaveWakeUpCommandClass ] - NODE 49: Received Wake Up Request
2017-06-30 17:27:56.065 [ZWaveWakeUpCommandClass ] - NODE 49: Received WAKE_UP_NOTIFICATION
2017-06-30 17:27:56.066 [ZWaveWakeUpCommandClass ] - NODE 49: Is awake with 0 messages in the wake-up queue.
2017-06-30 17:27:56.066 [ZWaveController ] - Notifying event listeners: ZWaveWakeUpEvent
2017-06-30 17:27:56.067 [ZWaveThingHandler ] - NODE 49: Got an event from Z-Wave network: ZWaveWakeUpEvent
2017-06-30 17:27:56.069 [icationCommandMessageClass] - NODE 23: Transaction not completed: node address inconsistent. lastSent=23, incoming=255
2017-06-30 17:27:57.069 [ZWaveWakeUpCommandClass ] - NODE 49: No more messages, go back to sleep
2017-06-30 17:27:57.070 [ZWaveWakeUpCommandClass ] - NODE 49: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
2017-06-30 17:27:57.071 [ZWaveController ] - Message queued. Queue length = 1. Queue={}
2017-06-30 17:27:57.071 [Controller$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2017-06-30 17:27:57.072 [SerialMessage ] - Assembled message buffer = 01 09 00 13 31 02 84 08 25 EB 94
2017-06-30 17:27:57.074 [ZWaveSerialHandler ] - NODE 49: Sending REQUEST Message = 01 09 00 13 31 02 84 08 25 EB 94
2017-06-30 17:27:57.088 [Handler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2017-06-30 17:27:57.090 [ZWaveController ] - Receive queue TAKE: Length=0
2017-06-30 17:27:57.091 [SerialMessage ] - Assembled message buffer = 01 04 01 13 01 E8
2017-06-30 17:27:57.092 [ZWaveController ] - Process Message = 01 04 01 13 01 E8
2017-06-30 17:27:57.093 [ZWaveController ] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2017-06-30 17:27:57.094 [SendDataMessageClass ] - NODE 49: Sent Data successfully placed on stack.
2017-06-30 17:28:01.202 [Handler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 EB 01 01 9C 9C
2017-06-30 17:28:01.205 [ZWaveController ] - Receive queue TAKE: Length=0
2017-06-30 17:28:01.206 [SerialMessage ] - Assembled message buffer = 01 09 00 13 EB 01 01 9C 00 00 92
2017-06-30 17:28:01.207 [ZWaveController ] - Process Message = 01 09 00 13 EB 01 01 9C 00 00 92
2017-06-30 17:28:01.208 [ZWaveController ] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=EB 01 01 9C
2017-06-30 17:28:01.209 [SendDataMessageClass ] - NODE 49: SendData Request. CallBack ID = 235, Status = Transmission complete, no ACK received(1)
2017-06-30 17:28:01.210 [ZWaveCommandProcessor ] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=49, callback=235, payload=31 02 84 08
2017-06-30 17:28:01.212 [ZWaveCommandProcessor ] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=EB 01 01 9C
2017-06-30 17:28:01.213 [ZWaveCommandProcessor ] - Checking transaction complete: class=SendData, callback id=235, expected=SendData, cancelled=false transaction complete!
2017-06-30 17:28:01.213 [SendDataMessageClass ] - NODE 49: WAKE_UP_NO_MORE_INFORMATION. Treated as ACK.
2017-06-30 17:28:01.214 [ZWaveController ] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-06-30 17:28:01.215 [ZWaveWakeUpCommandClass ] - NODE 49: Went to sleep
2017-06-30 17:28:01.215 [ZWaveWakeUpCommandClass ] - NODE 49: Is sleeping
2017-06-30 17:28:01.218 [ZWaveThingHandler ] - NODE 49: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-06-30 17:28:01.219 [Controller$ZWaveSendThread] - NODE 49: Response processed after 4144ms/4369ms.
For the hold event I can find something this:
2017-06-30 17:25:19.337 [icationCommandMessageClass] - NODE 49: Incoming command class CENTRAL_SCENE
2017-06-30 17:25:19.338 [veCentralSceneCommandClass] - NODE 49: Received CENTRAL_SCENE command V3
2017-06-30 17:25:19.340 [veCentralSceneCommandClass] - NODE 49: Received scene 1 at key 2 [Key Held Down]
2017-06-30 17:25:19.341 [ZWaveController ] - Notifying event listeners: ZWaveCommandClassValueEvent
2017-06-30 17:25:19.342 [ZWaveThingHandler ] - NODE 49: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2017-06-30 17:25:19.344 [ZWaveThingHandler ] - NODE 49: Got a value event from Z-Wave network, endpoint = 0, command class = CENTRAL_SCENE, value = 1.2
2017-06-30 17:25:19.345 [ZWaveThingHandler ] - NODE 49: Updating channel state zwave:device:21023552:node49:scene_number to 1.2 [DecimalType]
The button has a defect. I got a new button and this button works fine
Hi,
Sorry to resurrect an old thread.
I am having the exact same symptom.
Are you certain the defect is in the button and not some other reason?
Have you checked the debug logs?
Yes. I don’t understand what is going on.
Below a log of 1 successful scene detected and after that scene not detected.
NODE 9 is the button.
2018-07-15 00:36:39.947 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 09 05 5B 03 01 80 01 24
2018-07-15 00:36:39.953 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-07-15 00:36:39.957 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 04 00 09 05 5B 03 01 80 01 24
2018-07-15 00:36:39.962 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0B 00 04 00 09 05 5B 03 01 80 01 24
2018-07-15 00:36:39.966 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 09 05 5B 03 01 80 01
2018-07-15 00:36:39.969 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 9: Application Command Request (ALIVE:DONE)
2018-07-15 00:36:39.973 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Starting initialisation from DONE
2018-07-15 00:36:39.976 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@18ec6ec already registered
2018-07-15 00:36:39.980 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 9: Incoming command class CENTRAL_SCENE
2018-07-15 00:36:39.983 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 9: Received CENTRAL_SCENE command V3
2018-07-15 00:36:39.986 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 9: Received scene 1 at key 0 [Single Press]
2018-07-15 00:36:39.990 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2018-07-15 00:36:39.993 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2018-07-15 00:36:39.997 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got a value event from Z-Wave network, endpoint = 0, command class = CENTRAL_SCENE, value = 1.0
2018-07-15 00:36:40.002 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Updating channel state zwave:device:15cf518cecd:node9:scene_number to 1.0 [DecimalType]
2018-07-15 00:36:40.011 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=9, callback=2, payload=09 02 84 08
2018-07-15 00:36:40.014 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 09 05 5B 03 01 80 01
2018-07-15 00:36:40.016 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=2, expected=SendData, cancelled=false MISMATCH
2018-07-15 00:36:40.047 [INFO ] [pse.smarthome.model.script.ButtonRed] - ButtonRed 1x pushed
==> /var/log/openhab2/events.log <==
2018-07-15 00:36:40.059 [ome.event.ItemCommandEvent] - Item 'TreadmillWallPlug' received command ON
==> /var/log/openhab2/openhab.log <==
2018-07-15 00:36:40.067 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Command received zwave:device:15cf518cecd:node8:switch_binary --> ON
==> /var/log/openhab2/events.log <==
2018-07-15 00:36:40.076 [vent.ItemStateChangedEvent] - TreadmillWallPlug changed from OFF to ON
==> /var/log/openhab2/openhab.log <==
2018-07-15 00:36:40.072 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 8: Creating new message for application command SWITCH_BINARY_SET
2018-07-15 00:36:40.083 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-07-15 00:36:40.087 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-07-15 00:36:40.093 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 08 03 25 01 FF 25 03 10
2018-07-15 00:36:40.095 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 8: Sending REQUEST Message = 01 0A 00 13 08 03 25 01 FF 25 03 10
2018-07-15 00:36:40.105 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-07-15 00:36:40.107 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-07-15 00:36:40.110 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-07-15 00:36:40.112 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-07-15 00:36:40.116 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-07-15 00:36:40.118 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 8: Sent Data successfully placed on stack.
2018-07-15 00:36:40.121 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 03 00 00 02 EA
2018-07-15 00:36:40.124 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-07-15 00:36:40.127 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 03 00 00 02 00 00 E4
2018-07-15 00:36:40.130 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 03 00 00 02 00 00 E4
2018-07-15 00:36:40.133 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=03 00 00 02
2018-07-15 00:36:40.136 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 8: SendData Request. CallBack ID = 3, Status = Transmission complete and ACK received(0)
2018-07-15 00:36:40.138 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Starting initialisation from DONE
2018-07-15 00:36:40.141 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@14d134f already registered
2018-07-15 00:36:40.144 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=8, callback=3, payload=08 03 25 01 FF
2018-07-15 00:36:40.147 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=03 00 00 02
2018-07-15 00:36:40.150 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 08 03 25 03 FF 20
2018-07-15 00:36:40.150 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=3, expected=SendData, cancelled=false transaction complete!
2018-07-15 00:36:40.153 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2018-07-15 00:36:40.154 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-07-15 00:36:40.154 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 8: Response processed after 58ms/4244ms.
2018-07-15 00:36:40.156 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 04 00 08 03 25 03 FF 20
2018-07-15 00:36:40.157 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 04 00 08 03 25 03 FF 20
2018-07-15 00:36:40.159 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 08 03 25 03 FF
2018-07-15 00:36:40.161 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 8: Application Command Request (ALIVE:DONE)
2018-07-15 00:36:40.162 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Starting initialisation from DONE
2018-07-15 00:36:40.164 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@14d134f already registered
2018-07-15 00:36:40.165 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 8: Incoming command class SWITCH_BINARY
2018-07-15 00:36:40.167 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - Received Switch Binary Request for Node ID = 8
2018-07-15 00:36:40.168 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 8: Switch Binary report, value = 255
2018-07-15 00:36:40.169 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2018-07-15 00:36:40.171 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=8, callback=3, payload=08 03 25 01 FF
2018-07-15 00:36:40.173 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 08 03 25 03 FF
2018-07-15 00:36:40.174 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=3, expected=SendData, cancelled=false MISMATCH
2018-07-15 00:36:55.054 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 09 03 80 03 64 1F
2018-07-15 00:36:55.058 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-07-15 00:36:55.061 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 04 00 09 03 80 03 64 1F
2018-07-15 00:36:55.064 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 04 00 09 03 80 03 64 1F
2018-07-15 00:36:55.067 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 09 03 80 03 64
2018-07-15 00:36:55.069 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 9: Application Command Request (ALIVE:DONE)
2018-07-15 00:36:55.071 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Starting initialisation from DONE
2018-07-15 00:36:55.074 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@18ec6ec already registered
2018-07-15 00:36:55.076 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 9: Incoming command class BATTERY
2018-07-15 00:36:55.078 [DEBUG] [ommandclass.ZWaveBatteryCommandClass] - NODE 9: Received Battery Request
2018-07-15 00:36:55.080 [DEBUG] [ommandclass.ZWaveBatteryCommandClass] - NODE 9: Battery report value = 100
2018-07-15 00:36:55.083 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2018-07-15 00:36:55.085 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2018-07-15 00:36:55.087 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got a value event from Z-Wave network, endpoint = 0, command class = BATTERY, value = 100
2018-07-15 00:36:55.090 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Updating channel state zwave:device:15cf518cecd:node9:battery-level to 100 [DecimalType]
2018-07-15 00:36:55.093 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 8: Transaction not completed: node address inconsistent. lastSent=8, incoming=255
2018-07-15 00:36:55.153 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 09 02 84 07 7B
2018-07-15 00:36:55.157 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-07-15 00:36:55.159 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 04 00 09 02 84 07 7B
2018-07-15 00:36:55.172 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 08 00 04 00 09 02 84 07 7B
2018-07-15 00:36:55.175 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 09 02 84 07
2018-07-15 00:36:55.177 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 9: Application Command Request (ALIVE:DONE)
2018-07-15 00:36:55.179 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Starting initialisation from DONE
2018-07-15 00:36:55.186 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@18ec6ec already registered
2018-07-15 00:36:55.188 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 9: Incoming command class WAKE_UP
2018-07-15 00:36:55.190 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 9: Received Wake Up Request
2018-07-15 00:36:55.201 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 9: Received WAKE_UP_NOTIFICATION
2018-07-15 00:36:55.204 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 9: Is awake with 0 messages in the wake-up queue.
2018-07-15 00:36:55.207 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveWakeUpEvent
2018-07-15 00:36:55.209 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveWakeUpEvent
2018-07-15 00:36:55.232 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 8: Transaction not completed: node address inconsistent. lastSent=8, incoming=255
==> /var/log/openhab2/events.log <==
2018-07-15 00:36:55.235 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:15cf518cecd:node9' has been updated.
==> /var/log/openhab2/openhab.log <==
2018-07-15 00:36:56.232 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 9: No more messages, go back to sleep
2018-07-15 00:36:56.237 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 9: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
2018-07-15 00:36:56.243 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2018-07-15 00:36:56.243 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2018-07-15 00:36:56.254 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 09 02 84 08 25 04 43
2018-07-15 00:36:56.257 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 9: Sending REQUEST Message = 01 09 00 13 09 02 84 08 25 04 43
2018-07-15 00:36:56.269 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-07-15 00:36:56.273 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-07-15 00:36:56.277 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-07-15 00:36:56.284 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 04 00 00 02 ED
2018-07-15 00:36:56.281 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-07-15 00:36:56.290 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-07-15 00:36:56.292 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 9: Sent Data successfully placed on stack.
2018-07-15 00:36:56.294 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-07-15 00:36:56.297 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 04 00 00 02 00 00 E3
2018-07-15 00:36:56.300 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 04 00 00 02 00 00 E3
2018-07-15 00:36:56.303 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=04 00 00 02
2018-07-15 00:36:56.305 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 9: SendData Request. CallBack ID = 4, Status = Transmission complete and ACK received(0)
2018-07-15 00:36:56.307 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Starting initialisation from DONE
2018-07-15 00:36:56.310 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@18ec6ec already registered
2018-07-15 00:36:56.313 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=9, callback=4, payload=09 02 84 08
2018-07-15 00:36:56.316 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=04 00 00 02
2018-07-15 00:36:56.318 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=4, expected=SendData, cancelled=false transaction complete!
2018-07-15 00:36:56.320 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2018-07-15 00:36:56.322 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 9: Went to sleep
2018-07-15 00:36:56.325 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 9: Is sleeping
2018-07-15 00:36:56.327 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-07-15 00:36:56.329 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 9: Response processed after 70ms/4244ms.
Interesting. It looks from this log that everything is ok - the device sends the data, and the binding is decoding it correctly I think.
If the device is only sending this once, then I would guess it’s a device problem, although I can’t be 100% sure of course.