Fibaro FGD212 dimmer reports dimmer update, not processed in OpenHab

r0bert · January 17, 2021, 12:40pm

Hi all,

I have a problem with my z-wave set-up where I try to create a rule to trigger when someone changes the dimmer brightness of a Fibaro FGD212 dimmer with a physical switch connected to S1.

My .things config:
fibaro_fgd212_03_005 keuken_verlichting "Keuken verlichting" @ "Keuken" [node_id=14]

The .items config:
Dimmer keuken_verlichting "Keuken verlichting" (gKeuken) ["Light"] {channel="zwave:fibaro_fgd212_03_005:controller:keuken_verlichting:switch_dimmer1"}

Everything is working OK (Controller is online, all z-wave things are online), but changing the dimmer-level using the physical switch connected to S1 does not result in an update to OpenHab (i.e. the slider of the item is not updated). I see the following in the logging:

2021-01-17 13:10:53.468 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Application Command Request (ALIVE:DONE)
2021-01-17 13:10:53.469 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: resetResendCount initComplete=true isDead=false
2021-01-17 13:10:53.471 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0
2021-01-17 13:10:53.471 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: SECURITY NOT required on COMMAND_CLASS_SWITCH_MULTILEVEL
2021-01-17 13:10:53.472 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT
2021-01-17 13:10:53.473 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 14: Switch Multi Level report, value = 37
2021-01-17 13:10:53.475 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2021-01-17 13:10:53.476 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=37
2021-01-17 13:10:53.477 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Commands processed 1.
2021-01-17 13:10:53.478 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1fff091.
2021-01-17 13:10:54.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Application Command Request (ALIVE:DONE)
2021-01-17 13:10:54.010 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: resetResendCount initComplete=true isDead=false
2021-01-17 13:10:54.011 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2021-01-17 13:10:54.012 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: SECURITY NOT required on COMMAND_CLASS_SENSOR_MULTILEVEL
2021-01-17 13:10:54.014 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Received COMMAND_CLASS_SENSOR_MULTILEVEL V4 SENSOR_MULTILEVEL_REPORT
2021-01-17 13:10:54.015 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 14: Sensor Type = Power(4), Scale = 0
2021-01-17 13:10:54.017 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 14: Sensor Value = 16.1
2021-01-17 13:10:54.018 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2021-01-17 13:10:54.018 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=16.1
2021-01-17 13:10:54.020 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 14: Sensor conversion not performed for POWER.
2021-01-17 13:10:54.021 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Updating channel state zwave:fibaro_fgd212_03_005:controller:keuken_verlichting:sensor_power to 16.1 [DecimalType]
2021-01-17 13:10:54.022 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Commands processed 1.
2021-01-17 13:10:54.023 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@e346e7.
2021-01-17 13:10:59.016 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Application Command Request (ALIVE:DONE)
2021-01-17 13:10:59.016 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: resetResendCount initComplete=true isDead=false
2021-01-17 13:10:59.017 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2021-01-17 13:10:59.018 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: SECURITY NOT required on COMMAND_CLASS_SENSOR_MULTILEVEL
2021-01-17 13:10:59.018 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Received COMMAND_CLASS_SENSOR_MULTILEVEL V4 SENSOR_MULTILEVEL_REPORT
2021-01-17 13:10:59.019 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 14: Sensor Type = Power(4), Scale = 0
2021-01-17 13:10:59.020 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 14: Sensor Value = 14.7
2021-01-17 13:10:59.021 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2021-01-17 13:10:59.021 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=14.7
2021-01-17 13:10:59.022 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 14: Sensor conversion not performed for POWER.
2021-01-17 13:10:59.023 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Updating channel state zwave:fibaro_fgd212_03_005:controller:keuken_verlichting:sensor_power to 14.7 [DecimalType]
2021-01-17 13:10:59.024 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Commands processed 1.
2021-01-17 13:10:59.025 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1a36030.

The relevant line (I think) from the logging above is:

2021-01-17 13:10:53.473 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 14: Switch Multi Level report, value = 37

If I dim the lights, this value gets lower, and vice versa.

If I look at another topic (Aeotec RGBW Bulb 6 - help with rules / sitemap), the logging in that topic includes the following line, but is not present in my logging (please note, this concerns a different z-wave device):

NODE 13: Updating channel state zwave:device:controller:node13:switch_dimmer to 9 [PercentType]

It seems as if the channel state is never updated. Is this expected behaviour? (I hope not!)

Additional relevant information:
OpenHabian running openHab 3.0.0 release build with the 3.0.0 version of the z-wave binding.

Thanks for reading

Robert

Bruce_Osborne · January 17, 2021, 12:42pm

I do not know but the Z-Wave log viewer may help you find ideas.

r0bert · January 17, 2021, 1:34pm

The logviewer does not seem to work for me unfortunately. I did some digging around in the z-wave binding code, and it seems there might be a mismatch between what the FGD212 dimmer reports, and what the binding expects based on the device database (I now enabled TRACE logging):

2021-01-17 14:30:08.522 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 14: Message payload = 00 0E 03 26 03 2B 
2021-01-17 14:30:08.532 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Application Command Request (ALIVE:DONE)
2021-01-17 14:30:08.533 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: resetResendCount initComplete=true isDead=false
2021-01-17 14:30:08.535 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0
2021-01-17 14:30:08.536 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 14: SECURITY NOT required on COMMAND_CLASS_SWITCH_MULTILEVEL
2021-01-17 14:30:08.538 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 14: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT
2021-01-17 14:30:08.539 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 14: Switch Multi Level report, value = 43
2021-01-17 14:30:08.542 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2021-01-17 14:30:08.543 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=43
2021-01-17 14:30:08.544 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:scene_number, cmdClass=COMMAND_CLASS_SCENE_ACTIVATION, endpoint=0
2021-01-17 14:30:08.545 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:sensor_power, cmdClass=COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint=0
2021-01-17 14:30:08.545 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:meter_kwh, cmdClass=COMMAND_CLASS_METER, endpoint=0
2021-01-17 14:30:08.546 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:meter_watts, cmdClass=COMMAND_CLASS_METER, endpoint=0
2021-01-17 14:30:08.547 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:meter_reset, cmdClass=COMMAND_CLASS_METER, endpoint=0
2021-01-17 14:30:08.548 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:config_decimal_param19, cmdClass=COMMAND_CLASS_CONFIGURATION, endpoint=0
2021-01-17 14:30:08.548 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:config_decimal_param26, cmdClass=COMMAND_CLASS_CONFIGURATION, endpoint=0
2021-01-17 14:30:08.549 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:alarm_heat, cmdClass=COMMAND_CLASS_ALARM, endpoint=0
2021-01-17 14:30:08.550 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:alarm_power, cmdClass=COMMAND_CLASS_ALARM, endpoint=0
2021-01-17 14:30:08.550 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:alarm_system, cmdClass=COMMAND_CLASS_ALARM, endpoint=0
2021-01-17 14:30:08.551 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:switch_dimmer1, cmdClass=COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint=1
2021-01-17 14:30:08.552 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:switch_dimmer1, cmdClass=COMMAND_CLASS_BASIC, endpoint=1
2021-01-17 14:30:08.553 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:sensor_power1, cmdClass=COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint=1
2021-01-17 14:30:08.554 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:meter_kwh1, cmdClass=COMMAND_CLASS_METER, endpoint=1
2021-01-17 14:30:08.554 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:meter_watts1, cmdClass=COMMAND_CLASS_METER, endpoint=1
2021-01-17 14:30:08.555 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:alarm_heat1, cmdClass=COMMAND_CLASS_ALARM, endpoint=1
2021-01-17 14:30:08.556 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:alarm_power1, cmdClass=COMMAND_CLASS_ALARM, endpoint=1
2021-01-17 14:30:08.557 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:alarm_system1, cmdClass=COMMAND_CLASS_ALARM, endpoint=1
2021-01-17 14:30:08.558 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:notification_send1, cmdClass=COMMAND_CLASS_ALARM, endpoint=1
2021-01-17 14:30:08.558 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:switch_dimmer2, cmdClass=COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint=2
2021-01-17 14:30:08.559 [TRACE] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Checking channel=zwave:device:controller:node14:switch_dimmer2, cmdClass=COMMAND_CLASS_BASIC, endpoint=2
2021-01-17 14:30:08.560 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 14: Commands processed 1.

The switch_dimmer1 is at endpoint 1, however the dimmer percentage is sent to endpoint 0, might that be the cause of the problem here?

Bruce_Osborne · January 17, 2021, 1:52pm

I just realized you posted filtered logs. @chris needs unfiltered DEBUIG logs for troubleshooting. Filtered logs are useless for troubleshooting.

Also, please post the xml file from the zwave folder of userdata. Sometimes features are added or changed with device firmware versions.

r0bert · January 17, 2021, 2:32pm

Hi @Bruce_Osborne and @chris ,

Thanks for the reply. Attached you’ll find the logs, I’ve performed the following

Set log level to TRACE
Remove node 14 (this is the dimmer)
Disable all things except the z-wave serial controller
Remove all logfiles
Restart openhab
Add the discovered node 14
Change the dimming level twice
Collect logs and XML

The openhab.log file can be downloaded from WeTransfer: https://we.tl/t-kL61RvJOci
The XML file from the user data folder is attached: network_c2aa8fde__node_14.xml (44.7 KB)

Update:

The z-wave log viewer is indeed able to parse the entire log I can see the following there:

It looks as if the SWITCH_MULTILEVEL_REPORT is not handled. I tried updating the device XML in the database in the zwave binding JAR file, but no luck so far (that’s probably due to me not being familiar with the details of how to do this ;-))

chris · January 17, 2021, 3:09pm

The issue is that this is a multiendpoint device, but the device is not reporting using multichannel encapsulation as expected by the binding. In theory this should be configured during the initialisation (ie right after inclusion) - was that done with the binding or something else?

r0bert · January 17, 2021, 3:14pm

I used the button of my Aeotec z-stick gen5 to include the device. After that I added the z-wave Thing from the inbox in openHab. Will I get a different result when including the device from within openHab?

chris · January 17, 2021, 3:17pm

That’s fine - but you used the latest version of the binding, and not some other software to immediately after it was included?

If so, can you do a reinitialisation - there is an option in the configuration to do this. Please then provide the debug log so I can see what the binding is sending (it will probably be quite large so you’ll need to find somewhere to host it most likely)…

r0bert · January 17, 2021, 3:30pm

Hi Chris,

Thanks for helping me out Indeed, I included the device using the button on the z-stick, and plugged it in my raspberry PI with only openHab installed (OpenHabian latest). I did not update any version of the bindings (there are no updates available actually).

I did the following to get the log:

Stop openHab
Remove all existing logfiles
Start openHab
Reinitialize node 14 (this is the dimmer)
Stop openHab
Collect logs

I’ve uploaded the log file to WeTransfer: https://we.tl/t-FwZCQIn8pq

r0bert · January 19, 2021, 6:58pm

@chris

Not sure if this helps, but it seems that after the reinitialise, the controller polls the dimmer module and it correctly receives and sets the dimmer1 value (but only once, subsequent status updates by the module itself don’t work):

Bruce_Osborne · January 19, 2021, 9:29pm

That looks like a filtered log. Only unfiltered logs are useful for troubleshooting.

r0bert · January 19, 2021, 9:50pm

Hi Bruce,

The screenshot is actually an excerpt of the complete logfile in my precious post. Do you mean that that logfile is incomplete as well? (Just checking since I did not alter or mutate it)

Bruce_Osborne · January 19, 2021, 10:41pm

Not necessarily. Perhaps at that time no other node was communicating. Many people filter on the node of interest and that is not useful.

Joern1 · March 29, 2021, 3:41pm

Dear all, I do not know if its in the right context, but OH3 may have issues with a AntiVirus Software. I just freshly installed OH3 and set up Rasp PI4 with Aeotec Stick 5 plus (works fine ) but my Fibaro Plug was only able to switch on (not off !). I remembered from a AVM Fritzbox issue to this link. Putting OH3 adress to the black list resolved my updating problem.

Link: (No Data visible in Widgets /Pages - #3 by eloka080677)

Bruce_Osborne · March 29, 2021, 3:49pm

You are running antivirus software on a Pi 4? What software?

If it conflicts with OH it would be a configuration issue for that software.

r0bert · March 29, 2021, 6:32pm

Thanks Joern1, but I’m not running anything other than OpenHabian (so without anti-virus) on the Pi4. Other status updates work correctly, so it really seems to be caused by miscommunication /misconfiguration between de z-wave binding and the dimmer.

Joern1 · March 30, 2021, 11:26am

Sorry, this might be missunderstanding. The problem is, if you use Antivirus on your remote PC e.g. Windows PC to access the http page of your raspi, the Windows Antivirus e.g. in my case AVIRA Antivirus might block the data. In this case, you have to switch of WebSercurity or enter the IP address in the execption list. Just as a hint.

Bruce_Osborne · March 30, 2021, 11:57am

That is an AV configuration issue then.