Figuring out what triggered an action?

Configuration
1

I have an automation rule that sets a boolean variable (using input_boolean.turn_on) when a partcular MQTT message is received. That part is working. Every once in a while, “something” comes along and immediately turns that boolean back off. Is there any way to figure out what’s causing that?

It’s hard to test because it never seems to happen when I try to debug it. It seems that it only happens when a substantial amount of time (like a whole day) has passed, and then not always.

When I look at the logger, the entry at that time says:

3:32:30 PM [Mail has arrived today](http://192.168.2.48:8123/logbook#) turned off (homeassistant)

What does the tag “(homemassistant)” mean here? I don’t see that for any other entries in the logger

2

homeassistant is Home Assistant.
Not a user making a change on the UI, but a rule or flow changing the value.

I think this cannot be solved without you posting a lot more information.
What’s the automation config?
What’s tine input_boolean config?
What triggers turn off the input_boolean?
Why not record MQTT messages for a day (will be less than a megabyte, or a couple of megabytes to record that)?

3

Thanks for the response. To provide some more detail…

There is one MQTT message that turns the boolean. (This is working properly):

   - alias: Arriving mail trigger
      initial_state: 'on'
      trigger:
        platform: mqtt
        topic: home/mailbox
        payload: 'ON'
      action:
        service: input_boolean.turn_on
        entity_id: input_boolean.mail_here

There are two things that should turn it off. First an MQTT message:

# Signal that mail has been collected (Dash button press)
    - alias: Collected mail trigger - beyond
      initial_state: 'on'
      trigger:
        platform: mqtt
        topic: home/dash/beyond
        payload: 'ON'
      action:
        service: input_boolean.turn_off
        entity_id: input_boolean.mail_here

Second, a time event to clear it at the beginning of the new day:

    - alias: Clear mail flag at 1am
      initial_state: 'on'
      trigger:
        platform: time
        at: '01:00:00'
      action:
        service: input_boolean.turn_off
        entity_id: input_boolean.mail_here

AFAIK, the MQTT message is not being sent. (There is no reason it should be, it doesn’t show up in the log even though I have mqtt set to “debug”, and it doesn’t show up in a window where I’m running mosquitto_sub). And obviously the timer event should not be triggered.

Since there is no known reason why the boolean should be getting turned off, I’m trying to figure out what unknown (to me) other things might cause it to get turned off!

Here is the definition of the boolean:

input_boolean:
  mail_here:
      name: Mail has arrived today
      initial: off
      icon: mdi:mailbox
4

Remove the ‘initial: off’. I think if you reload your input booleans this will reset your mail_here to off.

5

"what does “reload your input booleans” mean? I thought “initial: off” meant that it would get to set to off when HA starts up. That would be OK. Are there other things that would trigger it?

6

If you don’t have ‘initial: off’ in your configuration, HA keeps the last known state when restarting.

If you have it, it is set to off when restarting, but I think also when reloading

image
image593×571 19.1 KB

and creating a helper in the GUI reloads too I think. Try removing it, and see if you still have unexplained changes.

7

Ok, I’ve removed it. It’s so intermittent that it will take several days to see if it makes any difference. To the extent I understand it, I don’t see why it would matter. The boolean is getting turned off seconds after being turned on - I’m clearly not restarting HA or manually triggering the reload at that time.

8

You can only try. If it is not that, you will have to continue your search.

9

The problem occurred when I manually triggered a test with the first MQTT message this morning.

ha_log

I’m still curious about the “(homeassistant)” tag on the message at 7:31:05. That’s the only message in the entire log that has has that tag, even though lots of other things are triggered by rules.

For example, when the MQTT message comes in at 7:31:03, it triggers a rule which turns “mail here” on, and when “mail here” goes on, it triggers a rule that turns on “RGBW Light1” and “RGBW Light2.” But those don’t have the “(homeassistant)” tag. Immediately afterward at 7:31:05 “mail here” gets turned off. But there is no rule (that I know of!) that would explain why that’s happening!

10

The only thing I can think of is that HA is trying to turn on “input_boolean.mail_here” via the automation but it doesn’t actually get trurned on so there is no “state changed” feedback so HA turns that boolean back off again a couple of seconds. It will do the same thing for any other device also. If you try to turn on a light and the light never reports the state change then in a couple of seconds the switch in HA goes back to off.

Are you sure that you have all of the entity_ids correct in the automations?

You haven’t shown us the config for your boolean yet. Maybe the problem is there?

11

I believe I did show the boolean config in an earlier message. Or else I’m not clear on what you are asking for. It is this:

input_boolean:
  mail_here:
      name: Mail has arrived today
      initial: off
      icon: mdi:mailbox

@francisp suggested removing the “initial: off” and I’ve done that but the problem is still happening.

I understand what you mean about the entity not confirming its state change. I have seen that behavior with lights and I have to agree that this has sort of the same “feel.” But I’m not sure it’s the same thing - I don’t think input_booleans need to “acknowledge” a state change, and I wouldn’t know how to tell it to do that even if I wanted to.

13

So, it took months of head scratching and hair pulling, but I finally figured out what’s happening. The sequence is like this:

1 - Mail carrier opens mailbox triggering and MQTT message to HA
2 - HA sends an XMPP message to Google Hangouts saying “you have mail” and containing a link that the recipient can click to acknowledge receipt
3 - The normal operation is is that the user clicks on the link when they get the mail. The script on the web server sends an API request to HA.
4 - BUT Sometimes, when Google sees that link in the mail, the crawl the link in order to preview it. That results in triggering what is supposed to the be the user action, immediately after the message is sent.

There were a couple of things that made this tricky to debug: First, it only happens intermittently (typically once a day) so it’s hard to reproduce for testing. Second, I still feel that it’s inordinately difficult to track down what component in HA is causing an action.

I’m mentioning it here, in hopes that it will save someone else from dealing with the same issue: If you send a XMPP message to a Google account that contains a URL, the Google crawler may access that URL.

I eventually found it when I noticed messages like this in my http access log:

66.102.9.19 - - [24/Dec/2020:17:20:08 -0600] “GET /mail_collected.php HTTP/1.1” 200 13 “-” “Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/56.0.2924.87 Safari/537.36 Google (+https://developers.google.com/+/web/snippet/)”

That IP address is coming from outside my network and nothing in my network runs Chrome/56. My workaround is to simply ignore any requests from the crawler (by looking for that user-agent string)