Automation Error Advice

c0ntax · July 18, 2023, 8:00am

I have an automation to run a script to turn on specific lights when I turn off my TV between 10pm and 2am. However, it’s stopped working lately, since the latest HA Core update and throws out an error. I’m not sure if the Core update is the reason for this or coincidence.

The automation runs the first two script services but not the rest and the error appears.

If I change the time from in the automation, just to test it, it works as expected.

I can’t make out what this error is telling me so if anyone could please help out and advise what the issue is.

Error

Logger: homeassistant.components.script.both_to_bed
Source: components/zha/light.py:551
Integration: Script (documentation, issues)
First occurred: July 17, 2023 at 10:16:55 PM (1 occurrences)
Last logged: July 17, 2023 at 10:16:55 PM

Both to Bed: Error executing script. Unexpected error for call_service at pos 2: Failed to enqueue message after 3 attempts: <EmberStatus.NETWORK_BUSY: 161>
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 468, in _async_step
    await getattr(self, handler)()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 703, in _async_call_service_step
    response_data = await self._async_run_long_action(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 665, in _async_run_long_action
    return long_task.result()
           ^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 1965, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2005, in _execute_service
    return await cast(
           ^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 235, in handle_service
    return await service.entity_service_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 848, in entity_service_call
    response_data = task.result()  # pop exception if have
                    ^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1192, in async_request_call
    return await coro
           ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 892, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/light/__init__.py", line 582, in async_handle_light_on_service
    await light.async_turn_on(**filter_turn_on_params(light, params))
  File "/usr/src/homeassistant/homeassistant/components/group/light.py", line 179, in async_turn_on
    await self.hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1965, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2005, in _execute_service
    return await cast(
           ^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 235, in handle_service
    return await service.entity_service_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 848, in entity_service_call
    response_data = task.result()  # pop exception if have
                    ^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1192, in async_request_call
    return await coro
           ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 892, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/light/__init__.py", line 582, in async_handle_light_on_service
    await light.async_turn_on(**filter_turn_on_params(light, params))
  File "/usr/src/homeassistant/homeassistant/components/zha/light.py", line 1197, in async_turn_on
    await super().async_turn_on(**kwargs)
  File "/usr/src/homeassistant/homeassistant/components/zha/light.py", line 373, in async_turn_on
    if not await self.async_handle_color_commands(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/zha/light.py", line 551, in async_handle_color_commands
    result = await self._color_cluster_handler.move_to_color(
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/zigpy/zcl/__init__.py", line 375, in request
    return await self._endpoint.request(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/zigpy/group.py", line 57, in request
    await self.application.send_packet(
  File "/usr/local/lib/python3.11/site-packages/bellows/zigbee/application.py", line 812, in send_packet
    raise zigpy.exceptions.DeliveryError(
zigpy.exceptions.DeliveryError: Failed to enqueue message after 3 attempts: <EmberStatus.NETWORK_BUSY: 161>

Automation

- alias: Both to Bed
  id: both_to_bed
  mode: single
  trigger:
  - platform: state
    entity_id: media_player.sky_q
    to: 'off'
  condition:
    condition: and
    conditions:
    - condition: time
      after: '22:00:00'
      before: '02:00:00'
    - condition: state
      entity_id: input_boolean.holiday_mode
      state: 'off'
    - condition: state
      entity_id: sensor.iphone_m_battery_state
      state: 'Not Charging'
    - condition: state
      entity_id: sensor.iphone_r_battery_state
      state: 'Not Charging'
    - condition: or
      conditions:
        - condition: state
          entity_id: person.m
          state: 'home'
        - condition: state
          entity_id: person.r
          state: 'home'
#      value_template: '{{ is_state("person.m", "home") or is_state("person.r",
#        "home") }}'
  action:
  - service: script.both_to_bed

Script

both_to_bed:
  alias: Both to Bed
  sequence:
  - service: light.turn_on
    data:
      entity_id: light.living_room_cabinet_lights
      brightness: 160
      rgb_color:
      - 250
      - 185
      - 120
      transition: 2   
  - service: light.turn_on
    data:
      entity_id: light.kitchen_lights
      brightness: 160
      rgb_color:
      - 250
      - 185
      - 120
      transition: 2
  - service: light.turn_on
    data:
      entity_id: light.headboard_light
      brightness: 160
      rgb_color:
      - 222
      - 91
      - 245
      transition: 120
  - service: light.turn_on
    data:
      entity_id: 
      - light.m_bedside_lamp
      - light.r_bedside_lamp
      brightness: 100
      rgb_color:
      - 252
      - 131
      - 10
      transition: 120
  - service: light.turn_off
    data:
      entity_id: 
      - light.living_room_light
      - light.tv_unit_lights_all
      transition: 4
  - delay:
      minutes: 2
  - service: light.turn_off
    data:
      entity_id: light.living_room_cabinet_lights

koying · July 18, 2023, 8:14am

That’s an error from ZHA telling it cannot reach one of your devices, apparently.
Usually, restarting HA fixes those issues.

tom_l · July 18, 2023, 8:18am

Looks like your zigbee network is overloaded:

Failed to enqueue message after 3 attempts: <EmberStatus.NETWORK_BUSY: 161>

Are these home assistant light groups or zigbee light groups?

light.living_room_cabinet_lights

light.kitchen_lights

If they are home assistant groups then an individual message is sent to each light.

If they are zigbee light groups then one broadcast message is sent per group.

Have a read of this issue: https://github.com/home-assistant/core/issues/86411

Either way a delay between your service calls may help.

c0ntax · July 18, 2023, 9:14am

They’re both zigbee groups, Tom.

Thanks for the github article, it’s an interesting read and I’ll take another look at my zigbee groups and try and space invoking them a bit to see if that helps.

kurtzettel · July 18, 2023, 2:19pm

Did something change in 2023.7 that would affect this? I have zigbee devices that are sometimes unavailable such as someone shutting off a switch. My scenes and automations used to run fine even if some devices weren’t able to respond. Now they just fail.

tom_l · July 18, 2023, 2:24pm

Nothing that would cause this.

Search this page for “ZHA”: Full Changelog for Home Assistant Core 2023.7 - Home Assistant

kurtzettel · July 18, 2023, 2:42pm

I’m gonna keep an eye on:

github.com/home-assistant/core

new Fault with 2023.7.0b...

opened 11:16AM - 01 Jul 23 UTC

criticallimit

integration: zha

### The problem ``` Logger: homeassistant.components.automation.kuche_licht_au…s Source: components/zha/light.py:471 Integration: Automatisierung (documentation, issues) First occurred: 11:26:17 (2 occurrences) Last logged: 11:26:17 Küche Licht aus: Error executing script. Unexpected error for call_service at pos 1: While executing automation automation.kuche_licht_aus Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/zigpy/device.py", line 310, in request return await req.result ^^^^^^^^^^^^^^^^ asyncio.exceptions.CancelledError The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 468, in _async_step await getattr(self, handler)() File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 703, in _async_call_service_step response_data = await self._async_run_long_action( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 665, in _async_run_long_action return long_task.result() ^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/core.py", line 1957, in async_call response_data = await coro ^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/core.py", line 1997, in _execute_service return await cast( ^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 235, in handle_service return await service.entity_service_call( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 833, in entity_service_call response_data = task.result() # pop exception if have ^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1191, in async_request_call return await coro ^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 877, in _handle_entity_call result = await task ^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/components/light/__init__.py", line 593, in async_handle_light_off_service await light.async_turn_off(**filter_turn_off_params(light, params)) File "/usr/src/homeassistant/homeassistant/components/zha/light.py", line 471, in async_turn_off result = await self._on_off_cluster_handler.off() ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/zigpy/util.py", line 132, in retry return await func() ^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/zigpy/zcl/__init__.py", line 375, in request return await self._endpoint.request( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/zigpy/endpoint.py", line 253, in request return await self.device.request( ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/zigpy/device.py", line 309, in request async with asyncio_timeout(timeout): File "/usr/local/lib/python3.11/asyncio/timeouts.py", line 111, in __aexit__ raise TimeoutError from exc_val TimeoutError ``` ### What version of Home Assistant Core has the issue? 2023.7.0b3 ### What was the last working version of Home Assistant Core? 2023.6.... ### What type of installation are you running? Home Assistant OS ### Integration causing the issue ZHA ### Link to integration documentation on our website _No response_ ### Diagnostics information _No response_ ### Example YAML snippet _No response_ ### Anything in the logs that might be useful for us? _No response_ ### Additional information _No response_

This issue seems close. My automation probably always had an error. My guess is that the new “Responding Services” returns an error now.

c0ntax · July 19, 2023, 7:59am

To update, I amended my automation to include delays between each service call of zigbee groups and it failed again last night, with the same error received.

I’m also confused as to why there may be too many zigbee calls when there are only 3 together in the automation so that can’t be overloading it, can it?

Another odd thing is, as I mentioned in my OP, if I temporarily change the timeframe condition to allow me to test it, so from 08:00 instead of 22:00 such as I did again this morning, the automation runs fine and as expected.

Third odd behaviour is, the automation doesn’t fail as a whole as would be expected. What I mean by this is, there are 6 service calls in the script. The first 2 calls run but service calls 3 and 4 do not. However, the last two do run which I wouldn’t expect because I always believed that an automation would stop running the rest of itself at the point it failed and not continue to call further services.

I’ve now changed the zigbee channel on my SkyConnect to see if that resolves it and will wait until tonight to see, failing that I’ll have to open a GITHub issue if it doesn’t.

This has only been happening since upgrade to Core 2023.7.2 and I am finding other devices acting weirdly also, such as a specific non-zigbee (wifi) device constantly becoming unavailable to the point I have to delete it and re-pair it every day. Plus the same zigbee overload errors on single devices in single call scripts.

EDIT: @kurtzettel I’ve just commented on that Github issue thread as it’s strange most of the issues people are logging there are night time zigbee automations which is similar to what I’ve found above that if I change the time to run the automation in the morning, it works but change it back to nighttime and run it, it doesn’t. The example you posted above is also run at night?

c0ntax · July 20, 2023, 8:22am

Further update - I changed zigbee (and thread) channel on my multi-protocol SkyConnect yesterday and the automation worked as expected last night.

Not sure if that’s coincidence or what…

But it is odd others are reporting similar issues since upgrade and mainly on night time automations.

nicknol · July 31, 2023, 6:05pm

Did anyone raise an issue in github? I can’t see any open issue that looks like what you describe.

Please help the community by raising an issue and providing logs and insights.

Thanks!

c0ntax · August 1, 2023, 8:17am

Yes, kurtzettel has linked to one above in post #6. That Github issue has been acknowledged and closed by devs and merged with another https://github.com/home-assistant/core/pull/97033

nicknol · August 1, 2023, 4:14pm

yes, the issue mentioned by kurtzettel was about something in the beta of 2023.7.
yes, it is marked as fixed. but as far as I can read it is about handling/suppressing the exception.

Let’s wait for the next patch or release and cross fingers