Zigbee Bulbs update immediately to UNDEF, Items don't change from this

I wonder if anyone is having the same trouble as I am:

I recently reworked my openHAB setup, as part of it, I factory reset and updated the firmware of most of my Zigbee things (using their various hubs). I’m also now on the latest openHAB distribution (2.5.7). Since then, I cannot get my bulbs to correctly report item status. They respond to direct commands fine, but the item never updates.

This makes it impossible to toggle an item depending on its current state, e.g. a button press I use to toggle the same light on and off:

rule "Button One Trigger"
when
  Channel "zigbee:philips_rwl021:04000B8C:0017880103e4043b:buttonI" triggered
then
  if (FirstBedroom_MainLight_Switch.state == ON) {
    FirstBedroom_MainLight_Switch.sendCommand(OFF)
  } else {
    FirstBedroom_MainLight_Switch.sendCommand(ON)
  }
end
[Light Starts Off]
2020-08-18 13:25:27.117 [vent.ChannelTriggeredEvent] - zigbee:philips_rwl021:04000B8C:0017880103e4043b:buttonI triggered SHORT_PRESSED
2020-08-18 13:25:27.146 [ome.event.ItemCommandEvent] - Item 'FirstBedroom_MainLight_Switch' received command ON
[Light Turns On but state is UNDEF]
2020-08-18 13:25:29.429 [vent.ChannelTriggeredEvent] - zigbee:philips_rwl021:04000B8C:0017880103e4043b:buttonI triggered SHORT_PRESSED
2020-08-18 13:25:29.454 [ome.event.ItemCommandEvent] - Item 'FirstBedroom_MainLight_Switch' received command ON
[Light stays ON, regardless of number of button presses]

Here are the debug logs of the same exchange:

events.log (1.2 KB) openhab.log (108.8 KB)

Hope someone can provide some insight, it’s driving me mad! :slight_smile:

Bulb in example is a Phillips Hue, but this happens with IKEA Tradfri too and on bulbs I haven’t updated. My coordinator is a Telegesis.

Hi @chris, looks like this might be a “me” problem. Can you see anything funny going on in the logs?

See -

which sort of petered out.
It does describe a kludge, a temporary workaround of forcing autoupdate. That at least gives you the state reflecting most recent command, but not true state.

1 Like

If you’ve reset the device, then I guess it was rejoined to the network? IF so, the binding should have reset the reporting - all devices should support this - some old devices only have a small number of entries in the reporting table but that’s not normally an issue otherwise.

Unfortunately I can’t really see what’s happening in the log - I see some attribute reports (temperature) but I’d need to see the initialisation to see if this is being configured correctly.

With any modern device, this should not be an issue - everything ought to support reporting.

Thanks Chris,

Yes, I started on a new machine, but with the same USB co-ordinator, so added everything back via discovery after factory resetting each thing.

How do I force initialisation? Do I remove and re-add a thing, or will it happen when the binding starts?

It should do it on startup - the binding runs through the same checks to detect the channels and configure things - it may not do it all as some information is persisted between restarts (which makes me think of something else here…).

I suggest the following… Debug logging of course :slight_smile:

  • Restart the binding, give things a minute or so to settle
  • Send a command to turn a light on/off (just for good measure really)
  • Remove the thing (Are you using the latest binding - if not, please do)
  • Stop the system (or at least ZigBee)
  • Look in the userdata/zigbee folder to make sure the XML file for the device is removed
  • Restart the binding
  • Give it a minute or so an send a command or two
  • Send me the logs :slight_smile:

The first part of the test is to allow me to check a few things - the second part might not be needed, but it’s probably easier to just run through this and send over the logs…

1 Like

Excellent, thanks Chris. I’ll do that as soon as I can. Just to make sure, when you say latest binding, you mean the snapshot and not the stable version right?

Correct - yes, I mean the snapshot (thanks for clarifying - I should have been clearer).

I think I’ve gone through quite some of the steps you described and created the requested logs in debug mode already. You may find them here:

Maybe it helps avoid double-work.

Are these issues the same?

Here, you say -:

However I understood the issue here is different

I understood this to mean that it doesn’t update the state if it’s commanded directly - ie via switch or other system.

Maybe I’ve misinterpreted the question? IF so, then my answer is also not relevant as I was assuming the issue is relating to reporting of device states

I had a look at that topic and it looks like both. If I toggle a light ON in a sitemap the physical light turns on but the state remains UNDEF. This is the same as if something else changes its state, e.g. a switch. If I send a REFRESH command to the thing, nothing happens and the Items linked to the Thing remains UNDEF

This only seems to be happening with bulbs, regardless of manufacturer. The battery voltage in my remotes are updating and my IKEA Fytur blinds are reporting instantly, regardless of how their states are changed.

2020-08-20 14:36:30.650 [vent.ItemStateChangedEvent] - SecondBedroom_Blinds_Position changed from 0 to 1
2020-08-20 14:36:31.692 [vent.ItemStateChangedEvent] - SecondBedroom_Blinds_Position changed from 1 to 10
2020-08-20 14:36:32.717 [vent.ItemStateChangedEvent] - SecondBedroom_Blinds_Position changed from 10 to 18
2020-08-20 14:36:33.754 [vent.ItemStateChangedEvent] - SecondBedroom_Blinds_Position changed from 18 to 27
2020-08-20 14:36:34.786 [vent.ItemStateChangedEvent] - SecondBedroom_Blinds_Position changed from 27 to 35
2020-08-20 14:36:35.821 [vent.ItemStateChangedEvent] - SecondBedroom_Blinds_Position changed from 35 to 44
2020-08-20 14:36:36.848 [vent.ItemStateChangedEvent] - SecondBedroom_Blinds_Position changed from 44 to 52
2020-08-20 14:36:37.878 [vent.ItemStateChangedEvent] - SecondBedroom_Blinds_Position changed from 52 to 61
2020-08-20 14:36:38.917 [vent.ItemStateChangedEvent] - SecondBedroom_Blinds_Position changed from 61 to 69
2020-08-20 14:36:39.952 [vent.ItemStateChangedEvent] - SecondBedroom_Blinds_Position changed from 69 to 78
2020-08-20 14:36:40.988 [vent.ItemStateChangedEvent] - SecondBedroom_Blinds_Position changed from 78 to 86
2020-08-20 14:36:42.021 [vent.ItemStateChangedEvent] - SecondBedroom_Blinds_Position changed from 86 to 95
2020-08-20 14:36:43.051 [vent.ItemStateChangedEvent] - SecondBedroom_Blinds_Position changed from 95 to 100

@Benjy, maybe you can have look at the last post in the mentioned thread (Items receive commands but stopped to update their states) and check if you experience similar behaviour when trying to trigger a thing initialization. This would be an indicator that there may be a connection?

Ok, so the bulb should report back its state. When the command comes in from the UI, the UI doesn’t get updated at that point - we expect the device to send a report to say that it has changed state. This should normally come in within a second, and then the UI should be updated.

@chris, it doesn’t matter how long I wait, there’s no returned updated state unfortunately, it remains UNDEF.

Interesting, @guy-inkognito is correct. I found a single bulb that’s working as expected. Checking the initialise switch works fine on that. For every other bulb it is not working:

2020-08-20 14:54:37.582 [ERROR] [converter.ZigBeeConverterSwitchLevel] - 00178801102B5321: Error opening device level controls
2020-08-20 14:54:37.584 [INFO ] [ng.zigbee.handler.ZigBeeThingHandler] - 00178801102B5321: Channel zigbee:device:04000B8C:00178801102b5321:00178801102B5321_11_dimmer failed to initialise device

Debug logs for initialisation of a single broken Thing: (still on latest stable)
openhab.log (23.5 KB)

@chris, is it still worth recording everything in the step-by-step you posted?

That’s understood - I was just trying to give an overview how how it is meant to work.

The problem we fight against here is getting a system that works for everyone under all conditions. We made the change to veto recently to solve a problem with another set of users because the other problem here is when devices DO respond how I said, and that can cause other difficulties…

Eg… If we have blinds - you start from 0%, send the command via the UI to go to 100%, and what the user will see is 0, 100, 10, 20 … 100. That upsets people, and it’s caused by the state being set by the command (ie the first 100 in this sequence). If we remove that, and devices do not report, then we get nothing - this is the situation that you have. So we add this back, and we just change to upsetting a different group of users…

You could change the autoupdatepolicy to recommend to see if that fixes it.

Ideally, the binding would change this for each channel, depending on what happens - or it could do some “magic” and set the state “some period” after sending the command - if the command was ack’d, and if no report was received. These sort of things would be a better and more dynamic (by which I mean better able to cope with different situations). But it also takes more work to think this through and implement :frowning: .

Thanks for your feedback, @chris!

However, after my testing as described in the other thread, I came to the conclusion that most likely the issue is not caused by the autoupdate policy but rather by something going wrong with the device initialization.

State update works as expected for devices that do not show the initialization error @Benjy just described, at least for me. Maybe @Benjy: Does the device that seems to initialize correctly also correctly change its state on your environment?

Well, yes, that error means that the reporting is not configured, so yes, resolving that would hopefully fix it, but that doesn’t change what I said about the way that the auto update policy works.

For what it’s worth, I don’t think it is bad to have channel autoupdate policy to “veto”. This causes no errors, only highlights a deficiency in device reporting.

The user can always set the Items autoupdate to true (force) and override the veto. That’s a kludge to partially circumvent the device reporting deficiency. It’s not “the answer”, just as removing channel veto is not the answer.

The root problem is the device failure to report.

Personally, I tink the autoupdate mechanism as it is at the moment is really good. It solves the “slider jump” thing and actually represents the “device truth”. For my personal feeling that’s how it should be. And in case you need another behavior you’re always free to change the autoupdate mechanism by e.g. setting it to an explicit true.

Yes, it’s a bit difficult to understand in the first place, but hey … :wink:

Do you have any impulse on how to “repair” the device initialization though?

Please can you enable trace logging on the above class (org.openhab.binding.zigbee.internal.converter.ZigBeeConverterSwitchLevel).

The error logged here is actually not printing the correct text - I’ll update that, but I’d like to see trace output when this happens.