[SOLVED] Items receive commands but stopped to update their states

Tags: #<Tag:0x00007f6172d8ae20>

Hi everybody,

I’m using the latest version of OH (2.5.5-1) + Zigbee binding and recently experienced a very strange behaviour. (I’m not exactly sure when it startet unfortunately.)

When sending a command to an item, e.g. by using a sitemap switch or a rule, the item receives the command and executes (e.g. light turns on). However, the item state doesn’t get updated.

What I’d expect:

2020-05-29 15:02:08.189 [ome.event.ItemCommandEvent] - Item 'Licht_AZ_Schreibtischlampe' received command ON

2020-05-29 15:02:08.230 [vent.ItemStateChangedEvent] - Licht_AZ_Schreibtischlampe changed from 0 to 100

2020-05-29 15:02:08.233 [GroupItemStateChangedEvent] - gLicht_AZ changed from OFF to ON through Licht_AZ_Schreibtischlampe

2020-05-29 15:02:08.238 [GroupItemStateChangedEvent] - gLicht changed from OFF to ON through gLicht_AZ

What happens:

2020-05-29 14:47:47.792 [ome.event.ItemCommandEvent] - Item 'Licht_AZ_Schreibtischlampe' received command ON

So, the actual behavior is exactly like what you achieve by using autoupdate=“false”. Indeed, if you add autoupdate=“true” to the item, it behaves as expected and starts updating it’s state again.

I’ve already cleared every configuration including items, rules etc. down to having just one simple item like this:

Dimmer Licht_AZ_Schreibtischlampe {channel="zigbee:device:***:***_11_dimmer"}

Still the same. So no conflict with rules or something like this. Even more interesting is that this only applies to most, but not all, items. Some behave as expected.

I’ve also tried the usual fixing approaches by clearing cache and restarting already with no success.

Any ideas? I’m getting crazy :smiley:

Thanks for any help and best!

It’s non obvious, but bindings are allowed to veto the default autoupdate actions. For example, if a binding knows a target device is “broken”, then it can prevent autoupdate from assigning a “false” state to a commanded Item.
I don’t think there is any logged indication of that happening, normally.

Whether and when this binding implements that, I could not say.

However, you should also consider - while you usually see the Item state update from a command resulting from autoupdate first, it is only a guess. Within a short time, you would normally expect a “real” update back from a commanded device. Don’t normally see that in the logs, when autoupdate works this will be a non-logged update-to-same-state.

So, for you - if autoupdate is not giving a state change - where is your “real” update from the device, that you would expect withiin a second or so?

I have no fix for you, but I think your zigbee is broke in some way.

Thanks @rossko57 for the info! I didn’t know that, pretty interesting and helpful to understand.

I’m using the Zigbee binding and see the issues there. These devices, as I understand it, do not have a backchannel thus are not able to communicate their states or acknowledge state changes. Therefore I’m dependant on the default autoupdate to work properly. As I said, I’m able to “fix” the issue by adding an autoupdate=true on every item, or “manually” update the state by a generic rule. However, I’m interesting in figuring out what caused the default autoupdate to stop working. So I’m thankful for any idea where to deeper look at in the binding mechanics.

Or is there any way to reset or re-install the binding without losing all the things (because I have a lot of them and it’d be unfortunate to re-learn all of them).

It by the way works pretty well with some EnOcean devices I have which actively send their states back after a short time (why I’m actually by intent use autoupdate=false for these devices).

Does the light turn on?

Do you mean in general or for your specific devices? There is a poll interval that can be configured at the Channel level, at least for my devices. I do see the same behavior at times with some bulbs that drop from the network, but usually a power cycle corrects it. Sometimes a reset is needed.

Can you advise how the binding does this? As far as I know this isn’t possible - the binding just sets the state - that’s all.

The channel description does have a setting for the recommended value of autoupdate - but I don’t think that this overrides the user setting. I could be wrong, but my understand was that the channel configuration was the recommendation unless the user set something different.

If the binding has the ability to affect this I’d certainly be interested to know though.

Yes, the device is turning on.

Interestingly, all Zigbee devices except for stopped to update their states. One single item is working as expected.

This is info I gleaned from here

Techie detail way over my head, As I read it, a binding can set a channel AutoUpdatePolicy to request autoupdate’s treatment of an associated Item in three ways
Yes please (recommend)
No thanks (veto)
If you like (default, I guess the most common case)

The words suggest a binding author might Veto when confident we’re going to get a timely, accurate “real” state update response to command…
Or set Recommend when we know there’ll be no response, a write-only device.

The words further suggest a broken or non-existent channel will act like a Veto, “this cannot work”. I’d say that’s unexpected for most users. It’s not clear to me if a binding might make that happen e.g. if a Thing is offline, and if that is automatic by framework or requires binding action.

I wonder if this veto-with-broken channel might popup unexpectedly, say a user configures an Item from xxx.file with a valid channel, but the Item also has an old PaperUI link to a invalid channel. Could be OP’s case.

A puzzle from above thread is why behaviour seems different with a positive autoupdate="true" Item setting. Should be the same as not specifying?

Thanks. So I think that is the same thing that I was talking about - the channel description can set this, but not really the binding changing this based on a commanded state.

When the binding receives a command, it does nothing to the state. When it does an update of the state, it can only set the state.

We recently changed this setting on some channels in ZigBee as the default was causing problems since the UI updates data, and then the binding updates data - this causes values to flick back and forward in most cases (I hope that makes sense :slight_smile: ).

Yes I understand the problem, seen with ramping dimmers etc.

UI? You mean, autoupdate acting in its usual default way in response to command from UI (or rule)

Does that mean some Zigbee channels do indeed have Veto policy set? (With the implication that the end device must then be configured to send timely updates)

I’m not 100% sure if it’s autoupdate, or just the UI, but the issue is the user clicks a dimmer to (say) 70% when it’s currently 0%. The dimmer then shows 70% in the UI even without autoupdate. Autoupdate may also set it to 70%, but then for some devices that send multiple reports, you may get a reading of 20%, then 60%, then 70%… So the user sees 0, 70, 20, 60, 70…

Yes, we were trying to get rid of exactly this issue since the ZigBee binding will configure devices to report their state and it was causing problems not having this set. Maybe I need to look at adding more intelligence into the binding to try and work out dynamically how to set this when it’s creating the channel definitions…

Okay. The OP seems to have the issue that his particular Zigbee config/devices are not reporting new status, plus, were by default “vetoing” autoupdate. That might be configuration error, I have now realized, or might be unwanted side effect of your change. Change seems more likely as effect noticed after update.

Not to say that I do not think there is something wrong with OPs config, by not reporting status. I’m just not sure if consequent suppression of autoupdate was intended in this fault situation.

Needs a bit more unpicking here really.

Thanks all for the interesting discussion and the details!

Sounds quite reasonable to me that this could be the reason. I’ve did some more testing with some unused devices:

  • Bitron wall plug dimmers + Osram wall plug switches [working]
  • Bulbs from Philips & Innr + Paulmann dimmers [not working]

Thus, as this is consistent within device manufacturers, it could probably be that the latter ones are not correctly reporting back their states?

As using an explicit autoupdate=true in the channel configurations make it work again, I’d assume this again overrides the update logic and triggers correct behaviour.

I do have a background in software development a couple of years ago but no deep knowledge of the OH software itself. So if you point me into the right direction I’m happy to - as far as possible for me - further assist with any investigation if required.

Thanks!

I would say so. I thought the Zigbee binding actively polled for status, but I do not know and that’s where my knowledge ends.

The ZigBee binding tries hard to avoid polling - polling is generally not a good thing as it needlessly consumes bandwidth. Both ZigBee and ZWave support systems for reporting change, and that’s what we try and use.

Of course some devices don’t support that, and then the binding will fall back to polling, but polling is relatively slow.

In general, most devices really should support reporting. If reporting configuration fails, then the binding will poll, but this is a much slower update than reporting.

Fair enough, I should RTFM


What should @guy-inkognito look at with respect to his ‘naughty’ devices? Are there device settings that could be checked, maybe with a tool?

Is there a means to see if the binding has, or should, fall back on to polling? A way to force poling if necessary? This suggests not

I’m further guessing a binding trace log may not be that helpful here … but should reveal operating uh mode?

Really I’d need to look at the detailed logs to see what is happening. The binding tries to select this sort of thing automatically - if reporting configuration works, then the binding will use reporting - if it doesn’t, it uses polling. This is automatic.

What I haven’t done is to adjust the auto update parameter during channel creation (as mentioned earlier). I could look at doing this automatically as well, but I’d need to find some time to work out how to detect this at the point that channels are being created.

I’m trying to work this sort of thing automatically as I don’t want to review logs every time some device does something differently (I’d spend my life looking at logs :slight_smile: ). The whole concept of the binding is to be dynamic and avoid the issue we see with the ZWave binding (which was written before dynamic channels were available in ESH) where we have to maintain a database. Self discovery of the device features is (IMHO) my best hope at keeping the support levels low :wink:

@guy-inkognito if you want to provide debug logs (as per the binding docs) showing the device initialisation phase, I will have a look to see what I can see.

I also need to know exactly what “not working” means - ie exactly what the conditions are that are being tested so there’s no confusion. I’m not trying to be difficult here, but I do want to be clear as to the exact test that is being done, and then get the relevant logs so I can tie up what is in the logs with what is physically happening.

Thanks.

2 Likes

I’ll put together a test scenario and provide the debug logs.

One additional question to be sure it’s useful: How can I correctly trigger the device initialization phase? Is it sufficient to power off and on the device? Or do I need to remove the thing and re-learn it to the binding? Or shall I use the initialize switch in the thing configuration UI?

In the meantime, here’s what “not working” means from my point of view. To make it clear I’d execute the following scenario while creating logs:

  • Remove all items except for one “working” and one “not working” with a very simple channel configuration like so:
Dimmer TestItem_Working {channel="zigbee:device:***:***_11_dimmer"}
Dimmer TestItem_NotWorking {channel="zigbee:device:***:***_11_dimmer"}
  • [Initialize both devices - see question above how to do so]
  • Trigger an item update via PaperUI Control for both
    ** Expectation: Both items receive the command. Item state of both gets updated to the value set via the UI within a couple of seconds
    ** What will probably happen: Both items receive the command. Item state of the “working” item gets updated within a couple of seconds. Item state of the “not working” item does not get updated
  • Wait half an hour or so until the “not working” device gets updated by polling mechanism (by looking into the logs a bit more detailed by myself (thanks @chris for the awesome log analyzer you have on your website!) I discovered that the state finally gets updated after like 20 minutes or so which perfectly fits the polling mechanics you described above)

Would you consider this sufficent or shall I change/add something on the scenario?

And no worries about being difficult of course - I’ve debugged enough software myself to know what it means. I’m very thankful for the support of all of you :slight_smile:

1 Like

Hello,

so here we go:

  • Defined items as written above
  • Set log level as in Zigbee binding doc
  • Stopped OH service
  • Cleaned cache
  • Rebooted: Logs start with reboot
  • Waited a while
  • Set TestItem_Working to 67 (14:06)
  • Set TestItem_NotWorking to 31 (14:07)

Behaviour was like described in my previous post.

Hope it helps! Thanks and have an nice weekend!


In case there’s something more I can provide or look at on my own, I’m happy to do so if you provide me with some guidance. Otherwise I’m looking forward to any insight from the logs hopefully.

Thx and cheers!

I think you may have needed to tag or reply to @chris for his further attention, he gets drawn into lots of stuff :wink:

1 Like