Scheduled action does not take place on end device

[rahulpdev]

Checklist

• [x] I checked for similar existing issues (both open and closed) before posting.
• [x] I am running the latest version.

Expected behavior

At the set time in my schedule I expect the end device to change state based on what was set in the schedule. In my example the schedule is defined that at 08:00:00 the device should change from heat mode to turn off mode.

Actual behavior

Although the schedule changes its state from turned on to triggered there is no corresponding event in the logs of the device and it does not change its state.

Log of the schedule: Closet weekday turned on 8:01:00 AM Closet weekday changed to triggered 8:00:00 AM Closet weekday turned on triggered by service switch.turn_on 7:14:43 AM Closet weekday turned off triggered by service switch.turn_off 7:14:37 AM Closet weekday turned on 5:01:00 AM Closet weekday changed to triggered 5:00:00 AM Closet weekday turned on 12:01:00 AM

Log of the device Closet radiator Thermostat turned off triggered by service climate.set_hvac_mode 3:06:02 PM Closet radiator Thermostat changed to Heat triggered by service climate.set_temperature 5:00:04 AM

Steps to Reproduce

In my case the attached schedule is controlling an Aqara lumi.airrtc.agl001 E1 radiatior valve.

[nielsfaber]

You can enable debug logging by adding this to configuration.yaml:

logger:
  default: warning
  logs:
    custom_components.scheduler: debug

You will need to restart HA afterwards.

After enabling debug logging the scheduler component should add additional lines in the HA logs on the scheduled time. These lines should help pinpointing the issue.

Could you please try this and share the results?

[rahulpdev]

I added the above code to my configuration.yaml and restarted HA but I'm not sure I'm getting additional lines in my logbook. Below is the latest from this morning. The underlying issue occurs intermittently but seems to occur most often at 08:00 when 7 of my 8 TRVs switch off at the same moment. It seems this large number of actions is in itself a problem as 1 or more actions don't always occur as scheduled. When fewer TRVs, say 3 or 4, are triggered at the same moment the issue does not seem as prevalent (this is anecdotal).

This morning the same actions that are in the logbook below for the Ensuite radiator should have occurred for the Main bedroom radiator but they did not occur and the TRV stayed on when it should have switched off.

Closet weekday turned on 8:01:00 AM - 5 hours ago

Kids bedroom weekday turned on 8:01:00 AM - 5 hours ago

Main bedroom weekday turned on 8:01:00 AM - 5 hours ago

Guest bedroom weekday turned on 8:01:00 AM - 5 hours ago

Boiler weekday turned on 8:01:00 AM - 5 hours ago

Study weekday turned on 8:01:00 AM - 5 hours ago

Ensuite weekday turned on 8:01:00 AM - 5 hours ago

Bathroom weekday turned on 8:01:00 AM - 5 hours ago

Bathroom radiator Thermostat turned off triggered by service climate.set_hvac_mode 8:00:04 AM - 5 hours ago

Bathroom radiator HVAC action turned off 8:00:04 AM - 5 hours ago

Kids bedroom radiator Thermostat turned off triggered by service climate.set_hvac_mode 8:00:02 AM - 5 hours ago

Kids bedroom radiator HVAC action turned off 8:00:02 AM - 5 hours ago

Ensuite radiator Thermostat turned off triggered by service climate.set_hvac_mode 8:00:02 AM - 5 hours ago

Ensuite radiator HVAC action turned off 8:00:02 AM - 5 hours ago

Closet weekday changed to triggered 8:00:00 AM - 5 hours ago

Kids bedroom weekday changed to triggered 8:00:00 AM - 5 hours ago

Main bedroom weekday changed to triggered 8:00:00 AM - 5 hours ago

Guest bedroom weekday changed to triggered 8:00:00 AM - 5 hours ago

Boiler weekday changed to triggered 8:00:00 AM - 5 hours ago

Study weekday changed to triggered 8:00:00 AM - 5 hours ago

Ensuite weekday changed to triggered 8:00:00 AM - 5 hours ago

Bathroom weekday changed to triggered 8:00:00 AM - 5 hours ago

[rahulpdev]

@nielsfaber

[nielsfaber]

I am not looking for logbook information, I meant the HA log: https://www.home-assistant.io/integrations/system_log/

[j-f-d]

I think I see something similar. I'm using the mqtt integration with zigbee2mqtt. The sensor I use is a BHT-002. Although the scheduler sets the new temperature in the device, it fails to update the HVAC mode. So if the schedule is set to Heat to 21C and the control is set to 5C and Off, then the control temperature setpoint will be changed to 21C, but remain Off. Similarly if the schedule changes to Turn Off, the control remains set to Heat.

I have a work-around where I add a script for the control, such that on temperature setpoint change the HVAC mode is set to Heat. Then rather than turn off the device, I set it to 5C. The script looks like:

alias: Heat on temperature change
sequence:
  - device_id: 1f320b061c0974c6c3f7f42b729533ae
    domain: climate
    entity_id: climate.0x8cf681fffe56710f
    type: set_hvac_mode
    hvac_mode: heat
mode: single

I don't know if it is related, but I'm getting MQTT errors in the system log:

Logger: homeassistant
Source: core.py:1144
First occurred: 4 March 2023 at 11:02:27 (190950 occurrences)
Last logged: 10:32:45

Error doing job: Exception in callback MQTT._mqtt_handle_message(<paho.mqtt.cl...x7f07f3e900b0>)
Error doing job: Exception in callback MQTT._mqtt_handle_message(<paho.mqtt.cl...x7f07f33f6570>)
Error doing job: Exception in callback MQTT._mqtt_handle_message(<paho.mqtt.cl...x7f07f7977b50>)
Error doing job: Exception in callback MQTT._mqtt_handle_message(<paho.mqtt.cl...x7f07f34ee1f0>)
Error doing job: Exception in callback MQTT._mqtt_handle_message(<paho.mqtt.cl...x7f07f34edd20>)
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/usr/src/homeassistant/homeassistant/components/mqtt/client.py", line 693, in _mqtt_handle_message
    self._mqtt_data.state_write_requests.process_write_state_requests()
  File "/usr/src/homeassistant/homeassistant/components/mqtt/models.py", line 267, in process_write_state_requests
    entity.async_write_ha_state()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 566, in async_write_ha_state
    self._async_write_ha_state()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 683, in _async_write_ha_state
    self.hass.states.async_set(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1512, in async_set
    state = State(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1144, in __init__
    raise InvalidStateError(
homeassistant.exceptions.InvalidStateError: Invalid state encountered for entity ID: sensor.0x8cf681fffe5672d3_program. State max length is 255 characters.

[github-actions[bot]]

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days

[j-f-d]

This issue seems to be a problem with the built in HA MQTT integration. A decent workaround for me is to configure zigbee2mqtt to filter the program attribute. In the configuration.yaml file, each affected device needs: filtered_attributes: ["program"] From the front end, select the device, "Settings" tab, then scroll down to the "Filtered Publish Attributes" and add: program

[github-actions[bot]]

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days