danobot / entity-controller

Home Assistant Entity and lighting controller for managing devices with timers, scripts, and sun-based time restrictions.
https://danobot.github.io/ec-docs/
GNU General Public License v3.0
294 stars 40 forks source link

Error after updating HA 2024.05 #326

Closed stefanoferrario closed 5 months ago

stefanoferrario commented 5 months ago

After updating to the last Home Assistant version 2024.05 I'm getting this issue described in log. Entity controller status is "pending" for all entities.


Traceback (most recent call last):
  File "/usr/local/lib/python3.12/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/entity_controller/__init__.py", line 571, in startup_delay_callback
    self.config_times(config)
  File "/config/custom_components/entity_controller/__init__.py", line 1134, in config_times
    self.update(start=self.start_time)
  File "/config/custom_components/entity_controller/__init__.py", line 589, in update
    self.entity.do_update()
  File "/config/custom_components/entity_controller/__init__.py", line 482, in do_update
    self.async_schedule_update_ha_state(True)
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1252, in async_schedule_update_ha_state
    self.hass.async_create_task(
  File "/usr/src/homeassistant/homeassistant/core.py", line 816, in async_create_task
    self.verify_event_loop_thread("async_create_task")
  File "/usr/src/homeassistant/homeassistant/core.py", line 440, in verify_event_loop_thread
    frame.report(
  File "/usr/src/homeassistant/homeassistant/helpers/frame.py", line 162, in report
    _report_integration(what, integration_frame, level, error_if_integration)
  File "/usr/src/homeassistant/homeassistant/helpers/frame.py", line 203, in _report_integration
    raise RuntimeError(
RuntimeError: Detected that custom integration 'entity_controller' calls async_create_task from a thread at custom_components/entity_controller/__init__.py, line 482: self.async_schedule_update_ha_state(True). Please report it to the author of the 'entity_controller' custom integration
hvorragend commented 5 months ago

Same here

mikeage commented 5 months ago

As a quick workaround, I believe this should work:

diff --git a/custom_components/entity_controller/__init__.py b/custom_components/entity_controller/__init__.py
index 2849bcc..348b453 100644
--- a/custom_components/entity_controller/__init__.py
+++ b/custom_components/entity_controller/__init__.py
@@ -479,7 +479,8 @@ class EntityController(entity.Entity):
         """ Schedules an entity state update with HASS """
         # _LOGGER.debug("Scheduled update with HASS")
         if self.may_update:
-            self.async_schedule_update_ha_state(True)
+            # self.async_schedule_update_ha_state(True)
+            self.schedule_update_ha_state(True)

     def set_attr(self, k, v):
         if k == CONF_DELAY:

But the proper fix is to make more things async, I think, not fewer.

Note that there are still two other warnings: one about event.async_track_state_change vs event.async_track_state_change_event (I opened a PR for this one), and another about calling async_create_task from a thread (I don't know the proper way to fix this one). But it no longer stays in pending, and EC is functional at least.

stefanoferrario commented 5 months ago

Using this workaround I confirm entity control status changed in “constrained” again. I think it is working correctly now but I will check during the evening/night.

I will wait for a next release in order to solve the issue definitively. Thanks

robchandhok commented 5 months ago

@mikeage thank you for this comment and PR #327 for the other issue. I've tested both together and I think called schedule_update_ha_state instead of the async version is actually a fine fix. Core is just calling it in a thread now?

With your two fixes I get zero warnings with 2024.5.1

stefanoferrario commented 5 months ago

I have done some tests and I noticed that (in my case with light) the entity is switched on on trigger event but then after some time (defined by the timer) status changed in idle but lights didn't switch off.

Maybe I have done some mistake fixing the issue...

stefanoferrario commented 5 months ago

Here the log with the error when timer ends:

Traceback (most recent call last):
  File "/usr/local/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.12/threading.py", line 1431, in run
    self.function(*self.args, **self.kwargs)
  File "/config/custom_components/entity_controller/__init__.py", line 767, in timer_expire
    self.timer_expires()
  File "/usr/local/lib/python3.12/site-packages/transitions/extensions/nesting.py", line 816, in trigger_event
    res = self._trigger_event(_model, _trigger, None, *args, **kwargs)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/transitions/extensions/nesting.py", line 1016, in _trigger_event
    tmp = self.events[_trigger].trigger(_model, self, *args, **kwargs)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/transitions/extensions/nesting.py", line 112, in trigger
    return _machine._process(func)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/transitions/core.py", line 1172, in _process
    return trigger()
           ^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/transitions/extensions/nesting.py", line 127, in _trigger
    res = self._process(event_data)
          ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/transitions/extensions/nesting.py", line 143, in _process
    if trans.execute(event_data):
       ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/transitions/core.py", line 272, in execute
    self._change_state(event_data)
  File "/usr/local/lib/python3.12/site-packages/transitions/extensions/nesting.py", line 276, in _change_state
    func()
  File "/usr/local/lib/python3.12/site-packages/transitions/extensions/nesting.py", line 205, in scoped_enter
    self.enter(event_data)
  File "/usr/local/lib/python3.12/site-packages/transitions/core.py", line 124, in enter
    event_data.machine.callbacks(self.on_enter, event_data)
  File "/usr/local/lib/python3.12/site-packages/transitions/core.py", line 1107, in callbacks
    self.callback(func, event_data)
  File "/usr/local/lib/python3.12/site-packages/transitions/core.py", line 1128, in callback
    func(*event_data.args, **event_data.kwargs)
  File "/config/custom_components/entity_controller/__init__.py", line 895, in on_enter_idle
    self.do_transition_behaviour(CONF_ON_ENTER_IDLE)
  File "/config/custom_components/entity_controller/__init__.py", line 1805, in do_transition_behaviour
    self.turn_off_control_entities()
  File "/config/custom_components/entity_controller/__init__.py", line 1342, in turn_off_control_entities
    self.call_service(e, "turn_off")
  File "/config/custom_components/entity_controller/__init__.py", line 1586, in call_service
    self.hass.async_create_task(
  File "/usr/src/homeassistant/homeassistant/core.py", line 816, in async_create_task
    self.verify_event_loop_thread("async_create_task")
  File "/usr/src/homeassistant/homeassistant/core.py", line 440, in verify_event_loop_thread
    frame.report(
  File "/usr/src/homeassistant/homeassistant/helpers/frame.py", line 162, in report
    _report_integration(what, integration_frame, level, error_if_integration)
  File "/usr/src/homeassistant/homeassistant/helpers/frame.py", line 203, in _report_integration
    raise RuntimeError(
RuntimeError: Detected that custom integration 'entity_controller' calls async_create_task from a thread at custom_components/entity_controller/__init__.py, line 1586: self.hass.async_create_task(. Please report it to the author of the 'entity_controller' custom integration.
robchandhok commented 5 months ago

@stefanoferrario you might try taking all the changes in the other PR referenced (#327). Take that whole file as your new baseline and then also the one line patch, that's what I'm testing. If you are comfortable with doing that.

stefanoferrario commented 5 months ago

I replaced the file and then I replace again self.async_schedule_update_ha_state(True) with self.schedule_update_ha_state(True). Still having the issue mentioned above. Switch off is not triggered at the end of timer. I have the error described in log above

robchandhok commented 5 months ago

Ok, bene. I will see if I get the error tonight as well. It looks like it should be calling the non-async version of create_task now.

blefevre commented 5 months ago

The second error can be resolved by replacing the call to async_create_task with asyncio.run_coroutine_threadsafe as in the following patch:

diff --git a/custom_components/entity_controller/__init__.py b/custom_components/entity_controller/__init__.py
index 2849bcc..ac20642 100644
--- a/custom_components/entity_controller/__init__.py
+++ b/custom_components/entity_controller/__init__.py
@@ -22,6 +22,7 @@ Version:          v9.7.3
 Project Page:     https://danielbkr.net/projects/entity-controller/
 Documentation:    https://github.com/danobot/entity-controller
 """
+import asyncio
 import hashlib
 import logging
 import re
@@ -1573,8 +1574,9 @@ class Model:
             params = service_data

         params["entity_id"] = entity
-        self.hass.async_create_task(
-            self.hass.services.async_call(domain, service, service_data, context=self.context)
+        asyncio.run_coroutine_threadsafe(
+            self.hass.services.async_call(domain, service, service_data, context=self.context),
+            self.hass.loop
         )
         self.update(service_data=service_data)

This plus the patch from @mikeage has fixed my EC integration.

danobot commented 5 months ago

Thanks for investigating and resolving all these issues, I released a new version incl @mikeage and @blefevre fixes. See 9.7.5

danobot commented 5 months ago

I had to make another change in #332 to resolve it as an emergency fix. Let me know if there are any issues with making that call synchronous or if it should use asyncio instead.

robchandhok commented 5 months ago

working well for me! (9.7.6)

dominicusmento commented 5 months ago

works for me too (v9.7.6). thanks for support @danobot