LED Light not turning off with ZWave control

kdsnet3410 · October 17, 2019, 11:55pm

This is really strange so I will try to explain it the best I can. I have several Cooper/Eaton RF9640 Dimmers in my house. I have group associations configured so they can be controlled from various locations using the RF9642 accessory dimmer. Everything works as expected. I can turn the lights on and off from all physical locations. The synced devices update each other and remained synced as expected. All Good. Then I try to control using OpenHAB. I can turn the lights on and dim them no problem. Indicator LEDs on both the master dimmer and the accessory dimmer sync with the commands from OpenHAB. All is well. Until I try to turn the lights off in OpenHAB. I turn the brightness to zero and the lights remain to glow but only when there is a single lamp in the circuit. If there are two LED lamps in a fixture or more than one fixture then it works as expected. They are obviously LED compatible dimmers and I am using dimmable LEDs. The dimmers are receiving the command from OpenHAB because the dimming level is all the way down and the amber LED on the face plates goes off to indicate the load is off. I only run into the problem when turning the lights off using ZWave. Perfectly fine when using the switches…

I have seen others with similar issues, but never where they will work from the physical device and not ZWave control. Any suggestions besides adding a dummy load or switching to incandescent lamps.

Thanks!

Bruce_Osborne · October 18, 2019, 12:09am

You have told us nothing about the software or environment it runs in.

kdsnet3410 · October 18, 2019, 12:27am

My apologies. I am running 2.5.0.M3 Milestone Build on openhabian. My ZWave bridge is a Aeotec Z-Stick Gen5. I am running the ZWave binding that was built yesterday.

rossko57 · October 18, 2019, 10:52am

Could you tell us what that involves - rule, UI ? Or better, show the events.log for what commands get sent to what.

kdsnet3410 · October 18, 2019, 11:55am

I have a slider widget in HABPanel to control the lighting. However, I have the same issues when using the control tab in PaperUI and the on/off switch in HABMin. I also tried sending an “OFF” to the dimmer item and get the same result as sending a “0”.

When I get home in about 10 hours I will post the log of when the device is controlled from the physical location and when controlled from OpenHAB for comparison. If I recall, I didn’t see anything difference between what the device sent to OpenHAB and what OpenHAB sent to the device. But I will confirm and upload a log.

kdsnet3410 · October 18, 2019, 8:48pm

When I push the button on the physical device I get the following logs:

2019-10-18 16:38:52.347 [vent.ItemStateChangedEvent] - FoyerLight_Dimmer changed from 0 to 100

2019-10-18 16:39:04.611 [vent.ItemStateChangedEvent] - FoyerLight_Dimmer changed from 100 to 0

When I slide the slider in HABPanel I get the following logs:

2019-10-18 16:39:09.668 [ome.event.ItemCommandEvent] - Item 'FoyerLight_Dimmer' received command 100

2019-10-18 16:39:09.684 [nt.ItemStatePredictedEvent] - FoyerLight_Dimmer predicted to become 100

2019-10-18 16:39:09.781 [vent.ItemStateChangedEvent] - FoyerLight_Dimmer changed from 0 to 100

2019-10-18 16:39:12.781 [ome.event.ItemCommandEvent] - Item 'FoyerLight_Dimmer' received command 0

2019-10-18 16:39:12.788 [nt.ItemStatePredictedEvent] - FoyerLight_Dimmer predicted to become 0

2019-10-18 16:39:12.862 [vent.ItemStateChangedEvent] - FoyerLight_Dimmer changed from 100 to 0

rossko57 · October 18, 2019, 9:43pm

Okay, there’s no reason to think you are not sending “0” across the zwave to the device.
As this produces different results from the local controls, we can presume “off” is different to “0”.

I’ve no idea if the zwave config for this device can deal with ON/OFF separately from 0-100%, but I guess that is the area to be looking into.

What happens if you command an OFF from UI switch (instead of slider)

kdsnet3410 · October 18, 2019, 10:36pm

This is what happens when I use a switch instead in HABPanel:

2019-10-18 18:26:16.096 [ome.event.ItemCommandEvent] - Item 'FoyerLight_Dimmer' received command ON

2019-10-18 18:26:16.104 [nt.ItemStatePredictedEvent] - FoyerLight_Dimmer predicted to become ON

2019-10-18 18:26:16.252 [vent.ItemStateChangedEvent] - FoyerLight_Dimmer changed from 0 to 100

2019-10-18 18:26:19.965 [ome.event.ItemCommandEvent] - Item 'FoyerLight_Dimmer' received command OFF

2019-10-18 18:26:19.975 [nt.ItemStatePredictedEvent] - FoyerLight_Dimmer predicted to become OFF

2019-10-18 18:26:20.010 [vent.ItemStateChangedEvent] - FoyerLight_Dimmer changed from 100 to 0

After the off is sent the list remained slightly illuminated as before.

The instructions for the switch can be found here:
https://www.eaton.com/content/dam/eaton/products/wiring-devices-and-connectivity/wiring-devices/z-wave-plus/z-wave-wireless-dimmer-access-RF9640N-RF9642Z-instrsheet.pdf

What I think that is important is there are three association groups; (1) lifeline, (2) dim, and (3) on/off. Is there a way for me to force a “off” to association group 3 when the dim value becomes 0? I am not sure if that is even a valid question in the context of ZWave devices. I am new and slowly learning how these devices communicate and update info across the network. I helped build the device definition but was a littly fuzzy on how the endpoints should be configured.

https://www.cd-jackson.com/index.php/zwave/zwave-device-database/zwave-device-list/devicesummary/1098

Bruce_Osborne · October 18, 2019, 10:43pm

Only Group 1 Lifeline should be tagged as controller for Z-Wave Plus, I believe. @chris can confirm or correct as appropriate,
That listing has a 3 association groups tagged as controller.

chris · October 18, 2019, 11:12pm

Yes, in general this should be the case. Maybe there are some exceptions, but I can’t think of any off the top of my head.

Bruce_Osborne · October 18, 2019, 11:20pm

Do you want me to “fix” this one?

chris · October 19, 2019, 8:02am

Yes, I doubt that this is required. With the lifeline, the device should send all these reports to the controller and by adding an explicit link to the controller in these groups it’s likely there will be duplicated messages sent which causes more problems.

Maybe this device doesn’t do that and these associations are required, but I think it’s unlikely. Only a debug log can tell - unless there is information to the contrary, I would remove the links and check the logs after the change is made, although by removing the database links it will not now automatically remove the associations from the device.

Bruce_Osborne · October 19, 2019, 9:53am

I updated the database. Now to wait for reviews, export, & snapshot build of the binding. I know Chris is super busy outsude of OH right now but he usually exports about once a week.

chris · October 19, 2019, 10:14am

I will probably do an update later today or tonight.

kdsnet3410 · October 19, 2019, 11:26am

Ok, I was able to update my xml file locally in the zwave jar file. I can now remove controller from all association which I was not able to do before. However, in PaperUI the “defaultAssociations” still shows as 1,2,3 even after a stop, cache clear, and start. Maybe that gets resolved once I grab a new build. But I am still getting the glowing light at dim level 0. Everything is working as before so I assume the database update is required to at least remove extra overhead from the ZWave network.

kdsnet3410 · November 6, 2019, 1:32am

Its been a few weeks and I would like to post another update and see if anyone has additional ideas. I did grab the latest binding and am still having the same issues. Also, I was able to verify that when controlling the RF9640 with Eaton’s Home automation hub the devices dim completely and turns off. I also verified the predecessor to this device (RF9540) works with both Eaton’s Home automation hub and OpenHAB. So in short, I am only able to reproduce the problem with the RF9640 and OpenHAB.

There are several differences between RF9540 and the RF9640 including the addition of z-wave plus. But one of the big things I noticed was the addition an association group called Set. Is there anyway to send an off to the Set association group when the dimmer level is 0?

chris · November 6, 2019, 1:56am

You can’t send commands to an association group - associations are used to configure a device to send commands, not to receive them

kdsnet3410 · November 6, 2019, 2:13am

@chris is there anything I can provide that can help narrow the problem down? Or is this just a device that will not be able to be fully supported due to poor design of the device?

chris · November 7, 2019, 1:12pm

Can you provide a debug log. I would expect that if you send an OFF command, then this should send he binary_switch command which should power the device off. If it works when pressing the switch, then it should also work remotely.

kdsnet3410 · November 7, 2019, 11:27pm

I collected the debug logs for thee tests. The dimmer I am testing is node 85 and is called TestBench.

The first test shows logs captured by pressing the button on the device (on then off)

2019-11-07 17:22:31.323 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1C 00 49 84 55 16 04 11 01 5E 26 85 59 55 86 72 5A 73 77 70 2B 2C 71 75 98 9F 6C 7A 40 

2019-11-07 17:22:31.340 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=85, callback=132, payload=84 55 16 04 11 01 5E 26 85 59 55 86 72 5A 73 77 70 2B 2C 71 75 98 9F 6C 7A 

2019-11-07 17:22:31.349 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 55 03 20 03 63 E4 

2019-11-07 17:22:31.349 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=85, callback=132, payload=84 55 16 04 11 01 5E 26 85 59 55 86 72 5A 73 77 70 2B 2C 71 75 98 9F 6C 7A 

2019-11-07 17:22:31.356 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=85, callback=0, payload=00 55 03 20 03 63 

2019-11-07 17:22:31.358 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2019-11-07 17:22:31.365 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0

2019-11-07 17:22:31.369 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null

2019-11-07 17:22:31.375 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=85, callback=132, payload=84 55 16 04 11 01 5E 26 85 59 55 86 72 5A 73 77 70 2B 2C 71 75 98 9F 6C 7A 

2019-11-07 17:22:31.378 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 85: Application update request. Node information received. Transaction null

2019-11-07 17:22:31.381 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 85: resetResendCount initComplete=true isDead=false

2019-11-07 17:22:31.384 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 85: Application update - no transaction.

2019-11-07 17:22:31.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=85, callback=0, payload=00 55 03 20 03 63 

2019-11-07 17:22:31.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2019-11-07 17:22:31.396 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 85: Application Command Request (ALIVE:DONE)

2019-11-07 17:22:31.399 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 85: resetResendCount initComplete=true isDead=false

2019-11-07 17:22:31.402 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 85: Incoming command class COMMAND_CLASS_BASIC, endpoint 0

2019-11-07 17:22:31.405 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 85: SECURITY NOT required on COMMAND_CLASS_BASIC

2019-11-07 17:22:31.408 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 85: Received COMMAND_CLASS_BASIC V1 BASIC_REPORT

2019-11-07 17:22:31.411 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 85: Basic report, value = 99

2019-11-07 17:22:31.416 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 85: Got an event from Z-Wave network: ZWaveCommandClassValueEvent

2019-11-07 17:22:31.420 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 85: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_BASIC, value=99

2019-11-07 17:22:31.425 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 85: Updating channel state zwave:device:54aea7e5:node85:switch_dimmer to 100 [PercentType]

2019-11-07 17:22:31.431 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 85: Commands processed 1.

2019-11-07 17:22:31.439 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 85: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1bba84d.

==> /var/log/openhab2/events.log <==

2019-11-07 17:22:31.438 [vent.ItemStateChangedEvent] - TestBench_Dimmer changed from 0 to 100

==> /var/log/openhab2/openhab.log <==

2019-11-07 17:22:31.444 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0

2019-11-07 17:22:31.446 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0

2019-11-07 17:22:31.449 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2019-11-07 17:22:31.451 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2019-11-07 17:22:38.521 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1C 00 49 84 55 16 04 11 01 5E 26 85 59 55 86 72 5A 73 77 70 2B 2C 71 75 98 9F 6C 7A 40 

2019-11-07 17:22:38.535 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=85, callback=132, payload=84 55 16 04 11 01 5E 26 85 59 55 86 72 5A 73 77 70 2B 2C 71 75 98 9F 6C 7A 

2019-11-07 17:22:38.543 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 55 03 20 03 00 87 

2019-11-07 17:22:38.543 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=85, callback=132, payload=84 55 16 04 11 01 5E 26 85 59 55 86 72 5A 73 77 70 2B 2C 71 75 98 9F 6C 7A 

2019-11-07 17:22:38.545 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2019-11-07 17:22:38.548 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0

2019-11-07 17:22:38.550 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null

2019-11-07 17:22:38.550 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=85, callback=0, payload=00 55 03 20 03 00 

2019-11-07 17:22:38.556 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=85, callback=132, payload=84 55 16 04 11 01 5E 26 85 59 55 86 72 5A 73 77 70 2B 2C 71 75 98 9F 6C 7A 

2019-11-07 17:22:38.559 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 85: Application update request. Node information received. Transaction null

2019-11-07 17:22:38.561 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 85: resetResendCount initComplete=true isDead=false

2019-11-07 17:22:38.564 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 85: Application update - no transaction.

2019-11-07 17:22:38.568 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=85, callback=0, payload=00 55 03 20 03 00 

2019-11-07 17:22:38.570 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2019-11-07 17:22:38.573 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 85: Application Command Request (ALIVE:DONE)

2019-11-07 17:22:38.577 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 85: resetResendCount initComplete=true isDead=false

2019-11-07 17:22:38.580 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 85: Incoming command class COMMAND_CLASS_BASIC, endpoint 0

2019-11-07 17:22:38.583 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 85: SECURITY NOT required on COMMAND_CLASS_BASIC

2019-11-07 17:22:38.585 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 85: Received COMMAND_CLASS_BASIC V1 BASIC_REPORT

2019-11-07 17:22:38.588 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - NODE 85: Basic report, value = 0

2019-11-07 17:22:38.592 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 85: Got an event from Z-Wave network: ZWaveCommandClassValueEvent

2019-11-07 17:22:38.595 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 85: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_BASIC, value=0

2019-11-07 17:22:38.598 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 85: Updating channel state zwave:device:54aea7e5:node85:switch_dimmer to 0 [PercentType]

2019-11-07 17:22:38.603 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 85: Commands processed 1.

2019-11-07 17:22:38.606 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 85: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@9a83a0.

2019-11-07 17:22:38.609 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0

2019-11-07 17:22:38.611 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0

2019-11-07 17:22:38.614 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

==> /var/log/openhab2/events.log <==

2019-11-07 17:22:38.614 [vent.ItemStateChangedEvent] - TestBench_Dimmer changed from 100 to 0

==> /var/log/openhab2/openhab.log <==

2019-11-07 17:22:38.620 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.