Dimmers do not report levels

Setup, Configuration and Use Runtime
, ,
1

I have a zwave setup using alexa and siri integration.

When using the Paper UI and monitoring the dimmers, they only seem to report Off/100% changes if I turn them on and off (the dimmers turn back on at their previous on setting, as I am sure you are all aware).

What they should be doing is reporting the dimmer level the lights are currently set to.

For example:
Alexa, set lights 60% (lights dim to 60%, openhab reports them at 60%) - correct
Alexa, turn lights off (lights turn off, openhab reports them at 0%) - correct
Alexa, turn lights on (lights turn on at 60%, openhab reports them at 100%, forever) - incorrect

The same with the openhab app on iOS, reports 100% level.
The same with the home app on iOS, reports 100% level.

So this, I would assume is an openhab issue.

My question is, will this always be the case using openhab? Having used other software previously I am very surprised openhab behaves in this way, every other software solution I have tried actually polls the devices to see what they are set to, especially after turning them on, this seems to be ‘automation 101’ in my opinion.

Something for the developers to think about.

(PS. In the time it have taken to write this, the lights are still showing 100%, in the UI, and both mobile apps.)

2

You could think about spending some money on that:

3

Wasn’t really asking for a feature request, the reason I say this is because I feel this functionality has been ‘overlooked’ and should be have been included in the very first ever release of this software.

At the moment there is a ‘set it and forget it’ and ‘receive it and report it’ control mechanism in place, there is nothing inherently wrong with this approach if all devices never remembered their own states.

Asking a device to report it’s status when a generic ON command is sent to a device that has a MULTI_LEVEL capability adds an overhead to the network of approx 10 bytes, so not really a big deal to implement, IMHO.

4

Sorry, was just mad this morning about that new “BountySource” stuff …

5

This is the case now. I don’t know what devices you have, but maybe there’s a configuration issue somewhere?

6

Not so. Look at my original scenario.

Turn a dimmer ON (not 100%), dimmer turns on at whatever level it was the last time it was set.

Openhab reports it as 100%.

Openhab never updates the level.

In other software I have used, the levels may also report 100%, but those levels update within a second or two to report the correct level, if this is, as you mention, the case now it would appear I have incorrect configuration.

The dimmers I have (2 of them) are TBK TZ67 Wall Plug Dimmers. Neither of them report levels after a generic ON command. It is also worth mentioning that these are also ‘Child-Lockable’ although I may need to implement that myself using parameters.

It’s not really a big deal. I just assumed I would be able to look at any of my interfaces and see what the levels were set to, which at the moment I cannot (unless I set the level with openhab running, or restart openhab with the lights on).

7

** UPDATE **

Seems I was a little over zealous in saying the dimmers never update in the UI.

They do, during their polling, which on my devices would be every 30 minutes.

Of course, it you turn on a dimmer 30 seconds before any polling is due, it would indeed appear that it is refreshing.

The smallest value I can set for polling is 10 Minutes, so I guess I am stuck with 10 minutes before I can accurately tell what the levels are.

I did try to make a rule to trigger when the ‘state changes’ from ‘OFF’ to ‘ON’ and send a ‘REPORT’ command to the device, this seemed to work the first time, but it happened to coincide with the poll. Maybe someone can tell me what command to implement via the rule engine so the device reports its status, this would be a temporary workaround (if it works) to the issue, although I am still convinced this is an engine core issue.

8

If you believe it to be an issue (and based on the description I would tend to agree) I recommend:

  1. Gathering debug level logs of the zwave binding and posting them here to see the network traffic back and forth between the zwave binding and the nodes.

  2. Work with chris who is the main zwave binding developer to identify what is going on based on these logs.

  3. File an issue on github.

When chris says “that is the case now and there may be a configuration issue somewhere” he means it. He didn’t misunderstand your question. There is so much that goes into making zwave work that something slightly off in the database entry for those particular model dimmers could be throwing things off. Based on reports, it is also not uncommon for device manufacturers to have errors in their implementation of the zwave spec. Or there can be behavioral or architectural differences between OH and these other software packages you have used that hides a flaw in the device that OH fails to compensate for.

Also realize that openHAB is not “other software”, particularly commercial software. It was initially developed (until quite recently) through reverse engineering the zwave protocol. It is almost entirely developed through volunteers who contribute their time and effort to building OH.

9

You can set the polling interval in seconds by just writing it into the input field (assuming you use habmin).

10

Hm, can you try a REFRESH command? I think I read that, when sending wrong commands to a dimmer some day (try send myDimmerItem bingbong in the Karaf shell)

11

Oooh, exciting stuff.

REFRESH works like a charm, but only if I execute the rule manually.

Will have to play around with the rule trigger a little, but things are looking up.

Is there a way to determine if a rule is being fired based on a state change? (before you say ‘check the logs’ I have tried looking for logs, and I cant find any, where are they located?)

Thanks again.

12

** UPDATE **

For people wishing to have current levels of dimmers (assuming they didn’t before, maybe it is just me). This is just a workaround, however, and will increase your network traffic as it has to refresh the level until the level stops changing. If like me your dimmers fade out and in, you will actually see the sliders move up and down as each level is reported, not entirely sure how many levels actually get reported, but for a full off to a full on that will be potentially be 100 level reports.

Install the experimental rule engine, restart openhab (it didnt show until I restarted).

  • Create a new rule, call it whatever you want.
  • Click the plus next to ‘When’
  • In the rule type (step 1) select ‘an item state changes’
  • In the next screen (step 2) select your device from the item menu.
  • Leave the other fields blank (presumably this means trigger for ‘anything’), when I tried different combinations here I got nothing at all.
  • Click the plus next to ‘then’
  • In the action type (step 1) select ‘send a command’
  • In the next screen (step 2) select the same device from your item menu.
  • In the command section manually type in REFRESH.
  • Click OK to save the rule
  • Click the ‘Tick’ to save the rules

If anyone has a better, less network hungry method of performing the same functionality, please let me know.

Thanks everyone for your patience, and a special thanks for the refresh tip.

13

Well, I respectfully disagree! Dimmers, switches, etc are all updated fine. If you have a specific issue, then we need to look at that, but the functionality is definately there!

Maybe this is the way the device reports - I don’t know. You need to provide logs or something so we can really see what is happening.

No - the smallest value you can set for polling is 10 seconds if I remember correctly (or maybe 15 seconds). I don’t generally recommend this, but if you have a device that has issues, then it can be used this fast.

14

OK, then may I respectfully ask:

  • a) how to turn logging on
  • b) where to find the log file
  • c) what would you like me to log in total

I have disabled my rule as my left dimmer plug refused to turn off, lol, it would set it’s levels but not accept an OFF command, maybe I fried it asking for 5 million status updates. I unplugged it and plugged it back in and it is behaving again, might just be a coincidence.

More than happy to provide any logs you want.

15

The the command log:set DEBUG org.openhab.binding.zwave

See http://docs.openhab.org/administration/logging.html

They are in the userdata/logs folder. (note that userdata may be mapped to some other location depending on your installation).

The response from the device showing what it returns when you change the setting.

16

Like this?

2017-08-08 08:32:17.363 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Command received zwave:device:9003ca52:node3:switch_dimmer --> ON
2017-08-08 08:32:17.364 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 3: Creating new message for command SWITCH_MULTILEVEL_SET
2017-08-08 08:32:17.365 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2017-08-08 08:32:17.365 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2017-08-08 08:32:17.367 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 03 03 26 01 FF 25 67 7C 
2017-08-08 08:32:17.367 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 0A 00 13 03 03 26 01 FF 25 67 7C 
2017-08-08 08:32:17.376 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2017-08-08 08:32:17.376 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-08-08 08:32:17.377 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
2017-08-08 08:32:17.377 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
2017-08-08 08:32:17.378 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
2017-08-08 08:32:17.378 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: Sent Data successfully placed on stack.
2017-08-08 08:32:17.389 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 67 00 8E 
2017-08-08 08:32:17.390 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-08-08 08:32:17.390 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 13 67 00 00 00 8C 
2017-08-08 08:32:17.390 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 13 67 00 00 00 8C 
2017-08-08 08:32:17.391 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=67 00 
2017-08-08 08:32:17.391 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 103, Status = Transmission complete and ACK received(0)
2017-08-08 08:32:17.391 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Starting initialisation from DONE
2017-08-08 08:32:17.392 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@ef5da9 already registered
2017-08-08 08:32:17.392 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=3, callback=103, payload=03 03 26 01 FF 
2017-08-08 08:32:17.392 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=67 00 
2017-08-08 08:32:17.393 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=103, expected=SendData, cancelled=false        transaction complete!
2017-08-08 08:32:17.393 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-08-08 08:32:17.393 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-08-08 08:32:17.394 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 3: Response processed after 26ms/185ms.
2017-08-08 08:32:17.483 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Command received zwave:device:9003ca52:node2:switch_dimmer --> ON
2017-08-08 08:32:17.483 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 2: Creating new message for command SWITCH_MULTILEVEL_SET
2017-08-08 08:32:17.484 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2017-08-08 08:32:17.484 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2017-08-08 08:32:17.486 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 02 03 26 01 FF 25 68 72 
2017-08-08 08:32:17.487 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0A 00 13 02 03 26 01 FF 25 68 72 
2017-08-08 08:32:17.494 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2017-08-08 08:32:17.495 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-08-08 08:32:17.495 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
2017-08-08 08:32:17.496 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
2017-08-08 08:32:17.496 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01 
2017-08-08 08:32:17.496 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: Sent Data successfully placed on stack.
2017-08-08 08:32:17.507 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 68 00 81 
2017-08-08 08:32:17.508 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2017-08-08 08:32:17.508 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 13 68 00 00 00 83 
2017-08-08 08:32:17.509 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 13 68 00 00 00 83 
2017-08-08 08:32:17.509 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=68 00 
2017-08-08 08:32:17.509 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 104, Status = Transmission complete and ACK received(0)
2017-08-08 08:32:17.509 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Starting initialisation from DONE
2017-08-08 08:32:17.510 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@6c2056 already registered
2017-08-08 08:32:17.510 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Set, dest=2, callback=104, payload=02 03 26 01 FF 
2017-08-08 08:32:17.510 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=68 00 
2017-08-08 08:32:17.511 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=104, expected=SendData, cancelled=false        transaction complete!
2017-08-08 08:32:17.511 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-08-08 08:32:17.511 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-08-08 08:32:17.511 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Response processed after 24ms/185ms.
17

This is what I am talking about, look at the times, it only updates during the 30 minute polling.

2017-08-08 08:32:17.361 [ItemCommandEvent          ] - Item 'Right_Lamp' received command ON
2017-08-08 08:32:17.367 [ItemStateChangedEvent     ] - Right_Lamp changed from 0 to 100
2017-08-08 08:32:17.482 [ItemCommandEvent          ] - Item 'Left_Lamp' received command ON
2017-08-08 08:32:17.484 [ItemStateChangedEvent     ] - Left_Lamp changed from 0 to 100
2017-08-08 08:38:56.383 [ItemStateChangedEvent     ] - Left_Lamp changed from 100 to 50
2017-08-08 08:48:20.845 [ItemStateChangedEvent     ] - Right_Lamp changed from 100 to 50

Thia was taken from the events log.

18

So the log shows that you turned on the device, and I guess it’s only coming on at 50%. Since there is no poll until later, this is only picked up at the later time.

I used to do a poll after doing a SET, but this was causing problems with some devices so it was removed. This is the joy of having to deal with hundreds of devices from hundreds of manufacturers :frowning: . I’ll see if this can be improved.

1 Like
19

Well, that is what I originally suggested, but a poll after a set would only show the current level of the dimmer, these dimmers have a fade in/out so any instant poll after power on would show whatever level it had reached at that time, in my tests 2% was reported.

If it were me, I would have any multilevel devices polled in 500ms durations until the device level stopped changing, this would reduce traffic and ultimately solve the problem (at least for me). This might be more code injection or program flow disruption than is comfortable, especially considering you would have to store the ‘last level reported’ somewhere in its class or structure or however it is you track nodes.

In any case, thank you for investigating.

20

I really think the dimmer should push its state after a change happened. Isn’t there any association group for the thing to report to? My fibaro first generation eyes (FGMS001) only answers to polls, if I forget to put openhab into the association groups. If they are associated, reports on changes work fine. Maybe that’s something you can look into as well, psych