Thank you for your response. I found out that I had another docker hass instance that was still running the automation. I thought I stopped it running but with a restart it started running again.
1 Like
I understand what you are saying and why. The system is at our second home and it’s doing the sending of notifications when there is motion in the security cameras. There’s no one there at the moment to trigger movement, but will be in a day or two. I’ll undo the changes I’ve made and see if it’s still doing it. I’ll then get back to this.
English is not my first language so I don’t know if my original explanation was clear, but at least in my case, the actual triggering event is legit and happening. There is movement in the camera and Frigate sends an MQTT message about it. So the automation in question isn’t firing just randomly. It’s just that the automation is disabled, so in my mind, it should not run.
Also, I’ve checked and there are no other instances of Home Assistant running or false automation present. Since making a new automation fixed it partly or completely (I don’t remember), I can only think that there was some kind of cached state (maybe of automations.yml) that caused problems. And to be clear, I had restarted the system many times.
Ok, thanks for the additional info.
When you say the automation is “disabled”, what exactly do you mean? Do you mean it is off?
When you say the automation “runs”, what exactly do you mean, and how did you determine that? Are you just seeing the results of the actions and assumed the automation must have run? Did you review the automation traces? Did you see a log message saying the automation ran? Did the automation’s last_triggered attribute indicate it ran recently? …?
Note that an automation’s actions can run other ways than a trigger “firing” and the conditions, if any, being satisfied. There is a service that can be called to “force” an automation’s actions to run. That service can be invoked from the GUI (at least a couple of different ways), or it can be called from another automation or script, or even HA’s REST API.
Yes. I first wrote 'turned off", but I changed it to “disabled” because that’s what it shows in the UI. 
I’ve also checked the state of the automation from the developer tools > states tab and the state has been “off” when I have expected it to be. (But the trigger still happened.)
Yes, I get the notification about movement in the cameras via Telegram. That is what the automation is for. As I wrote in yesterday’s post, it’s been a while so I don’t necessarily remember everything anymore. I have checked the trace and it showed everything like it normally would after a run. The ‘last_triggered’ attribute also changed, IIRC. There was some inconsistency between the attribute, what was shown in the log or what was shown in the UI in the entity status dialog.
I’ve checked and there is nothing set up to run the automation that way.
Ok, thanks. Yes, on the STATES page its state shows as on or off, whereas on the Automations page it will be “flagged” as disabled if off, and there will be no “flag” if on.
So, there are quite a few ways of checking if the automation was actually off when it appears to have been triggered, and what the source of the trigger was. You can look in the database, in the history of the automation, in the logbook, in home-assistant.log (especially if some additional debugging messages are enabled), etc. I’m not sure what you’re most comfortable with, but I’d be happy to make suggestions.
E.g., I have a very simple automation that gets triggered when one of the Z-Wave switches in the house is double or triple tapped, and the automation has a condition that nobody is home. When it’s triggered it sends me a text message.
I just did an experiment (while nobody is home) where I turned off this automation, “manually” triggered it by calling the automation.trigger service from the SERVICES page, and then turned it back on. This is what that looks like from the Logbook:
You can see it shows as still being triggered, even though it was turned off. And, BTW, I did get the text message, too.
That last entry in the Logbook is from an SQL entity I created that gets the last automation_triggered event from the database for this automation, and displays the time of the trigger and the source of the trigger. You can see it agrees with the other Logbook entries. (It says “NO SOURCE” because it wasn’t run from one of its triggers, but rather by being manually run.)
Next, with the automation on/enabled, I simulated a triple-tap by using the EVENTS page to send the corresponding event. Then I turned the automation off and sent the same event. You can see from the Logbook that the automation triggered while it was on, but not while it was off.
Not only that, but you can see the difference in the trigger event entry (and SQL entity) between these entries and the previous entries where it was manually triggered.
This is just one way to diagnose an issue where it appears an automation is triggering/running when it should be off/disabled. Again, there are many other ways.
Let me know if you’re able to reproduce the problem and if you’d like suggestions on how to diagnose it.
One thing you might want to do beforehand is to enable some additional debug messages in the log. If you want to use these messages to diagnose the problem, they have to be enabled before the problem happens. You can enable via the GUI, or somewhere in your config YAML, add:
logger:
default: warning
logs:
homeassistant.components.automation: debug
homeassistant.core: debug
FWIW, here are the messages from my log related to the above:
2023-03-16 09:11:55.543 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=automation, service=turn_off, service_data=entity_id=automation.tap_not_home>
2023-03-16 09:11:55.544 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.tap_not_home, old_state=<state automation.tap_not_home=on; last_triggered=2023-03-16T09:09:29.419300-05:00, mode=queued, current=0, max=10, id=tap_not_home, friendly_name=Tap Not Home @ 2023-03-16T09:11:47.435648-05:00>, new_state=<state automation.tap_not_home=off; last_triggered=2023-03-16T09:09:29.419300-05:00, mode=queued, current=0, max=10, id=tap_not_home, friendly_name=Tap Not Home @ 2023-03-16T09:11:55.544370-05:00>>
2023-03-16 09:11:59.705 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=automation, service=trigger, service_data=skip_condition=True, entity_id=['automation.tap_not_home']>
2023-03-16 09:11:59.706 DEBUG (MainThread) [homeassistant.components.automation.tap_not_home] Automation triggered
2023-03-16 09:11:59.706 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event automation_triggered[L]: name=Tap Not Home, entity_id=automation.tap_not_home>
2023-03-16 09:11:59.707 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.tap_not_home, old_state=<state automation.tap_not_home=off; last_triggered=2023-03-16T09:09:29.419300-05:00, mode=queued, current=0, max=10, id=tap_not_home, friendly_name=Tap Not Home @ 2023-03-16T09:11:55.544370-05:00>, new_state=<state automation.tap_not_home=off; last_triggered=2023-03-16T09:11:59.707034-05:00, mode=queued, current=1, max=10, id=tap_not_home, friendly_name=Tap Not Home @ 2023-03-16T09:11:55.544370-05:00>>
2023-03-16 09:11:59.714 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.running_automations, old_state=<state sensor.running_automations=0; state_class=measurement, automations=[], unit_of_measurement=#, icon=mdi:sleep, friendly_name=Running Automations @ 2023-03-16T09:09:30.423034-05:00>, new_state=<state sensor.running_automations=1; state_class=measurement, automations=['Tap Not Home'], unit_of_measurement=#, icon=mdi:run, friendly_name=Running Automations @ 2023-03-16T09:11:59.714566-05:00>>
2023-03-16 09:11:59.717 INFO (MainThread) [homeassistant.components.automation.tap_not_home] Tap Not Home: Running automation actions
2023-03-16 09:11:59.718 INFO (MainThread) [homeassistant.components.automation.tap_not_home] Tap Not Home: Executing step call service
2023-03-16 09:11:59.719 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=notify, service=sms_phil, service_data=title=Home Assistant Alert, message=??? tapped while nobody home.>
2023-03-16 09:12:01.033 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.tap_not_home, old_state=<state automation.tap_not_home=off; last_triggered=2023-03-16T09:11:59.707034-05:00, mode=queued, current=1, max=10, id=tap_not_home, friendly_name=Tap Not Home @ 2023-03-16T09:11:55.544370-05:00>, new_state=<state automation.tap_not_home=off; last_triggered=2023-03-16T09:11:59.707034-05:00, mode=queued, current=0, max=10, id=tap_not_home, friendly_name=Tap Not Home @ 2023-03-16T09:11:55.544370-05:00>>
2023-03-16 09:12:05.686 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=automation, service=turn_on, service_data=entity_id=automation.tap_not_home>
2023-03-16 09:12:05.688 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.tap_not_home, old_state=<state automation.tap_not_home=off; last_triggered=2023-03-16T09:11:59.707034-05:00, mode=queued, current=0, max=10, id=tap_not_home, friendly_name=Tap Not Home @ 2023-03-16T09:11:55.544370-05:00>, new_state=<state automation.tap_not_home=on; last_triggered=2023-03-16T09:11:59.707034-05:00, mode=queued, current=0, max=10, id=tap_not_home, friendly_name=Tap Not Home @ 2023-03-16T09:12:05.688084-05:00>>
2023-03-16 09:12:05.697 INFO (MainThread) [homeassistant.components.automation.tap_not_home] Initialized trigger Tap Not Home
2023-03-16 09:12:09.041 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.automation_trigger_time_source, old_state=<state sensor.automation_trigger_time_source=2023-03-16T09:09:29.419042-05:00, NO SOURCE; value=1678975769.419042|{"name":"Tap Not Home","entity_id":"automation.tap_not_home"}, icon=mdi:database-search, friendly_name=Automation Trigger Time & Source @ 2023-03-16T09:09:39.036001-05:00>, new_state=<state sensor.automation_trigger_time_source=2023-03-16T09:11:59.706783-05:00, NO SOURCE; value=1678975919.706783|{"name":"Tap Not Home","entity_id":"automation.tap_not_home"}, icon=mdi:database-search, friendly_name=Automation Trigger Time & Source @ 2023-03-16T09:12:09.040976-05:00>>
2023-03-16 09:30:51.513 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=automation, service=turn_on, service_data=entity_id=automation.tap_not_home>
2023-03-16 09:30:51.515 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.tap_not_home, old_state=<state automation.tap_not_home=off; last_triggered=2023-03-16T09:29:57.320105-05:00, mode=queued, current=0, max=10, id=tap_not_home, friendly_name=Tap Not Home @ 2023-03-16T09:30:03.746040-05:00>, new_state=<state automation.tap_not_home=on; last_triggered=2023-03-16T09:29:57.320105-05:00, mode=queued, current=0, max=10, id=tap_not_home, friendly_name=Tap Not Home @ 2023-03-16T09:30:51.515008-05:00>>
2023-03-16 09:30:51.524 INFO (MainThread) [homeassistant.components.automation.tap_not_home] Initialized trigger Tap Not Home
2023-03-16 09:30:54.985 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event TRIPLE_TAP[R]: entity_id=TEST>
2023-03-16 09:30:54.988 DEBUG (MainThread) [homeassistant.components.automation.tap_not_home] Automation trigger 'None' triggered by event 'TRIPLE_TAP'
2023-03-16 09:30:54.989 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event automation_triggered[L]: name=Tap Not Home, entity_id=automation.tap_not_home, source=event 'TRIPLE_TAP'>
2023-03-16 09:30:54.989 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.tap_not_home, old_state=<state automation.tap_not_home=on; last_triggered=2023-03-16T09:29:57.320105-05:00, mode=queued, current=0, max=10, id=tap_not_home, friendly_name=Tap Not Home @ 2023-03-16T09:30:51.515008-05:00>, new_state=<state automation.tap_not_home=on; last_triggered=2023-03-16T09:30:54.989666-05:00, mode=queued, current=1, max=10, id=tap_not_home, friendly_name=Tap Not Home @ 2023-03-16T09:30:51.515008-05:00>>
2023-03-16 09:30:54.997 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.running_automations, old_state=<state sensor.running_automations=0; state_class=measurement, automations=[], unit_of_measurement=#, icon=mdi:sleep, friendly_name=Running Automations @ 2023-03-16T09:29:58.382040-05:00>, new_state=<state sensor.running_automations=1; state_class=measurement, automations=['Tap Not Home'], unit_of_measurement=#, icon=mdi:run, friendly_name=Running Automations @ 2023-03-16T09:30:54.997073-05:00>>
2023-03-16 09:30:55.001 INFO (MainThread) [homeassistant.components.automation.tap_not_home] Tap Not Home: Running automation actions
2023-03-16 09:30:55.001 INFO (MainThread) [homeassistant.components.automation.tap_not_home] Tap Not Home: Executing step call service
2023-03-16 09:30:55.002 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=notify, service=sms_phil, service_data=title=Home Assistant Alert, message=None tapped while nobody home.>
2023-03-16 09:30:56.028 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.tap_not_home, old_state=<state automation.tap_not_home=on; last_triggered=2023-03-16T09:30:54.989666-05:00, mode=queued, current=1, max=10, id=tap_not_home, friendly_name=Tap Not Home @ 2023-03-16T09:30:51.515008-05:00>, new_state=<state automation.tap_not_home=on; last_triggered=2023-03-16T09:30:54.989666-05:00, mode=queued, current=0, max=10, id=tap_not_home, friendly_name=Tap Not Home @ 2023-03-16T09:30:51.515008-05:00>>
2023-03-16 09:30:56.033 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.running_automations, old_state=<state sensor.running_automations=1; state_class=measurement, automations=['Tap Not Home'], unit_of_measurement=#, icon=mdi:run, friendly_name=Running Automations @ 2023-03-16T09:30:54.997073-05:00>, new_state=<state sensor.running_automations=0; state_class=measurement, automations=[], unit_of_measurement=#, icon=mdi:sleep, friendly_name=Running Automations @ 2023-03-16T09:30:56.033769-05:00>>
2023-03-16 09:31:09.081 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.automation_trigger_time_source, old_state=<state sensor.automation_trigger_time_source=2023-03-16T09:29:57.319806-05:00, event 'TRIPLE_TAP'; value=1678976997.319806|{"name":"Tap Not Home","entity_id":"automation.tap_not_home","source":"event 'TRIPLE_TAP'"}, icon=mdi:database-search, friendly_name=Automation Trigger Time & Source @ 2023-03-16T09:30:09.079949-05:00>, new_state=<state sensor.automation_trigger_time_source=2023-03-16T09:30:54.989379-05:00, event 'TRIPLE_TAP'; value=1678977054.989379|{"name":"Tap Not Home","entity_id":"automation.tap_not_home","source":"event 'TRIPLE_TAP'"}, icon=mdi:database-search, friendly_name=Automation Trigger Time & Source @ 2023-03-16T09:31:09.081740-05:00>>
2023-03-16 09:31:15.318 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=automation, service=turn_off, service_data=entity_id=automation.tap_not_home>
2023-03-16 09:31:15.320 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.tap_not_home, old_state=<state automation.tap_not_home=on; last_triggered=2023-03-16T09:30:54.989666-05:00, mode=queued, current=0, max=10, id=tap_not_home, friendly_name=Tap Not Home @ 2023-03-16T09:30:51.515008-05:00>, new_state=<state automation.tap_not_home=off; last_triggered=2023-03-16T09:30:54.989666-05:00, mode=queued, current=0, max=10, id=tap_not_home, friendly_name=Tap Not Home @ 2023-03-16T09:31:15.320180-05:00>>
2023-03-16 09:31:18.520 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event TRIPLE_TAP[R]: entity_id=TEST>
If you look closely, you can see I also have another template sensor that indicates how many automation runs are currently executing, and for which automations. 