zigpy / zha-device-handlers

ZHA device handlers bridge the functionality gap created when manufacturers deviate from the ZCL specification, handling deviations and exceptions by parsing custom messages to and from Zigbee devices.
Apache License 2.0
743 stars 679 forks source link

[BUG]Hue bulbs with ZHA delays or not responding in UI #465

Closed blair287 closed 3 years ago

blair287 commented 4 years ago

The problem

When switching on a scene containing several hue bulbs all controlled via ZHA 5/10 times some do not turn on or they turn on but UI says they are off. If the devices are in a scene the scene will hang until the bulbs update their state or about 5 seconds pass then another scene can be run other wise nothing responds, this also occurs when they are not in a scene but appears to be less frequent but still happens a lot.

This issue used to happen very infrequently but now my lights do not work more than 50% of the time.

I have hue remotes activating a scene when pressed, the event is seen my HA for the remote button press, the lights seem to actually turn on most of the time but the UI says they are off or they turn on but there is over a 5 second delay till they do. This used to be instant.

Also having it where lights told to turn off 2/3 turn off physically but in UI all show off.

Environment

HA supervised inside proxmox on intel nuc

Problem-relevant configuration.yaml

Traceback/Error logs

Here is an example the light actually turned on but it looks like something failed and the UI showed it as off, which then prevents another scene from running.

2020-08-25 07:54:41 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 189: e9
2020-08-25 07:54:41 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0xbd 'aps_data_confirm' for <DeconzAddressEndpoint address_mode=ADDRESS_MODE.NWK address=0xe60a endpoint=11>, status: 0xe9
2020-08-25 07:54:41 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Error while sending 189 req id frame: TXStatus.MAC_NO_ACK
2020-08-25 07:54:41 DEBUG (MainThread) [zigpy.device] [0xe60a] Delivery error for seq # 0xbc, on endpoint id 11 cluster 0x0006: message send failure
2020-08-25 07:54:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xe60a:11:0x0006]: command failed: on exception: [0xe60a:11:0x0006]: Message send failure
2020-08-25 07:54:41 DEBUG (MainThread) [homeassistant.components.zha.entity] light.office_light: turned on: {'move_to_level_with_on_off': [4, <Status.SUCCESS: 0>], 'on_off': DeliveryError('[0xe60a:11:0x0006]: Message send failure')}
2020-08-25 07:54:41 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (24, 193, 0, <DeconzAddressEndpoint address_mode=2 address=0x3591 endpoint=11>, 260, 768, 1, b'\x01\xc0\x075>\n\x17\x01\x00', 2, 0)
2020-08-25 07:54:41 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 174>, 0]
2020-08-25 07:54:41 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 46>, 193]
2020-08-25 07:54:41 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1)
2020-08-25 07:54:41 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [28, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|APSDE_DATA_CONFIRM|2: 46>, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0000>, 1, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0f4e>, 11, 260, 6, b'\x18\xbe\x0b\x01\x00', 0, 175, 215, 160, 125, 171, 0, -67]
2020-08-25 07:54:41 DEBUG (MainThread) [zigpy.zcl] [0x0f4e:11:0x0006] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=190 command_id=Command.Default_Response>
2020-08-25 07:54:41 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0f4e>, ep: 11, profile: 0x0104, cluster_id: 0x0006, data: b'18be0b0100'
2020-08-25 07:54:41 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,)

Here is another this is happening on all bulbs


2020-08-25 08:10:19 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x3591:11:0x0006]: command failed: off exception: 
2020-08-25 08:10:19 DEBUG (MainThread) [homeassistant.components.zha.entity] light.office_play_2: turned off: ```
## Additional information
Adminiuga commented 4 years ago

it wasn't successful in sending the request out:

2020-08-25 07:54:41 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0xbd 'aps_data_confirm' for <DeconzAddressEndpoint address_mode=ADDRESS_MODE.NWK address=0xe60a endpoint=11>, status: 0xe9
2020-08-25 07:54:41 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Error while sending 189 req id frame: TXStatus.MAC_NO_ACK
Adminiuga commented 4 years ago

not a problem with zha or device handlers

blair287 commented 4 years ago

it wasn't successful in sending the request out:

2020-08-25 07:54:41 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0xbd 'aps_data_confirm' for <DeconzAddressEndpoint address_mode=ADDRESS_MODE.NWK address=0xe60a endpoint=11>, status: 0xe9
2020-08-25 07:54:41 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Error while sending 189 req id frame: TXStatus.MAC_NO_ACK

how come this is happening more and more went from a nearly perfect working ZHA set up to 50% of the time lights not coming on even though in UI they say they are on.

Adminiuga commented 4 years ago

there were no changes to zigpy_deconz for a really long time. Zigpy_deconz is what ZHA uses to communicate with ConBee. ConBee tells zigpy_deconz it did not sent the packet, what else ZHA is supposed to do if the problem is reported by the network?

meremortals70 commented 4 years ago

it wasn't successful in sending the request out:


2020-08-25 07:54:41 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0xbd 'aps_data_confirm' for <DeconzAddressEndpoint address_mode=ADDRESS_MODE.NWK address=0xe60a endpoint=11>, status: 0xe9

2020-08-25 07:54:41 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Error while sending 189 req id frame: TXStatus.MAC_NO_ACK

how come this is happening more and more went from a nearly perfect working ZHA set up to 50% of the time lights not coming on even though in UI they say they are on.

What firmware are you running on your Conbee? I was having a lot of issues with ZHA before updating the firmware in my Conbee.

The only Philips lights I have any issues with now are the LWB010's which are rubbish anyway.

Adminiuga commented 4 years ago

and what channel are you running on? Don't run on channel 11

blair287 commented 4 years ago

and what channel are you running on? Don't run on channel 11 I am on channel 11. How come I shouldn't use it?

dmulcahey commented 4 years ago

It really depends on what channels your WiFi runs on. Zigbee and WiFi share spectrum. Take a peek at: https://www.metageek.com/training/resources/zigbee-wifi-coexistence.html. 15 tends to be a decent channel.

TheJulianJES commented 4 years ago

Not sure if this is related, but I'm also getting: [zigpy_deconz.zigbee.application] Error while sending 64 req id frame: TXStatus.NWK_BT_TABLE_FULL and [zigpy_deconz.zigbee.application] Error while sending 82 req id frame: TXStatus.MAC_NO_ACK when activating a scene with multiple Philips Hue lights. Most of the time, it takes about 3-4 tries to get all lights turning on and changing to the correct color. Tried with older ZLL hue bulbs and with the newer ZHA hue bulbs.

Could be related to network connectivity - I tried simply turning off all WiFi access point (LQI is around 190 for most bulbs), but this didn't really improve the situation. (ConBee II is hooked up with a USB 2.0 2m extension cable to a USB 3.0 port (there are no USB 2.0 ports on that machine)) But I'm also not sure how and if the BT_TABLE_FULL error can be solved. (Or what it really means)

blair287 commented 4 years ago

It really depends on what channels your WiFi runs on. Zigbee and WiFi share spectrum. Take a peek at: https://www.metageek.com/training/resources/zigbee-wifi-coexistence.html. 15 tends to be a decent channel.

My WiFi is on channel 11 so opposite end to ZigBee channel 11.

It is getting a bit annoying didn't have any issues before, now quite frequently I'll turn off 3 bulbs and 1 of them will stay on. Never used to happen. Or if I turn on 3 bulbs only 1 will.

dmulcahey commented 4 years ago

I’m sorry it’s annoying but your logs show that there are delivery errors. There is nothing we can do from the ZHA side to remediate that and there are many things that can cause this. I know this isn’t an answer anyone likes but I’m out of ideas. If it were me I’d start looking at the path the packets are taking to the devices. Maybe set up the zha_map component and the network visualization card and see what the troubled device is connected to.

Adminiuga commented 4 years ago

What about neighbors? Do a wifi scan

TheJulianJES commented 4 years ago

Some other people also reported having issues with ConBee, although I'm unsure whether or not this could even be related: https://github.com/home-assistant/core/issues/38642#issuecomment-688252747

blair287 commented 4 years ago

What about neighbors? Do a wifi scan

I did channel 11 on ZigBee is the most empty channel for the WiFi around me.

Adminiuga commented 4 years ago

So I take the "most empty" != empty. Zigbee channel 11still overlaps with WiFi channel 1. Move to channel 25 or 26

blair287 commented 4 years ago

So I take the "most empty" != empty. Zigbee channel 11still overlaps with WiFi channel 1. Move to channel 25 or 26

ZigBee channel 11 and WiFi channel 11 are the furthest apart you can be.

Most ie 80% of WiFi networks around me are on WiFi channel 11 which overlaps with ZigBee 25. I'm using a conbee so don't have option of 26 but I believe that still overlaps with WiFi channel 11.

But I see the overlap is the side lobe of the WiFi channel 11 so maybe if those neighbors WiFi networks are far enough away maybe won't affect 25.

I'll give it a go.

blair287 commented 4 years ago

So I take the "most empty" != empty. Zigbee channel 11still overlaps with WiFi channel 1. Move to channel 25 or 26

Moved my router to channel 1 and set ZigBee to channel 25 absolutely no change same issues. Sometimes it works perfectly other times there is a huge delay and you can see home assistant hanging at exciting scene when it contains hue bulbs. Or you send off to 3 bulbs and only 1 or 2 turn off.

dmulcahey commented 4 years ago

@blair287 Are you still having this issue? IIRC you were having issues w/ IKEA blinds and I believe I saw that you mentioned that those issues just vanished... Is there any chance that they resolved after this change in channels mentioned above?

blair287 commented 4 years ago

@blair287 Are you still having this issue? IIRC you were having issues w/ IKEA blinds and I believe I saw that you mentioned that those issues just vanished... Is there any chance that they resolved after this change in channels mentioned above?

Still have the issue with hue bulbs the blind started working fine before the channel change no idea why that issue went away but saw someone else with same issue with blind so not sure what's going on.

The blind sometime still throws a fit I have to unpair then reset the blind but then leave it for an hour without repairing then when I pair again it works ok. If I pair straight away I get that laggy slow response back again.

dmulcahey commented 4 years ago

how do you have the conbee stick setup? How is it connected to the machine?

blair287 commented 4 years ago

how do you have the conbee stick setup? How is it connected to the machine?

Plugged into intel nuc via USB 2.0 2m extension

The blind delay is back after updating HA from 114.4 to 116.2 5 seconds again from command issue to it moving.

github-actions[bot] commented 3 years ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.