core icon indicating copy to clipboard operation
core copied to clipboard

Duplicate push notification

Open parautenbach opened this issue 3 years ago • 24 comments

The problem

I have a fairly simply automation that sometimes results in a duplicate notification. It's not the only one that exhibits this behaviour, but for simplicity of debugging the issue I'm focusing on only this one.

- 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

I logged this issue the first time in March on the forum in case it was an issue on my side. After some assistance from @zacwest it seems like I should report this as a bug.

Zac made a few suggestions, among which to include a random number to establish if it is indeed a duplicate notification and not simply a second notification due to some other issue.

I was already sure at the start that there isn't a duplicate event or state change – at least not what could be seen via the UI tools.

image

image

image

When I first logged this I was on 2022.2.9. I'm now on 2022.5.4. I keep my iOS companion app up to date all the time.

This is what the duplicate notification looks like:

image

Home Assistant.txt:

2022-05-20 17:53:13.339 [Info] [hakit-work-queue] [Environment.swift:71] init() > WebSocket: Received: event: for HARequestIdentifier(rawValue: 711)
2022-05-20 17:53:13.339 [Info] [hakit-work-queue] [Environment.swift:71] init() > WebSocket: Received: event: for HARequestIdentifier(rawValue: 711)
2022-05-20 17:53:13.339 [Info] [hakit-work-queue] [Environment.swift:71] init() > WebSocket: Received: event: for HARequestIdentifier(rawValue: 711)
2022-05-20 17:53:13.340 [Info] [hakit-work-queue] [Environment.swift:71] init() > WebSocket: Received: event: for HARequestIdentifier(rawValue: 711)
2022-05-20 17:56:13.148 [Verbose] [main] [WebViewController.swift:1014] sendExternalBus(message:) > sending {"type":"command","id":-1,"command":"restart"}
2022-05-20 17:56:13.148 [Info] [hakit-work-queue] [Environment.swift:71] init() > WebSocket: Sending: {"id":712,"type":"ping"}
2022-05-20 17:56:13.154 [Verbose] [main] [NotificationManager.swift:236] userNotificationCenter(_:didReceive:withCompletionHandler:) > User info in incoming not
ification [AnyHashable("webhook_id"): REDACTED, AnyHashable("url"): homeassistant://navigate/lovelace/de
vices, AnyHashable("aps"): {
    alert =     {
        body = "Systems shut down prior to loadshedding. (547)";
        title = System;
    };
    sound = default;
    "thread-id" = "system-general";
}] with response <UNNotificationResponse: 0x2827cc1e0; actionIdentifier: com.apple.UNNotificationDefaultActionIdentifier, notification: <UNNotification: 0x2827d
b540; source: io.robbie.HomeAssistant date: 2022-05-20 15:56:01 +0000, request: <UNNotificationRequest: 0x2827dacd0; identifier: 024FC8AC-8444-4D9B-9506-8C52493
BE92E, content: <UNNotificationContent: 0x2814df900; title: <redacted>, subtitle: (null), body: <redacted>, summaryArgument: , summaryArgumentCount: 0, category
Identifier: , launchImageName: , threadIdentifier: system-general, attachments: (
), badge: (null), sound: <UNNotificationSound: 0x280398850>, realert: 0, interruptionLevel: 1, relevanceScore: 0.00, trigger: (null)>, intents: (
)>>
2022-05-20 17:56:13.154 [Info] [main] [NotificationManager.swift:250] userNotificationCenter(_:didReceive:withCompletionHandler:) > launching URL homeassistant:
//navigate/lovelace/devices
2022-05-20 17:56:13.386 [Error] [main] [Environment.swift:72] init() > WebSocket: Error: Optional(POSIXErrorCode(rawValue: 53): Software caused connection abort
)
2022-05-20 17:56:13.386 [Info] [main] [Environment.swift:71] init() > WebSocket: phase transition to disconnected(error: Optional(POSIXErrorCode(rawValue: 53):
Software caused connection abort), forReset: false)
2022-05-20 17:56:13.386 [Info] [main] [Environment.swift:71] init() > WebSocket: disconnecting; permanently: false, error: Optional(POSIXErrorCode(rawValue: 53)
: Software caused connection abort)
2022-05-20 17:56:13.386 [Info] [main] [Environment.swift:71] init() > WebSocket: phase transition to disconnected(error: nil, forReset: true)
2022-05-20 17:56:13.387 [Info] [main] [WebhookManager.swift:217] sendEphemeral(server:request:) > sending to historic: WebhookRequest(type: "update_registration
", data: ["manufacturer": "Apple", "model": "iPhone13,1", "app_data": ["push_url": "https://mobile-apps.home-assistant.io/api/sendPushNotification", "push_token
": "REDACTED"], "os_version": "15.5", "app_version": "2022.3 (2022.358)", "device_name": "Ceres"], localMetadata: nil)
2022-05-20 17:56:13.388 [Verbose] [main] [WebViewController.swift:835] userContentController(_:didReceive:) > message {     id = "-1";     result = "<null>";
  success = 1;     type = result; }
2022-05-20 17:56:13.388 [Error] [main] [WebViewController.swift:997] handleExternalMessage(_:) > unknown: result
2022-05-20 17:56:13.419 [Info] [main] [Environment.swift:71] init() > WebSocket: connecting using HAConnectionInfo(url: http://homeassistant.local:8123, userAge
nt: Optional("Home Assistant/2022.3 (io.robbie.HomeAssistant; build:2022.358; iOS 15.5.0)"), engine: nil)
2022-05-20 17:56:13.422 [Verbose] [main] [IncomingURLHandler.swift:16] handle(url:) > Received URL: homeassistant://navigate/lovelace/devices
2022-05-20 17:56:13.552 [Info] [main] [Environment.swift:71] init() > WebSocket: Viability changed: true
2022-05-20 17:56:13.559 [Info] [main] [Environment.swift:71] init() > WebSocket: connected with headers: ["Content-Type": "application/octet-stream", "Connectio
n": "upgrade", "Sec-WebSocket-Accept": "Z2OGWnybF3xoqPFrK4t7UDvCHjU=", "Date": "Fri, 20 May 2022 15:56:13 GMT", "Upgrade": "websocket", "Server": "Python/3.9 ai
ohttp/3.8.1", "Sec-WebSocket-Extensions": "permessage-deflate"]
2022-05-20 17:56:13.559 [Info] [main] [Environment.swift:71] init() > WebSocket: phase transition to auth

HomeAssistant-Extensions-PushProvider.txt:

2022-05-20 17:53:28.421 [Info] [main] [Environment.swift:71] init() > WebSocket: Ping
2022-05-20 17:53:43.563 [Info] [hakit-work-queue] [Environment.swift:71] init() > WebSocket: Sending: {"id":2136,"type":"ping"}
2022-05-20 17:53:43.571 [Info] [hakit-work-queue] [Environment.swift:71] init() > WebSocket: Received: result success HARequestIdentifier(rawValue: 2136)
2022-05-20 17:54:39.405 [Info] [main] [Environment.swift:71] init() > WebSocket: Ping
2022-05-20 17:55:16.442 [Info] [hakit-work-queue] [Environment.swift:71] init() > WebSocket: Sending: {"id":2137,"type":"ping"}
2022-05-20 17:55:16.503 [Info] [hakit-work-queue] [Environment.swift:71] init() > WebSocket: Received: result success HARequestIdentifier(rawValue: 2137)
2022-05-20 17:56:01.785 [Info] [hakit-work-queue] [Environment.swift:71] init() > WebSocket: Received: event: for HARequestIdentifier(rawValue: 2097)
2022-05-20 17:56:01.789 [Debug] [main] [LocalPushManager.swift:161] handle(event:) > handling LocalPushEvent(confirmID: Optional("REDACTED"), identifier: "REDACTED", contentWithoutServer: <UNNotificationContent: 0x13be72620; title: System, subtitle: (null), body: Systems shut down prior to loadshedding. (547), summaryArgument: , summaryArgumentCount: 0, categoryIdentifier: , launchImageName: , threadIdentifier: system-general, attachments: (
), badge: (null), sound: <UNNotificationSound: 0x13be620c0>, realert: 0, interruptionLevel: 1, relevanceScore: 0.00)
2022-05-20 17:56:01.799 [Info] [hakit-work-queue] [Environment.swift:71] init() > WebSocket: Sending: {"confirm_id":"REDACTED","id":2138,"type":"mobile_app\/push_notification_confirm","webhook_id":"REDACTED"}
2022-05-20 17:56:01.807 [Info] [main] [PushProvider.swift:163] localPushManager(_:didReceiveRemoteNotification:) > failed: notCommand
2022-05-20 17:56:01.808 [Info] [hakit-work-queue] [Environment.swift:71] init() > WebSocket: Received: result failure HARequestIdentifier(rawValue: 2138): external(HAKit.HAError.ExternalError(code: "not_found", message: "Push notification channel not found")) via {"id":2138,"type":"result","success":false,"error":{"code":"not_found","message":"Push notification channel not found"}}
2022-05-20 17:56:01.808 [Error] [main] [NotificationAttachmentManager.swift:47] content(from:api:) > failed at getting attachment info: noAttachment
2022-05-20 17:56:01.808 [Info] [main] [NotificationAttachmentManager.swift:74] content(from:api:) > delivering content <UNMutableNotificationContent: 0x13bf60b10; title: <redacted>, subtitle: (null), body: <redacted>, summaryArgument: , summaryArgumentCount: 0, categoryIdentifier: , launchImageName: , threadIdentifier: system-general, attachments: (
), badge: (null), sound: <UNNotificationSound: 0x13be620c0>, realert: 0, interruptionLevel: 1, relevanceScore: 0.00
2022-05-20 17:56:01.817 [Error] [main] [LocalPushManager.swift:172] handle(event:) > failed to confirm local push: external(HAKit.HAError.ExternalError(code: "not_found", message: "Push notification channel not found"))
2022-05-20 17:56:01.837 [Info] [main] [LocalPushManager.swift:188] handle(event:) > added local notification
~

This seems to be the key to the issue:

2022-05-20 17:56:01.807 [Info] [main] [PushProvider.swift:163] localPushManager(_:didReceiveRemoteNotification:) > failed: notCommand

It seems like the local push fails and then the notification gets sent externally.

What version of Home Assistant Core has the issue?

core-2022.5.4

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

notify

Link to integration documentation on our website

https://www.home-assistant.io/integrations/notify/

Diagnostics information

I'd be happy to share the ZIP file of the companion app logs, but I don't know how to easily sanitise it.

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

parautenbach avatar May 22 '22 19:05 parautenbach

notify documentation notify source (message by IssueLinks)

Hey there @home-assistant/core, mind taking a look at this issue as it has been labeled with an integration (notify) you are listed as a code owner for? Thanks! (message by CodeOwnersMention)

I think the notable error is actually:

2022-05-20 17:56:01.808 [Info] [hakit-work-queue] [Environment.swift:71] init() > WebSocket: Received: result failure HARequestIdentifier(rawValue: 2138): external(HAKit.HAError.ExternalError(code: "not_found", message: "Push notification channel not found")) via {"id":2138,"type":"result","success":false,"error":{"code":"not_found","message":"Push notification channel not found"}}

It seems like the confirmation code response handler is having an issue finding the pending response, but it's also still doing the 10 second wait and firing through the HTTP call, making me think it's failing to add the "cancel this retry" value to the dictionary.

zacwest avatar May 24 '22 01:05 zacwest

Just posting a quick update: It's still happening (HA 2022.6.6 and iOS 2022.3), but I did notice that clearing one of the two notifications actually clears both. Not sure if it's important, but mentioning it nonetheless. I'm guessing it would only happen if iOS think it's the same notification.

parautenbach avatar Jun 17 '22 19:06 parautenbach

Another bit of info that might help: I noticed that when I clear the one notification, it removes both. Probably just confirms that it is an identical notification (e.g. if there's an underlying unique ID being used, both have the same ID).

parautenbach avatar Jun 24 '22 15:06 parautenbach

I don’t have the logs but I am seeing this exact issue on 2022.7–running in a VM Box. Clearing one notification clears the other automatically and it’s only happening with some notifications.

ryanhindinger avatar Aug 04 '22 02:08 ryanhindinger

Hopefully another instance of this issue can help us debug this pesky issue. Which mobile client (and version) are you seeing this on? Android or iOS?

parautenbach avatar Aug 04 '22 04:08 parautenbach

I am seeing this on iOS v15.5 with Home Assistant companion app version 2022.3 installed. Not sure if it helps but my notifications are all being fired out of NodeRed—including the ones that are duplicating and those that aren’t.

ryanhindinger avatar Aug 04 '22 04:08 ryanhindinger

Could you share more about your settings? Do you have local push enabled?

parautenbach avatar Sep 06 '22 08:09 parautenbach

I also occasionally get duplicate notifications on my Android devices (mine and my wife's Pixel phones). I am not using Local Push.

Home Assistant 2022.7.6 Supervisor 2022.09.1 Operating System 8.2

Below is the automation from which the notifications originate. I am happy to provide additional information as needed.

alias: Doorbell Motion
description: ''
trigger:
  - platform: state
    entity_id:
      - binary_sensor.doorbell_motion_detected
    from: 'off'
    to: 'on'
    for:
      hours: 0
      minutes: 0
      seconds: 1
condition:
  - condition: template
    value_template: >-
      {{ (as_timestamp(now()) -
      as_timestamp(states.automation.doorbell_motion.attributes.last_triggered |
      default(0)) | int > 120)}}
  - condition: time
    before: '22:00:00'
    after: '06:00:00'
action:
  - service: camera.snapshot
    data:
      filename: /config/www/tmp/snapshot.jpg
    target:
      entity_id: camera.doorbell_cropped
  - service: notify.all_phones
    data:
      message: Front door
      title: Motion Detected
      data:
        channel: Doorbell
        importance: max
        group: Doorbell
        image: /local/tmp/snapshot.jpg
        ttl: 0
        priority: high
        clickAction: entityId:camera.doorbell_low
mode: single

creeve4 avatar Sep 22 '22 14:09 creeve4

Same here. I'm running 3 diffret Android device with curret versio of the app. All receiving notifications duplicates.

SS from noti history. Screenshot_20221103_224417

Edit: doesn't make a different if I'm on or off wifi.

caladrien avatar Nov 03 '22 21:11 caladrien

This is still an ongoing issue. I've even had a case recently where the notification showed in triplicate. It really is the same notification, as was indicated by the logs before, but also since one can see in this screen capture chat clearing the one clears them all.

https://user-images.githubusercontent.com/743320/209689288-7b5d734a-2cf2-4316-b251-c31e270b0d33.mov

parautenbach avatar Dec 27 '22 15:12 parautenbach

I solved it for me. The reason seams to be an defective cache of the android home assistant app. I received as many notifications as I had logged in with different credentials in the app. In the beginning of home assistant I was playing around with users so lot. Clearing the apps' cache and data left me with only one notification.

caladrien avatar Jan 07 '23 17:01 caladrien

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

Still an issue.

parautenbach avatar Apr 07 '23 19:04 parautenbach

Still an issue.

Try to reset Push ID. It helped me.

DenisBY avatar Apr 09 '23 13:04 DenisBY

Thanks, I see it hasn't been mentioned, but unfortunately it doesn't fix this specific issue.

EDIT: I remembered: This was covered on the HA post about this issue.

parautenbach avatar Apr 09 '23 15:04 parautenbach

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

Still happens, unfortunately.

parautenbach avatar Jul 10 '23 07:07 parautenbach

I am having the same issue of duplicate or occasionally quadruple notifications.

My Home Assistant version is 2023.8.4 and the iOS app is on the latest version: 2023.460.

I have followed a few steps that were recommended in the original forum thread as well as some solutions mentioned here on Github- without any success. My attempts to resolve this included:

  1. Checking my automation yaml for duplicate entries.
  2. Companion App: Notifications > Reset 'Push ID'
  3. Companion App: Debugging > Reset Frontend Cache
  4. Companion App: Debugging > Reset
  5. Ensured automation mode is set to single- added a delay to my automation to avoid it being executed more than once.
  6. Companion App: Server Settings > Disable Local Push

. The following is my automation:

alias: Notification - Entrance Door Sensor - Open
description: ""
trigger:
  - platform: mqtt
    topic: zigbee2mqtt/hallway.doorsensor
    value_template: "{{value_json.contact}}"
    payload: false
condition: []
action:
  - service: notify.mobile_app_11pro
    data:
      title: Home
      message: Door Opened
  - delay:
      hours: 0
      minutes: 1
      seconds: 0
      milliseconds: 0
mode: single

I am also coming across the following message in my HA logs:

Logger: homeassistant.components.websocket_api.http.connection
Source: components/websocket_api/http.py:51
Integration: Home Assistant WebSocket API (documentation, issues)
First occurred: September 1, 2023 at 1:21:01 AM (6 occurrences)
Last logged: 8:18:58 AM

[140667676457280] from 192.168.1.2 (Home Assistant/2023.4 (io.robbie.HomeAssistant; build:2023.460; iOS 17.0.0)): Disconnected: Did not receive auth message within 10 seconds
[140667190099136] from 192.168.1.2 (Home Assistant/2023.4 (io.robbie.HomeAssistant; build:2023.460; iOS 17.0.0)): Disconnected: Did not receive auth message within 10 seconds
[140665198316352] from 192.168.1.2 (Home Assistant/2023.4 (io.robbie.HomeAssistant; build:2023.460; iOS 17.0.0)): Disconnected: Did not receive auth message within 10 seconds
[140666943905344] from 192.168.1.2 (Home Assistant/2023.4 (io.robbie.HomeAssistant; build:2023.460; iOS 17.0.0)): Disconnected: Did not receive auth message within 10 seconds
[140666183875392] from 192.168.1.109 (Home Assistant/2023.4 (io.robbie.HomeAssistant; build:2023.460; iOS 17.0.0)): Disconnected: Did not receive auth message within 10 seconds




Logger: homeassistant.components.websocket_api.http.connection
Source: components/websocket_api/connection.py:175
Integration: Home Assistant WebSocket API (documentation, issues)
First occurred: September 2, 2023 at 2:55:41 PM (3 occurrences)
Last logged: 8:18:49 AM

[140667569995584] Received invalid command: {'access_token': 'xxx_greyedout_a', 'type': 'auth'}
[140667207352640] Received invalid command: {'access_token': 'xxx_greyedout_b', 'type': 'auth'}

To give a bit more context, the issue started happening for me when I duplicated the above existing automation via the iOS app, in order to create a new automation for the door sensor. The new automation does not include sending a notification- it simply plays some media, when the door is opened. I tried disabling this new automation to see if the issue would persist and unfortunately it does. I also double checked the mode of both automations because I wanted to make sure that these are set to "single".

Finally, an interesting observation: when executing the automation via the app using the "run" function, I only receive a single notification.

In case there is more information required, I'd be happy to provide this.

Thanks for your help!

onestix avatar Sep 04 '23 07:09 onestix

Getting the same issues on Android... I'm creating the notification via call_service over the websocket api to the local instance. So pretty sure it's not a "broken" automation

Seeing this is the log

10-22 16:57:02.020 20540 21088 W FirebaseMessaging: Unable to log event: analytics library is missing
10-22 16:57:02.020 20540 21088 D FCMService: From: 331041709873
10-22 16:57:02.023 20540 20540 D MessagingService: Creating notification with following data: {webhook_id=xxx, message=hi, server_id=-1}
10-22 16:57:02.028 20540 20540 D MessagingService: Show notification with tag "null" and id "1478140100"
10-22 16:57:03.272 20540 21088 W FirebaseMessaging: Unable to log event: analytics library is missing
10-22 16:57:03.272 20540 21088 D FCMService: From: 331041709873
10-22 16:57:03.274 20540 20540 D MessagingService: Creating notification with following data: {webhook_id=xxx, message=hi, server_id=2}
10-22 16:57:03.279 20540 20540 D MessagingService: Show notification with tag "null" and id "1478141352"

the server_id part caught my eye I do have nabucasa's HA Cloud connected. A bit naïve... is that the other "server"

Maybe a clue... maybe not

Home Assistant 2023.10.3 Supervisor 2023.10.0 Operating System 11.0 Frontend 20231005.0 - latest

Companion aoo: 2023.10.2-full

AndyPook avatar Oct 22 '23 16:10 AndyPook

Ah, thanks for capturing that. It's indeed still an issue for on iOS too. I haven't been able to catch the information you have. Perhaps the iOS logs are different.

You might want to remove/obfuscate those webhook IDs though.

parautenbach avatar Oct 22 '23 18:10 parautenbach

Commenting to follow and leave my details as well:

Core: 2023.11.2 Supervisor: 2023.11.3 OS: 11.1 Frontend: 20231030.2 iOS App: 2023.471

alienator88 avatar Nov 14 '23 22:11 alienator88

FYI... my version of this "problem" has been resolved

It turns out that there was a reference to an old phone. Somehow this resulted in the notification to both phones. But as the old one no longer exists it was redirected to the new phone. (or something like that) Hard to replicate now I only have a single phone.

(you can search /config/.storage/core.entity_registration for your various phone names to see if this is the thing for you) Managed to find some references to the old phone, found the offending items, deleted. Now I only get a single notification

AndyPook avatar Dec 26 '23 21:12 AndyPook

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

It still happens with varying degrees: Sometimes many notifications will be duplicated, sometimes only one or two (over the span of a day).

parautenbach avatar Mar 26 '24 07:03 parautenbach

Hello! Happens on mine and my wife's device too. Several times throughout the day.

Versions: iOS: 17.4.1 (iPhone 13 Pro and iPhone 13) iOS HA App: 2024.3 (2024.608)

HA: Core 2024.3.3 Supervisor 2024.03.0 Operating System 12.1 Frontend 20240307.0

lesgrebe avatar Mar 27 '24 09:03 lesgrebe

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

This still happens.

parautenbach avatar Jun 25 '24 10:06 parautenbach

Yes, I can confirm same symptoms as @parautenbach. Has been happening for a long time, but finally decided to look into it...

pbutterworth avatar Jul 18 '24 08:07 pbutterworth