Polling not working with Tradfri E27 bulb

[weakfl]

Polling not working with Tradfri E27 bulb

[cdjackson]

2022-10-03 07:40:21.682 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - D85DEF11A1001973: Polling 3 channels...
2022-10-03 07:40:21.685 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - D85DEF11A1001973: Not polling zigbee:device:c3cd543626:d85def11a1001973:D85DEF11A1001973_11_dimmer - unlinked
2022-10-03 07:40:21.688 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - D85DEF11A1001973: Polling zigbee:device:c3cd543626:d85def11a1001973:D85DEF11A1001973_10_dimmer
2022-10-03 07:40:21.691 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - D85DEF11A1001973: Not polling zigbee:device:c3cd543626:d85def11a1001973:D85DEF11A1001973_18_dimmer - unlinked
2022-10-03 07:40:21.939 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000B57FFFEB1BAB5: Polling 2 channels...
2022-10-03 07:40:21.943 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000B57FFFEB1BAB5: Not polling zigbee:device:c3cd543626:000b57fffeb1bab5:000B57FFFEB1BAB5_1_dimmer - unlinked
2022-10-03 07:40:21.946 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000B57FFFEB1BAB5: Not polling zigbee:device:c3cd543626:000b57fffeb1bab5:000B57FFFEB1BAB5_1_colortemperature - unlinked

So this confirms what I thought - that the core seems to be reporting that these channels are not linked. I checked that up until my change today, there was no change to this code in the binding for 1.5 years when there were some changes to the way the core managed the link reporting. It's possible that at this time something else changed and I think there's an error there so I'll make another change in a few minutes and we can see if that solves the issue.

[cdjackson]

I have a Tradfri E27 dimmable light bulb that no longer answers to polling requests (it has worked fine in the past).

What exactly do you mean by this? You provide above a read command (which is a poll) and it is responding. Can you describe what the problem is - is the device going OFFLINE or something?

There are certainly polls working just fine in this log -:

Polling is not normally used by the binding.

UNSIGNED_64_BIT_INTEGER

This is currently not supported and it never has been so this hasn't changed. I will take a look at adding this, but since it's not used by the binding it's not really going to make much difference.

---

So, polling works - what is the actual problem that you as a user are seeing? ie forget about the low level zigbee commands - what's the high level issue?

[weakfl]

@cdjackson yes, that's at the beginning of the log when I changed the polling interval to 70s and back to 60s. As stated this seems to be working fine.
Subsequent polling attempts just time out and the device goes offline.

Please take a look at the log from 2022-10-01 09:33:23.668 onwards:

• 2022-10-01 09:33:23.668 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000B57FFFEB1BAB5: Polling [zigbee:device:c3cd543626:000b57fffeb1bab5:000B57FFFEB1BAB5_1_dimmer, zigbee:device:c3cd543626:000b57fffeb1bab5:000B57FFFEB1BAB5_1_colortemperature] channels...
• 2022-10-01 09:34:25.144 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000B57FFFEB1BAB5: Polling [zigbee:device:c3cd543626:000b57fffeb1bab5:000B57FFFEB1BAB5_1_dimmer, zigbee:device:c3cd543626:000b57fffeb1bab5:000B57FFFEB1BAB5_1_colortemperature] channels...
• 2022-10-01 09:34:54.590 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000B57FFFEB1BAB5: Polling stopped
• 2022-10-01 09:34:54.595 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000B57FFFEB1BAB5: Polling initialised at 61557ms
• 2022-10-01 09:35:24.599 [DEBUG] [.zigbee.handler.ZigBeeIsAliveTracker] - IsAlive Tracker Timeout has been reached for thingUID=zigbee:device:c3cd543626:000b57fffeb1bab5
• 2022-10-01 09:35:39.498 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000B57FFFEB1BAB5: Polling [zigbee:device:c3cd543626:000b57fffeb1bab5:000B57FFFEB1BAB5_1_dimmer, zigbee:device:c3cd543626:000b57fffeb1bab5:000B57FFFEB1BAB5_1_colortemperature] channels...
• 2022-10-01 09:36:41.061 [DEBUG] [ng.zigbee.handler.ZigBeeThingHandler] - 000B57FFFEB1BAB5: Polling [zigbee:device:c3cd543626:000b57fffeb1bab5:000B57FFFEB1BAB5_1_dimmer, zigbee:device:c3cd543626:000b57fffeb1bab5:000B57FFFEB1BAB5_1_colortemperature] channels...

I can't see any response to the polling requests. Or am I missing something?

[cdjackson]

The only thing check that is done after this message is to see if the channel is linked. I can only guess at the moment that this returns false since there from what I can tell is no poll being sent - so you don't receive the response as nothing gets sent.

[weakfl]

The only thing check that is done after this message is to see if the channel is linked. I can only guess at the moment that this returns false since there from what I can tell is no poll being sent

Are you referring to the bindtable @cdjackson ?

It was:

openhab> zigbee bindtable 32147
Binding table for node 32147 [000B57FFFEB1BAB5]
Src Address          | Dest Address         | Group | Mode    | Cluster
000B57FFFEB1BAB5/1   | 0022A300002921FD/1   |       | Address | 0006:ON_OFF

I've changed it to:

openhab> zigbee bindtable 32147
Binding table for node 32147 [000B57FFFEB1BAB5]
Src Address          | Dest Address         | Group | Mode    | Cluster
000B57FFFEB1BAB5/1   | 0022A300002921FD/1   |       | Address | 0006:ON_OFF
000B57FFFEB1BAB5/1   | 0022A300002921FD/1   |       | Address | 0008:LEVEL_CONTROL
000B57FFFEB1BAB5/1   | 0022A300002921FD/1   |       | Address | 0300:COLOR_CONTROL

Polling still doesn't work though. I'll try to reset the device next.

---

Another question:

Is the Level Control (0008) cluster supposed to report the last level even when the On/Off (0006) cluster is off?

openhab> zigbee read 37485/18 0006 0                                                                                                                                                                                                                                     
Reading endpoint 926D/18, cluster server cluster On/Off (0006), attributes On Off
Response for cluster 0x0006
Attribute    0  On Off                                              BOOLEAN                         false

openhab> zigbee read 37485/18 0008 0                                                                                                                                                                                                                                     
Reading endpoint 926D/18, cluster server cluster Level Control (0008), attributes Current Level
Response for cluster 0x0008
Attribute    0  Current Level                                       UNSIGNED_8_BIT_INTEGER          239

The UI state in openHAB isn't updated correctly even if the device is turned off. Imho this should report 0 if 0x0006 is off. Since the channels are consolidated there's currently no way to update the UI state.

EDIT:

This seem to be the case already. Don't know why it didn't work previously...

[weakfl]

@cdjackson to me it looks like polling is generally broken.

I have two more devices for which I have set polling to 60s and they're showing the same behaviour. Not answering to polling and going offline.

As soon as I execute a read command from console the device is shown as online and status is updated in the openHAB UI.

[cdjackson]

Are you referring to the bindtable @cdjackson ?

No - I mean that a channel is linked to an item. Nothing to do with zigbee - this is the openhab linking. It seems that this check is probably failing, so the binding doesn't poll if a channel is not linked to an item.

I can add some more debugging around this area to see what is happening.

[cdjackson]

Please provide updated logs with the new binding.

[weakfl]

No - I mean that a channel is linked to an item. Nothing to do with zigbee - this is the openhab linking. It seems that this check is probably failing, so the binding doesn't poll if a channel is not linked to an item.

They should be linked. I can also control the devices just fine, even if they're shown as offline.

Devices as shown in openHAB UI:

But still (compare with last screenshot):

000B57FFFEB1BAB5: Polling 2 channels...
000B57FFFEB1BAB5: Not polling zigbee:device:c3cd543626:000b57fffeb1bab5:000B57FFFEB1BAB5_1_dimmer - unlinked
000B57FFFEB1BAB5: Not polling zigbee:device:c3cd543626:000b57fffeb1bab5:000B57FFFEB1BAB5_1_colortemperature - unlinked

I can add some more debugging around this area to see what is happening.

Thanks a lot for looking into it @cdjackson. Here are the updated logs:

openhab.log.zip

[weakfl]

@cdjackson I've seen #777 has already been merged. Should I test the latest build or is something else required?

EDIT: NVM, seems the PR was just related to logging. Sorry for the noise.

[cdjackson]

Yes, please try this out. The PR has no change to logging - just a change to code.

[weakfl]

Yes, please try this out. The PR has no change to logging - just a change to code.

Unfortunately still the same result @cdjackson: openhab.log.zip

[cdjackson]

Please provide a log with the latest binding - I've just changed a little bit of logging.

[weakfl]

@cdjackson I will once a new build is available, #3118 failed to build.

[cdjackson]

I'm not sure what happened with the build, but it seems ok now.

[weakfl]

Thanks Chris.

With the latest build polling seems to be working again, so thanks for that as well. Some devices still go offline, but only very briefly and come back online with the next polling almost immediately.

Here's a debug log in case you're interested: openhab.log.zip

I consider the issue resolved, so feel free to close unless you want to make some follow-up changes.

[cdjackson]

Thanks. I'll close this then.