Automation is cancelled on API client disconnect

[Shulyaka]

The problem

I have a problem with my automations being cancelled during wait timer.
Background: I have a backup server that should stay powered off most of the time, only powering on at night to make a backup.
The power socket is controlled by home assistant. It has automation.backup_watchdog that waits for 31 minutes and powers off the server. While the server is running, it uses web API to restart the automation at a regular intervals while the OS is still running to prevent it to power off too early.
The error I have is that the automation mysteriously gets cancelled after about 6 minutes of waiting (out of 31), even when it is not restarted.

What version of Home Assistant Core has the issue?

core-2023.9.0

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant Core

Integration causing the issue

automation

Link to integration documentation on our website

https://www.home-assistant.io/docs/automation/basics/

Diagnostics information

No response

Example YAML snippet

id: '1668363102805'
alias: Backup watchdog
description: Backup watchdog
trigger:
  - platform: device
    type: changed_states
    device_id: 14c5be6c720fb48ea6daf7d4dfa7dcfc
    entity_id: light.sonoff_10013f38ac_1
    domain: light
  - platform: homeassistant
    event: start
  - platform: event
    event_type: automation_reloaded
    enabled: true
condition:
  - condition: template
    value_template: >-
      {{trigger is not defined or trigger.platform != "event" or
      trigger.event.event_type != "automation_reloaded" or
      this.attributes.current == 0}}
    alias: Only trigger if this automation has been reloaded
action:
  - condition: device
    type: is_on
    device_id: 14c5be6c720fb48ea6daf7d4dfa7dcfc
    entity_id: light.sonoff_10013f38ac_1
    domain: light
    alias: Cancel watchdog timer if backup is off
  - service: notify.persistent_notification
    data:
      message: Watchdog refreshed
      title: Test
    enabled: false
  - delay:
      hours: 0
      minutes: 31
      seconds: 0
      milliseconds: 0
  - type: turn_off
    device_id: 14c5be6c720fb48ea6daf7d4dfa7dcfc
    entity_id: light.sonoff_10013f38ac_1
    domain: light
    enabled: true
  - service: notify.persistent_notification
    data:
      message: Turning off backup
      title: Test
    enabled: false
mode: restart

Anything in the logs that might be useful for us?

2023-09-24 04:45:00.285 DEBUG (MainThread) [homeassistant.components.automation.backup_watchdog] Automation trigger 'None' triggered by state of light.sonoff_10013f38ac_1
2023-09-24 04:45:00.286 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Restarting
2023-09-24 04:45:00.286 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event automation_triggered[L]: name=Backup watchdog, entity_id=automation.backup_watchdog, source=state of light.sonoff_10013f38ac_1>
2023-09-24 04:45:00.287 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-23T18:17:31.653483+03:00, mode=restart, current=0, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T04:45:00.286781+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>
2023-09-24 04:45:00.322 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Running automation actions
2023-09-24 04:45:00.323 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Test condition Cancel watchdog timer if backup is off: True
2023-09-24 04:45:00.323 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Skipped disabled step call_service
2023-09-24 04:45:00.324 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Executing step delay 0:31:00
2023-09-24 04:52:19.045 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=automation, service=trigger, service_data=entity_id=automation.backup_watchdog>
2023-09-24 04:52:19.048 DEBUG (MainThread) [homeassistant.components.automation.backup_watchdog] Automation triggered
2023-09-24 04:52:19.049 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Restarting
2023-09-24 04:52:19.053 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event automation_triggered[L]: name=Backup watchdog, entity_id=automation.backup_watchdog>
2023-09-24 04:52:19.053 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T04:45:00.286781+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T04:52:19.053763+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>
2023-09-24 04:52:19.065 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Running automation actions
2023-09-24 04:52:19.067 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Test condition Cancel watchdog timer if backup is off: True
2023-09-24 04:52:19.067 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Skipped disabled step call_service
2023-09-24 04:52:19.068 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Executing step delay 0:31:00
2023-09-24 04:58:19.894 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T04:52:19.053763+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T04:52:19.053763+03:00, mode=restart, current=0, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>
2023-09-24 04:58:20.913 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=automation, service=trigger, service_data=entity_id=automation.backup_watchdog>
2023-09-24 04:58:20.915 DEBUG (MainThread) [homeassistant.components.automation.backup_watchdog] Automation triggered
2023-09-24 04:58:20.916 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Restarting
2023-09-24 04:58:20.916 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event automation_triggered[L]: name=Backup watchdog, entity_id=automation.backup_watchdog>
2023-09-24 04:58:20.916 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T04:52:19.053763+03:00, mode=restart, current=0, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T04:58:20.916546+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>
2023-09-24 04:58:20.929 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Running automation actions
2023-09-24 04:58:20.930 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Test condition Cancel watchdog timer if backup is off: True
2023-09-24 04:58:20.930 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Skipped disabled step call_service
2023-09-24 04:58:20.931 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Executing step delay 0:31:00
2023-09-24 05:04:21.705 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T04:58:20.916546+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T04:58:20.916546+03:00, mode=restart, current=0, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>
2023-09-24 05:04:23.154 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=automation, service=trigger, service_data=entity_id=automation.backup_watchdog>
2023-09-24 05:04:23.156 DEBUG (MainThread) [homeassistant.components.automation.backup_watchdog] Automation triggered
2023-09-24 05:04:23.156 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Restarting
2023-09-24 05:04:23.157 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event automation_triggered[L]: name=Backup watchdog, entity_id=automation.backup_watchdog>
2023-09-24 05:04:23.157 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T04:58:20.916546+03:00, mode=restart, current=0, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:04:23.157294+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>
2023-09-24 05:04:23.168 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Running automation actions
2023-09-24 05:04:23.169 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Test condition Cancel watchdog timer if backup is off: True
2023-09-24 05:04:23.169 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Skipped disabled step call_service
2023-09-24 05:04:23.170 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Executing step delay 0:31:00
2023-09-24 05:10:23.459 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:04:23.157294+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:04:23.157294+03:00, mode=restart, current=0, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>
2023-09-24 05:10:24.524 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=automation, service=trigger, service_data=entity_id=automation.backup_watchdog>
2023-09-24 05:10:24.525 DEBUG (MainThread) [homeassistant.components.automation.backup_watchdog] Automation triggered
2023-09-24 05:10:24.525 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Restarting
2023-09-24 05:10:24.525 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event automation_triggered[L]: name=Backup watchdog, entity_id=automation.backup_watchdog>
2023-09-24 05:10:24.526 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:04:23.157294+03:00, mode=restart, current=0, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:10:24.525878+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>
2023-09-24 05:10:24.533 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Running automation actions
2023-09-24 05:10:24.534 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Test condition Cancel watchdog timer if backup is off: True
2023-09-24 05:10:24.534 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Skipped disabled step call_service
2023-09-24 05:10:24.535 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Executing step delay 0:31:00
2023-09-24 05:16:25.826 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:10:24.525878+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:10:24.525878+03:00, mode=restart, current=0, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>
2023-09-24 05:16:27.211 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=automation, service=trigger, service_data=entity_id=automation.backup_watchdog>
2023-09-24 05:16:27.213 DEBUG (MainThread) [homeassistant.components.automation.backup_watchdog] Automation triggered
2023-09-24 05:16:27.214 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Restarting
2023-09-24 05:16:27.214 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event automation_triggered[L]: name=Backup watchdog, entity_id=automation.backup_watchdog>
2023-09-24 05:16:27.214 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:10:24.525878+03:00, mode=restart, current=0, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:16:27.214691+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>
2023-09-24 05:16:27.223 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Running automation actions
2023-09-24 05:16:27.224 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Test condition Cancel watchdog timer if backup is off: True
2023-09-24 05:16:27.224 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Skipped disabled step call_service
2023-09-24 05:16:27.225 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Executing step delay 0:31:00
2023-09-24 05:22:27.844 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:16:27.214691+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:16:27.214691+03:00, mode=restart, current=0, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>
2023-09-24 05:22:28.826 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=automation, service=trigger, service_data=entity_id=automation.backup_watchdog>
2023-09-24 05:22:28.828 DEBUG (MainThread) [homeassistant.components.automation.backup_watchdog] Automation triggered
2023-09-24 05:22:28.829 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Restarting
2023-09-24 05:22:28.829 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event automation_triggered[L]: name=Backup watchdog, entity_id=automation.backup_watchdog>
2023-09-24 05:22:28.829 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:16:27.214691+03:00, mode=restart, current=0, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:22:28.829718+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>
2023-09-24 05:22:28.836 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Running automation actions
2023-09-24 05:22:28.836 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Test condition Cancel watchdog timer if backup is off: True
2023-09-24 05:22:28.837 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Skipped disabled step call_service
2023-09-24 05:22:28.837 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Executing step delay 0:31:00
2023-09-24 05:28:29.720 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:22:28.829718+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:22:28.829718+03:00, mode=restart, current=0, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>
2023-09-24 05:28:30.738 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=automation, service=trigger, service_data=entity_id=automation.backup_watchdog>
2023-09-24 05:28:30.739 DEBUG (MainThread) [homeassistant.components.automation.backup_watchdog] Automation triggered
2023-09-24 05:28:30.739 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Restarting
2023-09-24 05:28:30.739 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event automation_triggered[L]: name=Backup watchdog, entity_id=automation.backup_watchdog>
2023-09-24 05:28:30.740 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:22:28.829718+03:00, mode=restart, current=0, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:28:30.740173+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>
2023-09-24 05:28:30.747 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Running automation actions
2023-09-24 05:28:30.747 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Test condition Cancel watchdog timer if backup is off: True
2023-09-24 05:28:30.748 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Skipped disabled step call_service
2023-09-24 05:28:30.748 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Executing step delay 0:31:00
2023-09-24 05:34:31.488 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:28:30.740173+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:28:30.740173+03:00, mode=restart, current=0, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>
2023-09-24 05:34:33.058 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=automation, service=trigger, service_data=entity_id=automation.backup_watchdog>
2023-09-24 05:34:33.059 DEBUG (MainThread) [homeassistant.components.automation.backup_watchdog] Automation triggered
2023-09-24 05:34:33.059 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Restarting
2023-09-24 05:34:33.060 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event automation_triggered[L]: name=Backup watchdog, entity_id=automation.backup_watchdog>
2023-09-24 05:34:33.060 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:28:30.740173+03:00, mode=restart, current=0, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:34:33.060489+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>
2023-09-24 05:34:33.073 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Running automation actions
2023-09-24 05:34:33.075 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Test condition Cancel watchdog timer if backup is off: True
2023-09-24 05:34:33.076 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Skipped disabled step call_service
2023-09-24 05:34:33.077 INFO (MainThread) [homeassistant.components.automation.backup_watchdog] Backup watchdog: Executing step delay 0:31:00
2023-09-24 05:38:09.213 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.backup_watchdog, old_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:34:33.060489+03:00, mode=restart, current=1, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>, new_state=<state automation.backup_watchdog=on; id=1668363102805, last_triggered=2023-09-24T05:34:33.060489+03:00, mode=restart, current=0, icon=mdi:timer-sync, friendly_name=Backup watchdog @ 2023-09-23T18:09:36.742725+03:00>>

Nothing relevant after this.

Additional information

Traces of the last run:

[home-assistant]

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.

_{^{(message by CodeOwnersMention)}}

---

automation documentation
automation source
_{^{(message by IssueLinks)}}

[Shulyaka]

After a bit of debugging I've found a clue.
It turns out that when an automation is started via REST API services/automation/trigger, it will be running until the connection is broken. However in my case the automation is what is responsible to switch off the backup server power after it shuts down, and the curl process is terminated during the shutdown.
This is probably related to the introduction of a service responses or an aiohttp update.

To quote the documentation:

POST /api/services/<domain>/<service> 🔒
Calls a service within a specific domain. Will return when the service has been executed or after 10 seconds, whichever comes first.

This is not what I am experiencing now. The call does not return until the service call is finished, and when the client drops the connection, the asyncio.CancelledError is raised that cancels the automation.

Please advise.

[Shulyaka]

The aiohttp version I have is 3.8.5 and aio-libs/aiohttp#6727 is already there

[joostlek]

I don't know how the whole rest API works, but maybe you can consider using a webhook as trigger?

[Shulyaka]

It's a valid workaround, yes.