search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
71.34k stars 29.88k forks source link

Error while executing automation #107974

Closed for-anurag closed 7 months ago

for-anurag commented 8 months ago

The problem

Suddenly there are very frequent automation failures. Please see the details mentioned in logs section. I tried restarting HA couple of times but issue persists.

What version of Home Assistant Core has the issue?

2024.1.3

What was the last working version of Home Assistant Core?

What type of installation are you running?

Home Assistant Core

Integration causing the issue

No response

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?

Logger: bellows.ezsp
Source: runner.py:188
First occurred: 22:32:35 (2 occurrences)
Last logged: 22:32:35

NCP entered failed state. Requesting APP controller restart

Logger: homeassistant.components.automation.living_room_lights_dimmer
Source: helpers/script.py:1792
Integration: Automation (documentation, issues)
First occurred: 22:32:39 (4 occurrences)
Last logged: 22:32:39

Living Room Lights Dimmer: Choose at step 4: choice 3: Choose at step 2: choice 1: Repeat at step 1: Error executing script. Error for call_service at pos 2: Failed to send request: ApplicationController is not running
Living Room Lights Dimmer: Choose at step 4: choice 3: Choose at step 2: choice 1: Error executing script. Error for repeat at pos 1: Failed to send request: ApplicationController is not running
Living Room Lights Dimmer: Choose at step 4: choice 3: Error executing script. Error for choose at pos 2: Failed to send request: ApplicationController is not running
Living Room Lights Dimmer: Error executing script. Error for choose at pos 4: Failed to send request: ApplicationController is not running

Additional information

No response

home-assistant[bot] commented 8 months ago

Hey there @home-assistant/core, mind taking a look at this issue as it has been labeled with an integration (automation) you are listed as a code owner for? Thanks!

Code owner commands Code owners of `automation` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign automation` Removes the current integration label and assignees on the issue, add the integration domain after the command. - `@home-assistant add-label needs-more-information` Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue. - `@home-assistant remove-label needs-more-information` Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

(message by CodeOwnersMention)

automation documentation automation source (message by IssueLinks)

mib1185 commented 8 months ago

please provide the automation code. it seems there is a service call, where the called service provider (an integration) returns the error ApplicationController is not running ... which service is called and which integration provide it?

for-anurag commented 8 months ago

please provide the automation code. it seems there is a service call, where the called service provider (an integration) returns the error ApplicationController is not running ... which service is called and which integration provide it?

Here is the automation code: Ikea Symfonisk.yaml.txt

This is the implementation of the code:

alias: Living Room Lights Dimmer
description: ""
use_blueprint:
  path: anuragkumar-dev/ikea_e1744_symfonisk.yaml
  input:
    integration: ZHA
    controller_device: 2b7950014d2028af443686c7eb476859
    helper_last_controller_event: input_text.living_room_lights_dimmer_last_controller_event
    action_rotate_left:
      - parallel:
          - device_id: 42f55cd6972e88fb65ebedb1f18682cd
            domain: light
            entity_id: a8821564d05cdbb16e36292a5385c27a
            type: brightness_decrease
            enabled: false
        enabled: true
      - service: light.turn_on
        data:
          transition: 1
          brightness_step: -10
        target:
          entity_id:
            - light.dining_table_lamp_light
            - light.dining_table_ceiling_light
            - light.tv_under_cabinet_lights_light
            - light.tv_cabinet_lights_light
            - light.white_cabinet_lights_light
            - light.coffee_table_ceiling_light
            - light.picture_focus_light
    action_rotate_right:
      - parallel:
          - device_id: 42f55cd6972e88fb65ebedb1f18682cd
            domain: light
            entity_id: a8821564d05cdbb16e36292a5385c27a
            type: brightness_increase
            enabled: false
        enabled: true
      - service: light.turn_on
        data:
          transition: 1
          brightness_step: 10
        target:
          entity_id:
            - light.dining_table_lamp_light
            - light.dining_table_ceiling_light
            - light.tv_under_cabinet_lights_light
            - light.tv_cabinet_lights_light
            - light.white_cabinet_lights_light
            - light.coffee_table_ceiling_light
            - light.picture_focus_light
    rotate_left_loop: true
    rotate_right_loop: true
    action_click_short:
      - service: input_boolean.turn_on
        data: {}
        target:
          entity_id: input_boolean.ha_sim_bright_lights
    action_click_double:
      - service: input_boolean.turn_on
        data: {}
        target:
          entity_id: input_boolean.ha_sim_dim_lights
for-anurag commented 8 months ago

Here is a more detailed log details that I can see this time in chronological order:

for-anurag commented 8 months ago

Logger: bellows.ezsp Source: runner.py:188 First occurred: 10:56:21 AM (1 occurrences) Last logged: 10:56:21 AM

NCP entered failed state. Requesting APP controller restart

for-anurag commented 8 months ago 
Logger: homeassistant.components.automation.living_room_lights_dimmer
Source: helpers/script.py:476
Integration: Automation (documentation, issues)
First occurred: 10:56:25 AM (4 occurrences)
Last logged: 10:56:25 AM

Living Room Lights Dimmer: Choose at step 4: choice 1: Choose at step 2: choice 1: Repeat at step 1: Error executing script. Unexpected error for call_service at pos 2: 'NoneType' object has no attribute 'sendUnicast'
Living Room Lights Dimmer: Choose at step 4: choice 1: Choose at step 2: choice 1: Error executing script. Unexpected error for repeat at pos 1: 'NoneType' object has no attribute 'sendUnicast'
Living Room Lights Dimmer: Choose at step 4: choice 1: Error executing script. Unexpected error for choose at pos 2: 'NoneType' object has no attribute 'sendUnicast'
Living Room Lights Dimmer: Error executing script. Unexpected error for choose at pos 4: 'NoneType' object has no attribute 'sendUnicast'
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 476, in _async_step
    await getattr(self, handler)()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 713, in _async_call_service_step
    response_data = await self._async_run_long_action(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 675, in _async_run_long_action
    return long_task.result()
           ^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2149, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2186, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 272, in handle_service
    return await service.entity_service_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 907, in entity_service_call
    raise result from None
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1497, in async_request_call
    return await coro
           ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 952, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/light/__init__.py", line 624, 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 336, in async_turn_on
    result = await self._level_cluster_handler.move_to_level_with_on_off(
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 84, in wrapper
    return await RETRYABLE_REQUEST_DECORATOR(func)(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/zigpy/util.py", line 137, in retry
    return await func()
           ^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/zigpy/zcl/__init__.py", line 377, 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 322, in request
    await send_request
  File "/usr/local/lib/python3.11/site-packages/zigpy/application.py", line 833, in request
    await self.send_packet(
  File "/usr/local/lib/python3.11/site-packages/bellows/zigbee/application.py", line 868, in send_packet
    status, _ = await self._ezsp.sendUnicast(
                      ^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'sendUnicast'
for-anurag commented 8 months ago 
Logger: homeassistant.components.automation.living_room_lights_dimmer
Source: components/automation/__init__.py:669
Integration: Automation (documentation, issues)
First occurred: 10:56:25 AM (1 occurrences)
Last logged: 10:56:25 AM

While executing automation automation.living_room_lights_dimmer
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/automation/__init__.py", line 669, in async_trigger
    await self.action_script.async_run(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1587, in async_run
    return await asyncio.shield(run.async_run())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 426, in async_run
    await self._async_step(log_exceptions=False)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 479, in _async_step
    self._handle_exception(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 502, in _handle_exception
    raise exception
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 476, in _async_step
    await getattr(self, handler)()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 933, in _async_choose_step
    await self._async_run_script(script)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1078, in _async_run_script
    await self._async_run_long_action(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 675, in _async_run_long_action
    return long_task.result()
           ^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1587, in async_run
    return await asyncio.shield(run.async_run())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 426, in async_run
    await self._async_step(log_exceptions=False)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 479, in _async_step
    self._handle_exception(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 502, in _handle_exception
    raise exception
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 476, in _async_step
    await getattr(self, handler)()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 933, in _async_choose_step
    await self._async_run_script(script)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1078, in _async_run_script
    await self._async_run_long_action(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 675, in _async_run_long_action
    return long_task.result()
           ^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1587, in async_run
    return await asyncio.shield(run.async_run())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 426, in async_run
    await self._async_step(log_exceptions=False)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 479, in _async_step
    self._handle_exception(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 502, in _handle_exception
    raise exception
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 476, in _async_step
    await getattr(self, handler)()
  File "/usr/src/homeassistant/homeassistant/helpers/trace.py", line 272, in async_wrapper
    await func(*args)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 898, in _async_repeat_step
    await async_run_sequence(iteration)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 832, in async_run_sequence
    await self._async_run_script(script)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1078, in _async_run_script
    await self._async_run_long_action(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 675, in _async_run_long_action
    return long_task.result()
           ^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1587, in async_run
    return await asyncio.shield(run.async_run())
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 426, in async_run
    await self._async_step(log_exceptions=False)
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 479, in _async_step
    self._handle_exception(
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 502, in _handle_exception
    raise exception
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 476, in _async_step
    await getattr(self, handler)()
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 713, in _async_call_service_step
    response_data = await self._async_run_long_action(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 675, in _async_run_long_action
    return long_task.result()
           ^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2149, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2186, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 272, in handle_service
    return await service.entity_service_call(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 907, in entity_service_call
    raise result from None
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1497, in async_request_call
    return await coro
           ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 952, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/light/__init__.py", line 624, 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 336, in async_turn_on
    result = await self._level_cluster_handler.move_to_level_with_on_off(
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/zha/core/cluster_handlers/__init__.py", line 84, in wrapper
    return await RETRYABLE_REQUEST_DECORATOR(func)(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/zigpy/util.py", line 137, in retry
    return await func()
           ^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/zigpy/zcl/__init__.py", line 377, 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 322, in request
    await send_request
  File "/usr/local/lib/python3.11/site-packages/zigpy/application.py", line 833, in request
    await self.send_packet(
  File "/usr/local/lib/python3.11/site-packages/bellows/zigbee/application.py", line 868, in send_packet
    status, _ = await self._ezsp.sendUnicast(
                      ^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'sendUnicast'
for-anurag commented 8 months ago

Full log download attached as well:

home-assistant_2024-01-14T07-08-26.884Z.log

smarthomefamilyverrips commented 8 months ago

Maybe stupid question, but are all devices in your automation still available in HA? When now and then at me a automation fails it is always because one of the devices in the automation not is connected anymore (mostly a zigbee light/switch became unavailable in ZHA in my case)

home-assistant[bot] commented 8 months ago

Hey there @dmulcahey, @adminiuga, @puddly, @thejulianjes, 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!

Code owner commands Code owners of `zha` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign zha` Removes the current integration label and assignees on the issue, add the integration domain after the command. - `@home-assistant add-label needs-more-information` Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue. - `@home-assistant remove-label needs-more-information` Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

(message by CodeOwnersMention)

zha documentation zha source (message by IssueLinks)

for-anurag commented 8 months ago

Maybe stupid question, but are all devices in your automation still available in HA? When now and then at me a automation fails it is always because one of the devices in the automation not is connected anymore (mostly a zigbee light/switch became unavailable in ZHA in my case)

I can see all zigbee devices available. The issue occurs randomly. The automation trigger is a zigbee remote rotary switch (Ikea Symfonisk). While im rotating the switch, all zigbee lights part of the automation increases or decreases in brightness, however, suddenly the operation stops responding (birghtness of none of the lights are seen changing anymore). It is when there is an error thrown in the logs. After waiting for a while again the automation starts working on rotating the switch.

for-anurag commented 8 months ago

I was under impression that core 2024.1.2 had no.such issue, but its happening in this version as well. Now ive lost track since when it started happening.

smarthomefamilyverrips commented 8 months ago

Not says it will help but maybe if possible try power cycle all devices in automation once in case there still would be some connectivity issues 🤔

for-anurag commented 8 months ago

Not says it will help but maybe if possible try power cycle all devices in automation once in case there still would be some connectivity issues 🤔

Yeah, true, many times power recycling does fixes strange behaviours! Unfortunately, this time it didn't. I power recycled whole home power supply including removing the battery of the remote and putting it back.

issue-triage-workflows[bot] commented 7 months 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 Home Assistant 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.