Possible Automation Bug

I have configured a very basic automation to turn off a fan at a user specified time. Last night the automation triggered and turned the fan off, then immediately turned it back on. I have looked through the logs and cannot figure out what caused this nor how to prevent it from happening again.

Please help.

id: '1654734307613'
alias: Fan Sleep Timer (Time based)
description: ''
trigger:
  - platform: time
    at: input_datetime.fan_off_time
condition:
  - condition: state
    entity_id: input_boolean.sleep_timer_enabled
    state: 'on'
action:
  - device_id: 6bb15fb9e2680e7cad886363edbb6376
    domain: fan
    entity_id: fan.bedroom_fan
    type: turn_off
mode: single

Logbook Trace:

{
  "trace": {
    "last_step": "action/0",
    "run_id": "74456e938c86dc9fb7ab2a0f9ab244e8",
    "state": "stopped",
    "script_execution": "finished",
    "timestamp": {
      "start": "2022-06-20T09:00:00.002775+00:00",
      "finish": "2022-06-20T09:00:00.118225+00:00"
    },
    "domain": "automation",
    "item_id": "1654734307613",
    "trigger": "time set in input_datetime.fan_off_time",
    "trace": {
      "trigger/0": [
        {
          "path": "trigger/0",
          "timestamp": "2022-06-20T09:00:00.003023+00:00",
          "changed_variables": {
            "this": {
              "entity_id": "automation.fan_sleep_timer_time",
              "state": "on",
              "attributes": {
                "last_triggered": "2022-06-15T06:00:00.008927+00:00",
                "mode": "single",
                "current": 0,
                "id": "1654734307613",
                "friendly_name": "Fan Sleep Timer (Time based)"
              },
              "last_changed": "2022-06-19T05:10:13.773575+00:00",
              "last_updated": "2022-06-19T05:10:13.773575+00:00",
              "context": {
                "id": "01817a5e5e0de89ab11a2604b2dfcae9",
                "parent_id": null,
                "user_id": null
              }
            },
            "trigger": {
              "id": "0",
              "idx": "0",
              "platform": "time",
              "now": "2022-06-20T03:00:00.001411-06:00",
              "description": "time set in input_datetime.fan_off_time",
              "entity_id": "input_datetime.fan_off_time"
            }
          }
        }
      ],
      "condition/0": [
        {
          "path": "condition/0",
          "timestamp": "2022-06-20T09:00:00.003188+00:00",
          "result": {
            "result": true
          }
        }
      ],
      "condition/0/entity_id/0": [
        {
          "path": "condition/0/entity_id/0",
          "timestamp": "2022-06-20T09:00:00.003315+00:00",
          "result": {
            "result": true,
            "state": "on",
            "wanted_state": "on"
          }
        }
      ],
      "action/0": [
        {
          "path": "action/0",
          "timestamp": "2022-06-20T09:00:00.005312+00:00",
          "changed_variables": {
            "context": {
              "id": "018180571682977e1a2ef043a34cce41",
              "parent_id": null,
              "user_id": null
            }
          }
        }
      ]
    },
    "config": {
      "id": "1654734307613",
      "alias": "Fan Sleep Timer (Time based)",
      "description": "",
      "trigger": [
        {
          "platform": "time",
          "at": "input_datetime.fan_off_time"
        }
      ],
      "condition": [
        {
          "condition": "state",
          "entity_id": "input_boolean.sleep_timer_enabled",
          "state": "on"
        }
      ],
      "action": [
        {
          "device_id": "6bb15fb9e2680e7cad886363edbb6376",
          "domain": "fan",
          "entity_id": "fan.bedroom_fan",
          "type": "turn_off"
        }
      ],
      "mode": "single"
    },
    "blueprint_inputs": null,
    "context": {
      "id": "018180571682977e1a2ef043a34cce41",
      "parent_id": null,
      "user_id": null
    }
  },
  "logbookEntries": [
    {
      "name": "Fan Sleep Timer (Time based)",
      "message": "has been triggered by time set in input_datetime.fan_off_time",
      "source": "time set in input_datetime.fan_off_time",
      "entity_id": "automation.fan_sleep_timer_time",
      "context_id": "018180571682977e1a2ef043a34cce41",
      "when": "2022-06-20T09:00:00.003996+00:00",
      "domain": "automation"
    },
    {
      "when": "2022-06-20T09:00:00.111451+00:00",
      "name": "Bedroom Fan",
      "state": "off",
      "entity_id": "fan.bedroom_fan",
      "context_entity_id": "automation.fan_sleep_timer_time",
      "context_entity_id_name": "Fan Sleep Timer (Time based)",
      "context_event_type": "automation_triggered",
      "context_domain": "automation",
      "context_name": "Fan Sleep Timer (Time based)",
      "message": "turned off"
    },
    {
      "when": "2022-06-20T09:00:00.186808+00:00",
      "name": "Bedroom Fan",
      "state": "on",
      "entity_id": "fan.bedroom_fan",
      "context_entity_id": "automation.fan_sleep_timer_time",
      "context_entity_id_name": "Fan Sleep Timer (Time based)",
      "context_event_type": "automation_triggered",
      "context_domain": "automation",
      "context_name": "Fan Sleep Timer (Time based)",
      "message": "turned on"
    }
  ]
}

That’s very odd: the automation doesn’t even have code to turn it on.

Try using a service call instead of device logic:

action:
  - service: fan.turn_off
    entity_id: fan.bedroom_fan

…and see if the problem recurs.

I used a service to turn it off:

action:
  - service: fan.turn_off
    data: {}
    target:
      device_id: 6bb15fb9e2680e7cad886363edbb6376

but still get the same bug:

{
  "trace": {
    "last_step": "action/0",
    "run_id": "f0714155bc1f131f65cf54c6bb5bdbc1",
    "state": "stopped",
    "script_execution": "finished",
    "timestamp": {
      "start": "2022-06-20T13:45:00.002847+00:00",
      "finish": "2022-06-20T13:45:00.120129+00:00"
    },
    "domain": "automation",
    "item_id": "1654734307613",
    "trigger": "time set in input_datetime.fan_off_time",
    "trace": {
      "trigger/0": [
        {
          "path": "trigger/0",
          "timestamp": "2022-06-20T13:45:00.003092+00:00",
          "changed_variables": {
            "this": {
              "entity_id": "automation.fan_sleep_timer_time",
              "state": "on",
              "attributes": {
                "last_triggered": "2022-06-20T13:25:00.003193+00:00",
                "mode": "single",
                "current": 0,
                "id": "1654734307613",
                "friendly_name": "Fan Sleep Timer (Time based)"
              },
              "last_changed": "2022-06-20T13:22:00.352086+00:00",
              "last_updated": "2022-06-20T13:25:00.123292+00:00",
              "context": {
                "id": "01818149b3e1285bfd09657cf94a941f",
                "parent_id": null,
                "user_id": null
              }
            },
            "trigger": {
              "id": "0",
              "idx": "0",
              "platform": "time",
              "now": "2022-06-20T07:45:00.001463-06:00",
              "description": "time set in input_datetime.fan_off_time",
              "entity_id": "input_datetime.fan_off_time"
            }
          }
        }
      ],
      "condition/0": [
        {
          "path": "condition/0",
          "timestamp": "2022-06-20T13:45:00.003253+00:00",
          "result": {
            "result": true
          }
        }
      ],
      "condition/0/entity_id/0": [
        {
          "path": "condition/0/entity_id/0",
          "timestamp": "2022-06-20T13:45:00.003377+00:00",
          "result": {
            "result": true,
            "state": "on",
            "wanted_state": "on"
          }
        }
      ],
      "action/0": [
        {
          "path": "action/0",
          "timestamp": "2022-06-20T13:45:00.005886+00:00",
          "changed_variables": {
            "context": {
              "id": "0181815c03629025b1754692679a9a2c",
              "parent_id": null,
              "user_id": null
            }
          },
          "result": {
            "params": {
              "domain": "fan",
              "service": "turn_off",
              "service_data": {},
              "target": {
                "device_id": [
                  "6bb15fb9e2680e7cad886363edbb6376"
                ]
              }
            },
            "running_script": false,
            "limit": 10
          }
        }
      ]
    },
    "config": {
      "id": "1654734307613",
      "alias": "Fan Sleep Timer (Time based)",
      "description": "",
      "trigger": [
        {
          "platform": "time",
          "at": "input_datetime.fan_off_time"
        }
      ],
      "condition": [
        {
          "condition": "state",
          "entity_id": "input_boolean.sleep_timer_enabled",
          "state": "on"
        }
      ],
      "action": [
        {
          "service": "fan.turn_off",
          "data": {},
          "target": {
            "device_id": "6bb15fb9e2680e7cad886363edbb6376"
          }
        }
      ],
      "mode": "single"
    },
    "blueprint_inputs": null,
    "context": {
      "id": "0181815c03629025b1754692679a9a2c",
      "parent_id": null,
      "user_id": null
    }
  },
  "logbookEntries": [
    {
      "name": "Fan Sleep Timer (Time based)",
      "message": "has been triggered by time set in input_datetime.fan_off_time",
      "source": "time set in input_datetime.fan_off_time",
      "entity_id": "automation.fan_sleep_timer_time",
      "context_id": "0181815c03629025b1754692679a9a2c",
      "when": "2022-06-20T13:45:00.004021+00:00",
      "domain": "automation"
    },
    {
      "when": "2022-06-20T13:45:00.110581+00:00",
      "name": "Bedroom Fan",
      "state": "off",
      "entity_id": "fan.bedroom_fan",
      "context_entity_id": "automation.fan_sleep_timer_time",
      "context_entity_id_name": "Fan Sleep Timer (Time based)",
      "context_event_type": "automation_triggered",
      "context_domain": "automation",
      "context_name": "Fan Sleep Timer (Time based)",
      "message": "turned off"
    },
    {
      "when": "2022-06-20T13:45:00.189049+00:00",
      "name": "Bedroom Fan",
      "state": "on",
      "entity_id": "fan.bedroom_fan",
      "context_entity_id": "automation.fan_sleep_timer_time",
      "context_entity_id_name": "Fan Sleep Timer (Time based)",
      "context_event_type": "automation_triggered",
      "context_domain": "automation",
      "context_name": "Fan Sleep Timer (Time based)",
      "message": "turned on"
    }
  ]
}

As an experiment, make the automation turn off some other device instead of that particular fan. The goal is to determine if the issue is with the automation or the fan itself.

Good idea. I will play around with it more tonight when I am home.

Also, use the entity_id as I posted rather than the device_id — just keeps things a bit simpler. Shouldn’t make a difference, but then it shouldn’t be behaving like this in the first place.

What happens if you manually trigger the automation (which bypasses the trigger and condition blocks)?

I was able to play around last night and got a little closer to finding the source. I have another automation that sets the speed of this fan whenever it is turned on. When this “Default Speed” automation is active, it causes the fan to turn on immediately after it is turned off by the Sleep Timer automation.

Again, I can’t determine why this would happen:

id: '1655615410732'
alias: Bedroom Fan Default Speed
description: ''
trigger:
  - platform: device
    type: turned_on
    device_id: 6bb15fb9e2680e7cad886363edbb6376
    entity_id: fan.bedroom_fan
    domain: fan
condition: []
action:
  - service: fan.set_percentage
    data:
      percentage: 60
    target:
      device_id: 6bb15fb9e2680e7cad886363edbb6376
mode: single