[ZWave] FGD212 not reporting status back

ljsquare · February 17, 2020, 7:59am

I’ve a couple of Fibaro FGD212 dimmers and all except 1 report the status back. I run openhab 2.5-2

items:

Dimmer						Kitchen_Light_Dimmer1								"Keuken lamp [%d %%]"									<light>			(Kitchen, PresenceSimulations, GroundFloor_Lights, Lights, Node24)										{ channel="zwave:device:512:node24:switch_dimmer1" }
Dimmer						Bathroom_Light_Dimmer1								"Badkamer lamp [%d %%]"									<light>			(Bathroom, FirstFloor_Lights, Lights, Node8)																{ channel="zwave:device:512:node8:switch_dimmer1" }
Dimmer						MasterBedroom_Light_Dimmer1							"Slaapkamer lamp [%d %%]"								<light>			(MasterBedroom, PresenceSimulations, FirstFloor_Lights, Lights, Node9)										{ channel="zwave:device:512:node9:switch_dimmer1" }

What I mean is when I flip the switch of Bathroom_Light_Dimmer I get in my log this event:
Bathroom_Light_Dimmer1 changed from 0 to 100
As expect it, so does MasterBedroom_Light_Dimmer1
But with the Kitchen_Light_Dimmer1 I won’t get any event report. The devices works, the light will go on, but it doesn’t report back his percentage (eg 100). OH still thinks the item state is 0.

In both PaperUI and HABMin the lifeline is the controller:
HABMin

PaperUI

Other channels (such as power and scene events) do get reported back. Somehow only channel dimmer1 (and dimmer2, the second switch) are not reported back.

Do I miss something? Can I log something else to search for the cause?

Charley · February 17, 2020, 2:06pm

Is it a Zwave+ device?
If it is only Zwave then there is no reporting back when you use a switch.

chris · February 17, 2020, 2:09pm

That’s not correct - most ZWave devices also support reporting and I have a number of older (non-ZW+) Fibaro devices that certainly do.

Associations and reporting is not a new concept in ZW+ - the only change is that the lifeline (group 1) became a requirement rather than a “nice to have”.

This device should report given it’s got a lifeline group and it’s configured to report to the controller.

Charley · February 17, 2020, 2:12pm

@chris
Sorry my mistake. I was always thinking the wrong way. Also have two dimmers that don’t give any status and they are both ZW non plus.

ljsquare · February 17, 2020, 6:27pm

That’s exactly what I thought. I’ve even compare all the parameters of my devices and they are all the same (except min max dim values). And still one does not report back.
Shall I post a debug log of the zwave binding to see if something is wrong?

Bruce_Osborne · February 17, 2020, 6:43pm

Just checking but are the device type, id, and firmware versions all the same too?

ljsquare · February 17, 2020, 6:47pm

Yes all the same

ljsquare · February 17, 2020, 7:22pm

In this log I’ve switch on and off the first switch (s1). It reports the 75% (set by force brightness) and later 0%. But OH won’t update the item.


2020-02-17 20:14:26.893 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0A 00 04 00 18 04 2B 01 0A 00 CD 
2020-02-17 20:14:26.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 04 2B 01 0A 00 
2020-02-17 20:14:26.908 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 04 2B 01 0A 00 
2020-02-17 20:14:26.920 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-17 20:14:26.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Application Command Request (ALIVE:DONE)
2020-02-17 20:14:26.925 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: resetResendCount initComplete=true isDead=false
2020-02-17 20:14:26.927 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: Incoming command class COMMAND_CLASS_SCENE_ACTIVATION, endpoint 0
2020-02-17 20:14:26.929 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: SECURITY NOT required on COMMAND_CLASS_SCENE_ACTIVATION
2020-02-17 20:14:26.935 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 24: Received COMMAND_CLASS_SCENE_ACTIVATION V1 SCENEACTIVATION_SET
2020-02-17 20:14:26.939 [DEBUG] [ass.ZWaveSceneActivationCommandClass] - NODE 24: Scene activation: Scene 10, Time 0
2020-02-17 20:14:26.943 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2020-02-17 20:14:26.948 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SCENE_ACTIVATION, value=10
2020-02-17 20:14:26.953 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Updating channel state zwave:device:512:node24:scene_number to 10 [DecimalType]
2020-02-17 20:14:26.960 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Commands processed 1.
2020-02-17 20:14:26.968 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@31acb6.
2020-02-17 20:14:26.971 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:26.973 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:26.976 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-17 20:14:26.978 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-17 20:14:27.358 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 18 03 26 03 4B 87 
2020-02-17 20:14:27.366 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 03 26 03 4B 
2020-02-17 20:14:27.371 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 03 26 03 4B 
2020-02-17 20:14:27.373 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-17 20:14:27.376 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Application Command Request (ALIVE:DONE)
2020-02-17 20:14:27.378 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: resetResendCount initComplete=true isDead=false
2020-02-17 20:14:27.380 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0
2020-02-17 20:14:27.383 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: SECURITY NOT required on COMMAND_CLASS_SWITCH_MULTILEVEL
2020-02-17 20:14:27.385 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 24: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT
2020-02-17 20:14:27.388 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 24: Switch Multi Level report, value = 75
2020-02-17 20:14:27.390 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2020-02-17 20:14:27.393 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=75
2020-02-17 20:14:27.397 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Commands processed 1.
2020-02-17 20:14:27.400 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@3cc99.
2020-02-17 20:14:27.402 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:27.405 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:27.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-17 20:14:27.411 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-17 20:14:27.424 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 18 03 26 03 4B 87 
2020-02-17 20:14:27.431 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 03 26 03 4B 
2020-02-17 20:14:27.436 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 03 26 03 4B 
2020-02-17 20:14:27.439 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-17 20:14:27.441 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Application Command Request (ALIVE:DONE)
2020-02-17 20:14:27.444 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: resetResendCount initComplete=true isDead=false
2020-02-17 20:14:27.447 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0
2020-02-17 20:14:27.449 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: SECURITY NOT required on COMMAND_CLASS_SWITCH_MULTILEVEL
2020-02-17 20:14:27.452 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 24: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT
2020-02-17 20:14:27.454 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 24: Switch Multi Level report, value = 75
2020-02-17 20:14:27.456 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2020-02-17 20:14:27.459 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=75
2020-02-17 20:14:27.462 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Commands processed 1.
2020-02-17 20:14:27.464 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1ba04ef.
2020-02-17 20:14:27.466 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:27.471 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:27.474 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-17 20:14:27.477 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-17 20:14:27.496 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 18 06 31 05 04 22 00 07 FC 
2020-02-17 20:14:27.505 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 06 31 05 04 22 00 07 
2020-02-17 20:14:27.511 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 06 31 05 04 22 00 07 
2020-02-17 20:14:27.514 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-17 20:14:27.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Application Command Request (ALIVE:DONE)
2020-02-17 20:14:27.520 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: resetResendCount initComplete=true isDead=false
2020-02-17 20:14:27.522 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2020-02-17 20:14:27.526 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: SECURITY NOT required on COMMAND_CLASS_SENSOR_MULTILEVEL
2020-02-17 20:14:27.528 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 24: Received COMMAND_CLASS_SENSOR_MULTILEVEL V4 SENSOR_MULTILEVEL_REPORT
2020-02-17 20:14:27.531 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 24: Sensor Type = Power(4), Scale = 0
2020-02-17 20:14:27.534 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 24: Sensor Value = 0.7
2020-02-17 20:14:27.538 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2020-02-17 20:14:27.541 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=0.7
2020-02-17 20:14:27.546 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 24: Sensor conversion not performed for POWER.
2020-02-17 20:14:27.550 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Updating channel state zwave:device:512:node24:sensor_power to 0.7 [DecimalType]
2020-02-17 20:14:27.554 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Commands processed 1.
2020-02-17 20:14:27.556 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@dea76a.
2020-02-17 20:14:27.560 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:27.562 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:27.565 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-17 20:14:27.567 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-17 20:14:32.902 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 18 06 31 05 04 22 00 81 7A 
2020-02-17 20:14:32.912 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 06 31 05 04 22 00 81 
2020-02-17 20:14:32.918 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 06 31 05 04 22 00 81 
2020-02-17 20:14:32.922 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-17 20:14:32.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Application Command Request (ALIVE:DONE)
2020-02-17 20:14:32.927 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: resetResendCount initComplete=true isDead=false
2020-02-17 20:14:32.930 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2020-02-17 20:14:32.933 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: SECURITY NOT required on COMMAND_CLASS_SENSOR_MULTILEVEL
2020-02-17 20:14:32.935 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 24: Received COMMAND_CLASS_SENSOR_MULTILEVEL V4 SENSOR_MULTILEVEL_REPORT
2020-02-17 20:14:32.938 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 24: Sensor Type = Power(4), Scale = 0
2020-02-17 20:14:32.941 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 24: Sensor Value = 12.9
2020-02-17 20:14:32.944 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2020-02-17 20:14:32.946 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=12.9
2020-02-17 20:14:32.951 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 24: Sensor conversion not performed for POWER.
2020-02-17 20:14:32.953 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Updating channel state zwave:device:512:node24:sensor_power to 12.9 [DecimalType]
2020-02-17 20:14:32.957 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Commands processed 1.
2020-02-17 20:14:32.960 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@11bf05b.
2020-02-17 20:14:32.963 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:32.965 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:32.968 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-17 20:14:32.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-17 20:14:41.724 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0A 00 04 00 18 04 2B 01 0B 00 CC 
2020-02-17 20:14:41.736 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 04 2B 01 0B 00 
2020-02-17 20:14:41.741 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 04 2B 01 0B 00 
2020-02-17 20:14:41.744 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-17 20:14:41.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Application Command Request (ALIVE:DONE)
2020-02-17 20:14:41.750 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: resetResendCount initComplete=true isDead=false
2020-02-17 20:14:41.753 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: Incoming command class COMMAND_CLASS_SCENE_ACTIVATION, endpoint 0
2020-02-17 20:14:41.756 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: SECURITY NOT required on COMMAND_CLASS_SCENE_ACTIVATION
2020-02-17 20:14:41.759 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 24: Received COMMAND_CLASS_SCENE_ACTIVATION V1 SCENEACTIVATION_SET
2020-02-17 20:14:41.762 [DEBUG] [ass.ZWaveSceneActivationCommandClass] - NODE 24: Scene activation: Scene 11, Time 0
2020-02-17 20:14:41.765 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2020-02-17 20:14:41.768 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SCENE_ACTIVATION, value=11
2020-02-17 20:14:41.773 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Updating channel state zwave:device:512:node24:scene_number to 11 [DecimalType]
2020-02-17 20:14:41.778 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Commands processed 1.
2020-02-17 20:14:41.782 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1ea9e65.
2020-02-17 20:14:41.790 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:41.793 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:41.796 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-17 20:14:41.799 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-17 20:14:42.082 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 18 03 26 03 00 CC 
2020-02-17 20:14:42.090 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 03 26 03 00 
2020-02-17 20:14:42.093 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 03 26 03 00 
2020-02-17 20:14:42.096 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-17 20:14:42.098 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Application Command Request (ALIVE:DONE)
2020-02-17 20:14:42.101 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: resetResendCount initComplete=true isDead=false
2020-02-17 20:14:42.103 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0
2020-02-17 20:14:42.105 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: SECURITY NOT required on COMMAND_CLASS_SWITCH_MULTILEVEL
2020-02-17 20:14:42.108 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 24: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT
2020-02-17 20:14:42.110 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 24: Switch Multi Level report, value = 0
2020-02-17 20:14:42.113 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2020-02-17 20:14:42.115 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=0
2020-02-17 20:14:42.120 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Commands processed 1.
2020-02-17 20:14:42.123 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@16608b.
2020-02-17 20:14:42.126 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:42.129 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:42.132 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-17 20:14:42.134 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-17 20:14:42.882 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 18 06 31 05 04 22 00 0D F6 
2020-02-17 20:14:42.890 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 06 31 05 04 22 00 0D 
2020-02-17 20:14:42.896 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 06 31 05 04 22 00 0D 
2020-02-17 20:14:42.899 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-17 20:14:42.902 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Application Command Request (ALIVE:DONE)
2020-02-17 20:14:42.904 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: resetResendCount initComplete=true isDead=false
2020-02-17 20:14:42.906 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2020-02-17 20:14:42.909 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: SECURITY NOT required on COMMAND_CLASS_SENSOR_MULTILEVEL
2020-02-17 20:14:42.911 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 24: Received COMMAND_CLASS_SENSOR_MULTILEVEL V4 SENSOR_MULTILEVEL_REPORT
2020-02-17 20:14:42.914 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 24: Sensor Type = Power(4), Scale = 0
2020-02-17 20:14:42.917 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 24: Sensor Value = 1.3
2020-02-17 20:14:42.920 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2020-02-17 20:14:42.923 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=1.3
2020-02-17 20:14:42.927 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 24: Sensor conversion not performed for POWER.
2020-02-17 20:14:42.930 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Updating channel state zwave:device:512:node24:sensor_power to 1.3 [DecimalType]
2020-02-17 20:14:42.934 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Commands processed 1.
2020-02-17 20:14:42.936 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1fa6154.
2020-02-17 20:14:42.938 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:42.940 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:42.942 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-17 20:14:42.945 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-02-17 20:14:53.862 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 18 06 31 05 04 22 00 00 FB 
2020-02-17 20:14:53.873 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 06 31 05 04 22 00 00 
2020-02-17 20:14:53.879 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=24, callback=0, payload=00 18 06 31 05 04 22 00 00 
2020-02-17 20:14:53.882 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-02-17 20:14:53.885 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Application Command Request (ALIVE:DONE)
2020-02-17 20:14:53.887 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: resetResendCount initComplete=true isDead=false
2020-02-17 20:14:53.890 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2020-02-17 20:14:53.892 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: SECURITY NOT required on COMMAND_CLASS_SENSOR_MULTILEVEL
2020-02-17 20:14:53.894 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 24: Received COMMAND_CLASS_SENSOR_MULTILEVEL V4 SENSOR_MULTILEVEL_REPORT
2020-02-17 20:14:53.896 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 24: Sensor Type = Power(4), Scale = 0
2020-02-17 20:14:53.898 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 24: Sensor Value = 0E+1
2020-02-17 20:14:53.900 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2020-02-17 20:14:53.903 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=0E+1
2020-02-17 20:14:53.906 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 24: Sensor conversion not performed for POWER.
2020-02-17 20:14:53.908 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Updating channel state zwave:device:512:node24:sensor_power to 0 [DecimalType]
2020-02-17 20:14:53.911 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Commands processed 1.
2020-02-17 20:14:53.913 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 24: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1d1c258.
2020-02-17 20:14:53.915 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:53.917 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-02-17 20:14:53.919 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-02-17 20:14:53.921 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

chris · February 17, 2020, 7:25pm

Were any of these devices used with different software or a previous version of OH?

ljsquare · February 17, 2020, 10:26pm

Nope, the working devices are long existing, they worked in 2.4 up to the latest 2.5.2 version of OH.
The faulty device is new, just 2 days in the system.

ljsquare · February 18, 2020, 7:53pm

OK, little odd update.
If I send a command to the force_brightness channel, I get the update of the dimmer channel back.

2020-02-18 20:48:09.580 [vent.ItemStateChangedEvent] - Kitchen_Light_Scene changed from 21 to 20
2020-02-18 20:48:13.144 [nt.ItemStatePredictedEvent] - Kitchen_Light_ForceBrightness predicted to become 90
2020-02-18 20:48:13.187 [GroupItemStateChangedEvent] - Light_ForceBrightnesses changed from 99 to 90 through Kitchen_Light_ForceBrightness
2020-02-18 20:48:13.192 [vent.ItemStateChangedEvent] - Kitchen_Light_ForceBrightness changed from 99 to 90
2020-02-18 20:48:15.215 [vent.ItemStateChangedEvent] - Kitchen_Light_Dimmer2 changed from 0 to 100

In the log above: I flip the switch connected to S2 (second switch), it reports a scene changes, but no dimmer change (or update).
Then I send a command with the karaf console: smarthome:send Kitchen_Light_ForceBrightness 90
And then as expected, it report the force brightness back AND the dimmer channel.

I’ve already done a soft reset of the controller and a restart of OH with clean cache, but the problem still exists.

ljsquare · February 20, 2020, 8:27am

Second update:

In Domoticz it works like it suppose to be. If I flip the switch, Domoticz reacts and set the switch accordingly.

So it seems like a OH problem. I’m using the last zwave binding.

@chris, any idea how I can debug this problem?

chris · February 20, 2020, 12:37pm

The issue will be related to MC Associations which is quite a messy area. ZWave changed this a lot over a short time - they added 3 or 4 different versions of the command classes over one or two years and this led to a lot of different implementations.

Currently the binding tries to use MCA when the device supports multiple channels to ensure that MC reports are used (otherwise in theory the information doesn’t allow the binding to know what switch it comes from).

If you have a log showing the device reinitialisation I will take a look at what the binding does. Possibly the best thing is to exclude and re-include the device to be sure it is reset.

ljsquare · February 23, 2020, 8:40am

If re-included the device. It took a while, it was hard to get it in include-mode, somehow.
But now OH sees it as an unknown device.
What now?
zwavelog.txt.zip.txt (474.7 KB) (rename to .zip)
Node 24 was the excluded one, node 25 the new included

chris · February 23, 2020, 9:21am

Strange - in the log it clearly shows that it has been fully discovered, and it shows the correct thing type was selected, so I don’t know why it is still showing that this is not the case.

What exactly do you see?

ljsquare · February 23, 2020, 9:53am

I’ve just check, now it sees it as a Fibaro dimmer 2, as suppose to be.
But at the moment I can’t test the original problem, the status report.
I’ll try to test it this afternoon.

ljsquare · February 23, 2020, 2:12pm

Well, it did the trick. It works now as suppose it should. Thanks for the help, @chris