Duplicate iOS companion app notifications

I’m receiving duplicate notifications for some of my automations. It used to work fine. I think this started happening in the past month or so, but I don’t have an exact date.

Here is one of the automations:

- alias: "Notify If New Backup Found"
  trigger:
    - platform: state
      entity_id: sensor.last_backup
  mode: single
  condition:
    condition: template
    value_template: >-
      {% set last_backup = states('sensor.last_backup') | as_datetime %}
      {{ ((utcnow() - last_backup).seconds) < 60 }}
  action:
    - service: notify.mobile_app_ceres
      data:
        title: "System"
        message: "A new Home Assistant backup was made."
        data:
          group: "system-backup"
          url: homeassistant://navigate/lovelace/devices

And what I see:

At first, I thought there could be a race condition in the state engine, but I found very little evidence of anything even close to that – and I think the world would’ve been up in arms if that was the case. Regardless, I explicitly added mode: single (even though it’s the default).

My current theory is that it might have something to do with when you can receive push notifications directly (when on your home network). Unfortunately, I’ve been too late to capture the companion app logs (truncated). I need to be quicker to export it when it happens again. Maybe the notification gets sent both internally and externally?

I’m sure the state the automation triggers on only changed once – at that time. The second change seen here was after an HA restart.

Zoomed in to 02:00 until 02:10.

I’m sure the automation only triggered once:

Server version: 2022.2.9 (I’m still planning my upgrade to 2022.3.x)
Companion app (iOS): 2022.3

I couldn’t find any related posts on the forum or on any of the relevant GitHub repos.

A few debugging things worth investigating:

  1. Include a random identifier: add something like {{ range(1, 1000) | random }} to your message. If it’s the same number, it’s the same send that’s duplicated somehow.
  2. Reset the push token in App Configuration > Notifications. It’s possible Firebase has double-recorded your device for its internal identifier, which could in theory make it fire twice. Hard to debug this one.
  3. Try turning off Local Push in the server’s settings in App Configuration.
  4. Check if there’s any error logs in the event log in App Configuration > Debugging.

Thanks, Zac. Good ideas (who would know better than you anyway :slight_smile:).

I’m going to try the first step first.

I’ll report back once I know more.

I’ve added the random string and had a few notifications since. No duplicates!

Since this doesn’t seem to happen every time, I’m thinking I’ll keep running it like this for a little longer. If it doesn’t happen again, I’m going to remove the random string to see if I’m getting duplicates again, and take it from there.

At last, it happened again, but I forgot to capture the companion app logs…

The logs stick around for a few days (3 days for App Store versions, 7 days for TestFlight versions), so it may still be in there. If you export them you can glance in the zip file.

Unfortunately I was too late, so I’ll need to wait for the next round…

Maybe check your automations yaml to see if there are two instances of the automation sending the message. I’ve had this happen to me. When you save an automation via the gui, the automations.yaml gets reloaded in the background and you manage to save again you end up with duplicates. The bigger automations.yaml, the bigger the chance.

Thanks for the idea, Edwin.

I checked now to be sure and don’t see any duplicates. My issue happens for a number of automations. I’m just sticking to the one here for simplicity.

I’ve implemented the suggestion to add a random number to the message too (in the screenshot), so I think if there was a duplicate those number would differ.

I’ll keep the issue you mention in mind though. I only edit via YAML, but do have unique IDs assigned in order to benefit from the automation debugger.

If there are no duplicate values from the random number, there must be double execution. If you look at the backup log the backup is mentioned twice too, so double execution is not that strange considering. You’d think it was caused by something changed with the backup process if it weren’t for the fact you see it elsewhere too.

Hiding the effect is easy enough by adding a short delay after the notification (combined with the single execution mode) but I wouldn’t be satisfied until I understand where this comes from. My bet is in the event system or more than in the automation itself, seeing there are double backup finished events. Do you have any automations or scripts that explicitly fire events?

Just noticed: Weird is there are two backup lines about the same backup at completely different times. It almost looks like it is revisiting old events again. That is very strange indeed. Without deeper knowledge of inner workings it is almost impossible to guess how this could happen. Anything happened at the time of the repeated event?

Where are you seeing that? On your own system? I should note that I’m not using the new backup mechanism recently introduced. This is still an older shell script being executed. That said, it doesn’t change much and it’s only one of my automations doing this (as you said too).

Yeah, so concurrent executions would be limited. I already have mode: single which I added the first time I saw this and I thought I wouldn’t bother to debug the issue further. Then it kept on happening…

Ditto. Luckily it’s not crazy annoying as it doesn’t always happen, but it seems interestingly enough now to understand this better.

Only a few automations where I trigger on events, none of them related to the automations where I see duplicate notifications. I don’t emit custom events anywhere.

Where are you seeing this? I’ve thought of duplicate events too, and I can probably create a little automation for only the event of this one automation based on an event trigger and not a state trigger. That said, the HA devs have been pretty clear that even if there are multiple events, if they result in the same (current) state, there won’t be a state trigger.

Not that I can think of.

What caught me is your own logbook screenshot. It mentions twice the last backup changed to March 27, 2:05 AM, the first time at (no surprise) 2:05 AM, but then again at 9:43 PM, but mentioning the same backup date time of 2:05 AM. That seems weird - even if you backup twice a day it should mention a different time, not the earlier one.

Oh, good spot!

The odd times you see are times when I restarted HA. I normally work on it a bit in the evenings when I have time.

I know it was the case here and for the previous screenshot.

It’s probably the state getting restored upon start-up.

I really thought we (you) might be onto something.