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
289 stars 41 forks source link

Entity Controller stuck in 'active' state #305

Closed Blackbird714 closed 10 months ago

Blackbird714 commented 11 months ago

Description

I have created an entity controller that uses state_entities and scripts to handle on/off for a Govee light strip from SmartThings. I'm using scripts because I'm also using adaptive lighting to manage sleep/color/brightness for the same light.

I'm following a pattern that worked for other lights in my installation, but for just this one EC instance, the EC entity is getting stuck in 'active' state. According to the docs, this is a "momentary, internal state" and my other EC's all behave as described.

As a troubleshooting step, I've tried restarting HA, but the entity seems to always return to the stuck 'active' state. I went so far as uninstalling Entity Controller and reinstalling; shortly after reconfiguring, the behavior returned.

When I can get the problem EC back to idle, when the sensor is triggered, the EC goes to 'active' and says there. I've also observed that if an override is 'on' after reboot the EC goes to 'overridden' and stays there until turned off. But a sensor trigger always seems to end up with the same result (stuck in 'active').

Once stuck in 'active' state, switching to override doesn't work too; I see this message in the logs:

transitions.core.MachineError: "Can't trigger event 'override' from state(s) active!"

This feels like a deadlock or race condition, but I haven't been able to find a good way to isolate root cause.

Configuration

motion_mbr_floor_light:
  sensors:
    - binary_sensor.motion_sensor_master_br_motion
  state_entities:
    - input_boolean.light_state_mbr_floor
  delay: 300
  overrides:
    - input_boolean.adequate_light_back
  sensor_type: duration
  sensor_resets_timer: True
  behaviours:
    on_enter_overridden: "off"
  state_attributes_ignore:
    - brightness
    - color_temp
  trigger_on_activate: reset_al_activate_mbr_floor_light
  trigger_on_deactivate: reset_al_deactivate_mbr_floor_light

Steps to reproduce

Steps to reproduce the behavior:

  1. Establish starting state for test: lights and overrides off, EC state idle
  2. Trigger motion sensor

Expected behavior

This is how the component should work:

  1. Script runs to turn on lights
  2. EC state goes to blocked per state_entities state

Actual Behaviour

This is what actually happened:

  1. Script runs to turn on lights but fails (script works when directly executed)
  2. EC state goes to active and remains there until restarting HA (which sometimes does not seem to work)

Logs

2023-08-16 09:08:51.297 DEBUG (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] sensor_state_change :: 'binary_sensor.motion_sensor_master_br_motion' Sensor state change to: on
2023-08-16 09:08:51.297 DEBUG (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] sensor_state_change :: state: 'idle'
2023-08-16 09:08:51.298 INFO (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] <state input_boolean.light_state_mbr_floor=off; editable=True, icon=mdi:lightbulb-auto, friendly_name=Light State Master Bedroom Floor @ 2023-08-16T09:06:47.836299-04:00>
2023-08-16 09:08:51.298 DEBUG (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] State entities are OFF.
2023-08-16 09:08:51.298 DEBUG (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] Exiting idle
2023-08-16 09:08:51.299 DEBUG (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] on_exit_idle | Performing Transition Behaviour
2023-08-16 09:08:51.299 DEBUG (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] on_exit_idle | Action - ignore
2023-08-16 09:08:51.299 DEBUG (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] Entering active
2023-08-16 09:08:51.299 DEBUG (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] Using DAY MODE parameters: {'delay': 300, 'service_data': None, 'service_data_off': None}
2023-08-16 09:08:51.299 INFO (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] _start_timer :: Light params: {'delay': 300, 'service_data': None, 'service_data_off': None}
2023-08-16 09:08:51.305 DEBUG (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] on_enter_active :: light params before turning on: {'delay': 300, 'service_data': None, 'service_data_off': None}
2023-08-16 09:08:51.305 DEBUG (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] on_enter_active | Performing Transition Behaviour
2023-08-16 09:08:51.305 DEBUG (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] on_enter_active | Action - on
2023-08-16 09:08:51.306 DEBUG (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] on_enter_active | Performing Action - Turning on
2023-08-16 09:08:51.306 INFO (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] handleTriggerOnActivateEntities :: Triggering Activation entities (Yes! params passed along)
2023-08-16 09:08:51.306 DEBUG (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] Turning on reset_al_activate_mbr_floor_light (no parameters provided to pass to service call)
2023-08-16 09:08:51.306 DEBUG (MainThread) [custom_components.entity_controller.motion_mbr_floor_light] call_service :: Calling service turn_on on reset_al_activate_mbr_floor_light
2023-08-16 09:08:51.307 ERROR (MainThread) [homeassistant.helpers.event] Error while dispatching event for binary_sensor.motion_sensor_master_br_motion to <Job track state_changed event ['binary_sensor.motion_sensor_master_br_motion'] HassJobType.Callback <function async_track_state_change.<locals>.state_change_listener at 0x7f77ecbe4ea0>>
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/event.py", line 289, in _async_dispatch_entity_id_event
    hass.async_run_hass_job(job, event)
  File "/usr/src/homeassistant/homeassistant/core.py", line 625, in async_run_hass_job
    hassjob.target(*args)
  File "/usr/src/homeassistant/homeassistant/helpers/event.py", line 235, in state_change_listener
    state_change_dispatcher(event)
  File "/usr/src/homeassistant/homeassistant/helpers/event.py", line 222, in state_change_dispatcher
    hass.async_run_hass_job(
  File "/usr/src/homeassistant/homeassistant/core.py", line 625, in async_run_hass_job
    hassjob.target(*args)
  File "/config/custom_components/entity_controller/__init__.py", line 589, in sensor_state_change
    self.sensor_on()
  File "/usr/local/lib/python3.11/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.11/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.11/site-packages/transitions/extensions/nesting.py", line 112, in trigger
    return _machine._process(func)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/transitions/core.py", line 1172, in _process
    return trigger()
           ^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/transitions/extensions/nesting.py", line 127, in _trigger
    res = self._process(event_data)
          ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/transitions/extensions/nesting.py", line 143, in _process
    if trans.execute(event_data):
       ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/transitions/core.py", line 272, in execute
    self._change_state(event_data)
  File "/usr/local/lib/python3.11/site-packages/transitions/extensions/nesting.py", line 276, in _change_state
    func()
  File "/usr/local/lib/python3.11/site-packages/transitions/extensions/nesting.py", line 205, in scoped_enter
    self.enter(event_data)
  File "/usr/local/lib/python3.11/site-packages/transitions/core.py", line 124, in enter
    event_data.machine.callbacks(self.on_enter, event_data)
  File "/usr/local/lib/python3.11/site-packages/transitions/core.py", line 1107, in callbacks
    self.callback(func, event_data)
  File "/usr/local/lib/python3.11/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 879, in on_enter_active
    self.do_transition_behaviour(CONF_ON_ENTER_ACTIVE)
  File "/config/custom_components/entity_controller/__init__.py", line 1748, in do_transition_behaviour
    self.turn_on_control_entities()
  File "/config/custom_components/entity_controller/__init__.py", line 1273, in turn_on_control_entities
    self.handleTriggerOnActivateEntities()
  File "/config/custom_components/entity_controller/__init__.py", line 1270, in handleTriggerOnActivateEntities
    self.call_service(e, "turn_on")
  File "/config/custom_components/entity_controller/__init__.py", line 1537, in call_service
    domain, e = entity.split(".")
    ^^^^^^^^^
ValueError: not enough values to unpack (expected 2, got 1)

Version

9.6.1

2023-08-16 09:06:55.130 DEBUG (MainThread) [custom_components.hacs] <Integration danobot/entity-controller> Running checks against v9.6.1
Blackbird714 commented 11 months ago

Ok, I finally spotted my error; these lines in my EC config:

  trigger_on_activate: reset_al_activate_mbr_floor_light
  trigger_on_deactivate: reset_al_deactivate_mbr_floor_light

... it was missing the script. prefix. This should have been:

  trigger_on_activate: script.reset_al_activate_mbr_floor_light
  trigger_on_deactivate: script.reset_al_deactivate_mbr_floor_light

Sometimes you cannot see the forest for the trees!

danobot commented 10 months ago

Yeah, good spot! I saw the error message and came to the same conclusion. Would be nice to ahve better input validation and error messages. Closing this issue