Closed TheZoker closed 2 years ago
probot-home-assistant[bot]
commented
2 years ago Hey there @dmulcahey, @adminiuga, mind taking a look at this issue as it has been labeled with an integration (zha) you are listed as a code owner for? Thanks!
(message by CodeOwnersMention)
zha documentation zha source (message by IssueLinks)
Adminiuga
commented
2 years ago Check integration documentation about logging. Provide debug logs
TheZoker
commented
2 years ago Here are the debug logs:
Strangehadron
commented
2 years ago Same issue for me, also using ikea zigbee button (but not seem related to the zigbee button itself)
The problem By using an automation with an IKEA zigbee button to turn all the light off in my house, there is a 10 seconds delay for it to work. I test more and this doesn't seem to be related to automation itself (automation triggered directly and log appear directly).
When i turn off or on all the light on the dashboard the issue is the same, 10 seconds delay. In my log the activation appear only when light turn on or off, not when i click the switch on the dashboard.
I have light groups like these :
Light house -> Light dining room -> Light kitchen
Light dining room -> light 1 -> light 2 Light Kitchen -> light 1 -> light 2
The only group with the delay is the all light group, other or light itself don't have this delay. Maybe something related with a number of light ?
What version of Home Assistant Core has the issue?
core-2022.2.0b -> b2
What was the last working version of Home Assistant Core?
core-2021.12.10
What type of installation are you running?
Home Assistant OS
Integration causing the issue Zigbee2MQTT (MQTT)
Link to integration documentation on our website https://www.home-assistant.io/integrations/mqtt/
Anything in the logs that might be useful for us?
Exemple of z2m log when i trigger of the switch on the dashboard:
Zigbee2MQTT:error 2022-01-28 20:59:00: Publish 'set' 'state' to 'Lampe toilettes' failed: 'Error: Command 0x588e81fffec81de9/1 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (no response received)'
Zigbee2MQTT:error 2022-01-28 20:59:00: Publish 'set' 'state' to 'Lampe salle de bain' failed: 'Error: Command 0x842e14fffe32ceb4/1 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (no response received)'
Zigbee2MQTT:error 2022-01-28 20:59:37: Publish 'set' 'state' to 'Lampe chambre Amy' failed: 'Error: Command 0x0c4314fffe949246/1 genOnOff.on({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (no response received)'Additional information
fishbone-git
commented
2 years ago I'm seeing the same behaviour for grouped lights, no ZHA involved. Each of the lights can be turned on from the front end and will toggle immediately. When toggling the group entity, however, one comes on immediately, and the other exactly 10 seconds later
Strangehadron
commented
2 years ago I'm seeing the same behaviour for grouped lights, no ZHA involved. Each of the lights can be turned on from the front end and will toggle immediately. When toggling the group entity, however, one comes on immediately, and the other exactly 10 seconds later
Yes, it seem related to light groups, but i'm not encounter the problem for all my light groups. My issue appear with the all light group (composed of all other light group)
fishbone-git
commented
2 years ago agreed. groups are ok. light groups are not.
Adminiuga
commented
2 years ago Can you post debug logs of zha receiving the event from remote and triggered Ng automation and request to the bulb? Include homeassistant.core too, so could time the core events
TheZoker
commented
2 years ago Oh yeah true, when I try to call light.toggle on the whole group, then there is a 10 minute delay. So I don't think that this has to do anything with ZHA, but rather with the group entity somehow 🤔
I edited the initial issue and replaced zha with light.group
probot-home-assistant[bot]
commented
2 years ago grouped_light documentation grouped_light source (message by IssueLinks)
TheZoker
commented
2 years ago Hmm the only PR that I was able to find that could be related is maybe this one: https://github.com/home-assistant/core/pull/63477
fishbone-git
commented
2 years ago in my case, the logs show a timeout which is very repeatable. It seems to be a light group that also contains another light group
- platform: group
name: WLED Overkapping Lights
entities:
- light.wled_overkapping_master
- light.wled_garden_bulb
- light.wled_achtertuin_master - platform: group
name: Garden Light
entities:
- light.wled_garden_bulbI use the group as a kind of "alias" as I've changed the device a number of times and it saves rewriting automations and dashboards. When I take out the light group and use the device directly in the main group, all appears to work as it should
kongjudas
commented
2 years ago I have noticed the same since before Christmas but with light groups using ZHA. This group is containing 9 lights, all IKEA. I moved them from ZHA to the IKEA gateway and got better results, but inconsistent. I have the same problem now with the 2022.2b4 but only in a selection of groups. It seems to depend on the size of the group.
lweberru
commented
2 years ago Same issue with light groups and hue hubs. Scenes and single lights react fast, light groups take over 10 seconds or even longer and sometimes also dont react at all. Version: Home Assistant 2022.3.0.dev20220203
geekofweek
commented
2 years ago I can confirm @fishbone-git analysis, nested light groups seemed to be the culprit for me. Removing the nesting seemed to solve it.
Kirorus
commented
2 years ago I have same problem with nested light groups... With shelly2.5 and shelly rgbw2 and standard shelly integration
eerorossi
commented
2 years ago The same finding here. Steering nested group is slow (~10 s) while individual groups respond immediately.
Jpsy
commented
2 years ago Same here: Nested light groups have a delay of about 10 seconds, both when switching on and off. The inner light groups work instantaneously.
Probably NOT related to Zigbee / ZHA. No MQTT or Zigbee or other RF protocols involved in my case. All entities are cable bound KNX and work lightning fast when switched separately.
I went through all logs and there is nothing suspicious.
avdrovaart
commented
2 years ago Yeah same here, See https://github.com/home-assistant/core/issues/65766#issuecomment-1030627248 for a screenshot of the automation debug, my configuration. and also other steps I tried.
mguterl
commented
2 years ago I am having the same issue and can provide additional debug logs if needed.
emufan
commented
2 years ago Same here. And same with cover groups.
oywino
commented
2 years ago I have exactly the same issue. And for me it happens with nested light groups.
bartdorsey
commented
2 years ago Same here, groups of groups have a 10 second delay before the grouped lights turn off.. Curiously enough, turning them ON seems to be instant.
cafarre
commented
2 years ago Same here with nested groups of lights and covers too. It doesn't seem to be a problem with the shelly devices, they work fine individually. 10 second delay occurs when turning nested groups "on" or "off"
Jpsy
commented
2 years ago Even better: Try groups of nested groups. I have hierarchical light groups up to 7 levels deep. They take 1 minute to respond! 😫😂
Jpsy
commented
2 years ago Wait, this report is 9 days old. 8 days since the label was corrected to "grouped light". But the release is only 3 days ago. You ambushed me knowingly! Couldn't there have been at least a "known problems" hint somewhere in the small print?
Silvenga
commented
2 years ago Don't feel bad @Jpsy - I also had some problems finding this (and others, at least 5 tickets are related to this). The cross cutting nature is making searching difficult - is it a light problem, is it a hue problem, etc.
I wonder if the needs-more-information is still needed. 🐱
Jpsy
commented
2 years ago The logs that were the reason for needs-more-information have also been provided 8 days ago. The XX chromosome acceptance factor of HA has taken a serious hit. I'm in trouble. (Yes, I know this is an issue tracker, not a chat room.)
emufan
commented
2 years ago The XX chromosome acceptance factor of HA has taken a serious hit. I'm in trouble. (Yes, I know this is an issue tracker, not a chat room.)
Agree. For now I used the work around to remove the nested groups and assigned every device directly to the groups. A lot of overhead, but at least working.
rteterin
commented
2 years ago Same issue here.
With this config:
light:
- platform: group
name: room_main_light
entities:
- light.room_rgb
- platform: group
name: room_rgb
entities:
- light.room_e27_rgb_1
- light.room_e27_rgb_2
- light.room_e27_rgb_3
- light.room_e27_rgb_4
- light.room_e27_rgb_5
- light.room_e27_rgb_6Switching light.room_main_light on/off takes about 10 seconds to complete, while switching light.room_rgb on/off works instantly. The lights are connected via Sonoff Zigbee 3.0 Plus stick and Zigbee2mqtt.
System info: Home Assistant OS 7.2 core-2022.2.2 Zigbee2mqtt (1.23.0-1)
PhilippBaumgarten
commented
2 years ago I can confirm this new delay for groups - also for direct control of Hue lights. In my case also first group (Schlafzimmer - Deckenlicht) is causing delays for on/off command of up to 5seconds.
- platform: group
name: Schlafzimmer - Deckenlicht
unique_id: 40222f67-b935-4024-aad7-39c72b4a0bb7
entities:
- light.white_schlafzimmer_1
- light.white_schlafzimmer_2
- light.white_schlafzimmer_3
- light.white_schlafzimmer_4
- platform: group
name: Schlafzimmer
unique_id: 8f593185-a73e-4008-ae30-b41a23524711
entities:
- light.schlafzimmer_deckenlicht
- light.hue_go_obergeschossHi @Adminiuga,
reports are piling up here and in many related issues for about 10 days. The needs-more-information tag has not been removed. Duplicate flags have not been created. No response whatsoever. Is there some major road block? Anything else we can do to assist in debugging? This is really affecting many users.
Adminiuga
commented
2 years ago No debug logs for the issue were provided. Debug logs of zha startup are not relevant. Need the logs with timestamp where i can see the incoming event and coresponding service calls to turn the lights on. Further more, based on the additional feedback, the common denominator seem to be the light groups, so I'm not sure this is a zha problem. But again, since nobody cared to provide logs i can't tell. One thing for sure, I'm not seeing this issue in my production setup, but i'm also not using the light groups. but I'm using zha groups and haven't noticed issues
Silvenga
commented
2 years ago @Adminiuga are these logs enough? https://github.com/home-assistant/core/issues/65702
Adminiuga
commented
2 years ago Well, not really. That is not zha, but it re-enforces assumption that the problem might be with the group itself, since the underlying platform is hue and not zha.
In those logs, i assume the top entities n-are the light groups? The service call for the individual lights is called 10s after the service call for the light group, after the timeout
Silvenga
commented
2 years ago Yeah, the service call timing out was for a nested light group. Multiple levels of nested groups appear to compound the delay. Flattening the hierarchy mitigates the problem.
I think it's fair to assume that this is related to nested light groups - per https://github.com/home-assistant/core/issues/65702#issuecomment-1030328471, https://github.com/home-assistant/core/issues/65119#issuecomment-1024735886 and others. I've seen bug reports open for a broad range of integrations.
Jpsy
commented
2 years ago Yes, definitely. The issue is caused by nesting light groups, not by using ZHA. This was found early in this discussion and confirmed many times with examples and YAML code. According to related issue reports it is not even restricted to light groups, but happens with other groups too.
So please let me again as the question @Adminiuga and @dmulcahey:
Are the provided logs sufficient (to debug nested groups) and are you even the right assignees?
DenisMir
commented
2 years ago I can confirm that error too! I'm having light groups of KNX light entities. (nested light groups as well) Worked well for months and after one of the latest updates it takes ages to deactivate a light group.
Which logs can I deliver? What do I have to setup the logs. I am willing to assist but I need instructions on how to help best.
probot-home-assistant[bot]
commented
2 years ago group documentation group source (message by IssueLinks)
probot-home-assistant[bot]
commented
2 years ago Hey there @home-assistant/core, mind taking a look at this issue as it has been labeled with an integration (group) you are listed as a code owner for? Thanks!
(message by CodeOwnersMention)
Jpsy
commented
2 years ago Again: These are probably all duplicates
oywino
commented
2 years ago Updating to 2022.2.3 today didn't solve this problem 😒
gipnokote
commented
2 years ago Updating to 2022.2.3 today didn't solve this problem 😒
Obviously there is no solution yet, the ticket is "open" and still has "needs more information" tag :|
oywino
commented
2 years ago "Needs more information" is a bit too generic. If I revert back to 2021.12.10 and earlier, it works OK. From 2022.2.1 it fails. I suspect it should be easy to reproduce; Just define nested ZigBee light groups, and it should fail, meaning: When the light group is turned on or off, all light within the group that them selves are light groups, have a delay of 10sec before they respond. All other lights in the group that are not nested groups, respond instantly.
gipnokote
commented
2 years ago Just define nested ZigBee light groups, and it should fail
Not just Zigbee, but any nested grouped light will do. As for me, I reverted to 2021.12.10 and wait for a fix...
Jpsy
commented
2 years ago Yes please, stop iterating ZigBee in this ticket! The issue has obviously nothing to do with ZigBee and you don't help the developers by pointing in wrong or irrelevant directions again. They already have to read through a lot of content here.
oywino
commented
2 years ago Yes please, stop iterating ZigBee in this ticket! Sorry about that. My bad. It just came out like that because I only have ZigBee devices. Thank you for correcting me.
jacquemard
commented
2 years ago I have reproduced this issue on a fresh local install (thinking I could maybe fix it myself, but I have not been able to ^^), here are some logs when turning on the "root" group, if it can help:
2022-02-08 21:24:02 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [140082608257200] Received {'type': 'call_service', 'domain': 'light', 'service': 'turn_on', 'service_data': {'entity_id': 'light.root'}, 'id': 32}
2022-02-08 21:24:02 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.root>
2022-02-08 21:24:02 DEBUG (MainThread) [homeassistant.components.group.light] Forwarded turn_on command: {'entity_id': ['light.leaf']}
2022-02-08 21:24:02 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=['light.leaf']>
2022-02-08 21:24:03 DEBUG (Recorder) [homeassistant.components.recorder] Sending keepalive
2022-02-08 21:24:03 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7f679af3ca80> checked out from pool
2022-02-08 21:24:03 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7f679af3ca80> being returned to pool
2022-02-08 21:24:03 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7f679af3ca80> rollback-on-return
2022-02-08 21:24:04 DEBUG (MainThread) [zeroconf] offsets = questions=0, answers=0, authorities=0, additionals=0
2022-02-08 21:24:04 DEBUG (MainThread) [zeroconf] lengths = questions=51, answers=1, authorities=0, additionals=0
2022-02-08 21:24:04 DEBUG (MainThread) [zeroconf] now offsets = questions=51, answers=1, authorities=0, additionals=0
2022-02-08 21:24:12 DEBUG (MainThread) [homeassistant.core] Service did not complete before timeout: <ServiceCall light.turn_on (c:ea234caac9a987df3fcaf9122e71c479): entity_id=['light.root'], params=>
2022-02-08 21:24:12 DEBUG (MainThread) [homeassistant.core] Service did not complete before timeout: <ServiceCall light.turn_on (c:ea234caac9a987df3fcaf9122e71c479): entity_id=['light.leaf'], params=>
2022-02-08 21:24:12 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [140082608257200] Sending {"id": 32, "type": "result", "success": true, "result": {"context": {"id": "ea234caac9a987df3fcaf9122e71c479", "parent_id": null, "user_id": "aa93dc7ab1eb429f92868073793efccc"}}}
2022-02-08 21:24:12 DEBUG (MainThread) [homeassistant.components.group.light] Forwarded turn_on command: {'entity_id': ['light.virtual_light_test']}
2022-02-08 21:24:12 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=['light.virtual_light_test']>
2022-02-08 21:24:12 INFO (SyncWorker_1) [custom_components.virtual.light] turn_on: {}
2022-02-08 21:24:12 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.virtual_light_test, old_state=<state light.virtual_light_test=off; supported_color_modes=['brightness'], friendly_name=light_test, brightness=255, supported_features=1 @ 2022-02-08T21:23:48.293397+00:00>, new_state=<state light.virtual_light_test=on; supported_color_modes=['brightness'], color_mode=brightness, brightness=255, friendly_name=light_test, supported_features=1 @ 2022-02-08T21:24:12.217795+00:00>>
2022-02-08 21:24:12 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.leaf, old_state=<state light.leaf=off; supported_color_modes=['brightness'], entity_id=['light.virtual_light_test'], icon=mdi:lightbulb-group, friendly_name=leaf, supported_features=0 @ 2022-02-08T21:23:48.293669+00:00>, new_state=<state light.leaf=on; supported_color_modes=['brightness'], color_mode=brightness, brightness=255, entity_id=['light.virtual_light_test'], icon=mdi:lightbulb-group, friendly_name=leaf, supported_features=0 @ 2022-02-08T21:24:12.218165+00:00>>
2022-02-08 21:24:12 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.root, old_state=<state light.root=off; supported_color_modes=['brightness'], entity_id=['light.leaf'], icon=mdi:lightbulb-group, friendly_name=root, supported_features=0 @ 2022-02-08T21:23:48.293954+00:00>, new_state=<state light.root=on; supported_color_modes=['brightness'], color_mode=brightness, brightness=255, entity_id=['light.leaf'], icon=mdi:lightbulb-group, friendly_name=root, supported_features=0 @ 2022-02-08T21:24:12.218562+00:00>>
2022-02-08 21:24:12 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [140082608257200] Sending {"id": 17, "type": "event", "event": {"event_type": "state_changed", "data": {"entity_id": "light.virtual_light_test", "old_state": {"entity_id": "light.virtual_light_test", "state": "off", "attributes": {"supported_color_modes": ["brightness"], "friendly_name": "light_test", "brightness": 255, "supported_features": 1}, "last_changed": "2022-02-08T21:23:48.293397+00:00", "last_updated": "2022-02-08T21:23:48.293397+00:00", "context": {"id": "948dd3c987f204813e95720def051278", "parent_id": null, "user_id": "aa93dc7ab1eb429f92868073793efccc"}}, "new_state": {"entity_id": "light.virtual_light_test", "state": "on", "attributes": {"supported_color_modes": ["brightness"], "color_mode": "brightness", "brightness": 255, "friendly_name": "light_test", "supported_features": 1}, "last_changed": "2022-02-08T21:24:12.217795+00:00", "last_updated": "2022-02-08T21:24:12.217795+00:00", "context": {"id": "ea234caac9a987df3fcaf9122e71c479", "parent_id": null, "user_id": "aa93dc7ab1eb429f92868073793efccc"}}}, "origin": "LOCAL", "time_fired": "2022-02-08T21:24:12.217795+00:00", "context": {"id": "ea234caac9a987df3fcaf9122e71c479", "parent_id": null, "user_id": "aa93dc7ab1eb429f92868073793efccc"}}}
2022-02-08 21:24:12 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [140082608257200] Sending {"id": 17, "type": "event", "event": {"event_type": "state_changed", "data": {"entity_id": "light.leaf", "old_state": {"entity_id": "light.leaf", "state": "off", "attributes": {"supported_color_modes": ["brightness"], "entity_id": ["light.virtual_light_test"], "icon": "mdi:lightbulb-group", "friendly_name": "leaf", "supported_features": 0}, "last_changed": "2022-02-08T21:23:48.293669+00:00", "last_updated": "2022-02-08T21:23:48.293669+00:00", "context": {"id": "948dd3c987f204813e95720def051278", "parent_id": null, "user_id": "aa93dc7ab1eb429f92868073793efccc"}}, "new_state": {"entity_id": "light.leaf", "state": "on", "attributes": {"supported_color_modes": ["brightness"], "color_mode": "brightness", "brightness": 255, "entity_id": ["light.virtual_light_test"], "icon": "mdi:lightbulb-group", "friendly_name": "leaf", "supported_features": 0}, "last_changed": "2022-02-08T21:24:12.218165+00:00", "last_updated": "2022-02-08T21:24:12.218165+00:00", "context": {"id": "ea234caac9a987df3fcaf9122e71c479", "parent_id": null, "user_id": "aa93dc7ab1eb429f92868073793efccc"}}}, "origin": "LOCAL", "time_fired": "2022-02-08T21:24:12.218165+00:00", "context": {"id": "ea234caac9a987df3fcaf9122e71c479", "parent_id": null, "user_id": "aa93dc7ab1eb429f92868073793efccc"}}}
2022-02-08 21:24:12 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [140082608257200] Sending {"id": 17, "type": "event", "event": {"event_type": "state_changed", "data": {"entity_id": "light.root", "old_state": {"entity_id": "light.root", "state": "off", "attributes": {"supported_color_modes": ["brightness"], "entity_id": ["light.leaf"], "icon": "mdi:lightbulb-group", "friendly_name": "root", "supported_features": 0}, "last_changed": "2022-02-08T21:23:48.293954+00:00", "last_updated": "2022-02-08T21:23:48.293954+00:00", "context": {"id": "948dd3c987f204813e95720def051278", "parent_id": null, "user_id": "aa93dc7ab1eb429f92868073793efccc"}}, "new_state": {"entity_id": "light.root", "state": "on", "attributes": {"supported_color_modes": ["brightness"], "color_mode": "brightness", "brightness": 255, "entity_id": ["light.leaf"], "icon": "mdi:lightbulb-group", "friendly_name": "root", "supported_features": 0}, "last_changed": "2022-02-08T21:24:12.218562+00:00", "last_updated": "2022-02-08T21:24:12.218562+00:00", "context": {"id": "ea234caac9a987df3fcaf9122e71c479", "parent_id": null, "user_id": "aa93dc7ab1eb429f92868073793efccc"}}}, "origin": "LOCAL", "time_fired": "2022-02-08T21:24:12.218562+00:00", "context": {"id": "ea234caac9a987df3fcaf9122e71c479", "parent_id": null, "user_id": "aa93dc7ab1eb429f92868073793efccc"}}}With the following configuration:
light:
- platform: virtual # from twrecked/hass-virtual
name: light_test
- platform: group
name: leaf
entities:
- light.virtual_light_test
- platform: group
name: root
entities:
- light.leaf
emontnemery
commented
2 years ago Thanks a lot @remij1 for sharing the config example, that really helped 👍
The problem
After updating to the latest beta, it takes about 10 seconds to turn on/off my
yeelightlights.I use a ikea zigbee switch to turn on/off the lights. When I track the
zha_eventin HA, the event appears immediately. When I turn the yeelights on/off within the HA dashboard, this also happens immediately, except when I call it on a light group.So the issue seems to lay anywhere between the event trigger and the automation, that turns on/off the lights.
I was able to reproduce this on two different instances in two different homes (both with yeelights and ikea zigbee switches).
It seems, that the issue has to do with the
light.groupintegration somehow. What's also intresting is, that I have three groups.group1andgroup2and then agroup3which consists ofgroup1andgroup2:And this issue only happens on group 3, but not on group 1 and 2. So it seems, that it has something to do with the nested group (maybe).
What version of Home Assistant Core has the issue?
core-2022.2.0b1
What was the last working version of Home Assistant Core?
core-2021.12.10
What type of installation are you running?
Home Assistant OS
Integration causing the issue
light.group
Link to integration documentation on our website
https://www.home-assistant.io/integrations/light.group/
Example YAML snippet
Anything in the logs that might be useful for us?
No response
Additional information
No response