Tagged notifications sometimes coming out of order on Android

Configuration
1

I have an automation set up that sends HTML5 notifications when the lock on my front door is locked/unlocked.

If I do either of those actions and check my phone immediately, I seem to get the right notification. However, if I do them both in quick succession - an unlock and then a re-lock, and then check my phone afterwards, the notification I see is often (but not always) the unlock notification, despite the door actually being locked.

My hass logs indicate that the notifications are being sent in the correct order, so I’m wondering if there’s some kind of sequencing data I can provide in the event.

This is my automation:

  • alias: ‘Front door notifications’
    trigger:
    • platform: state
      entity_id: lock.locked
      condition:
    • condition: template
      value_template: ‘{{ trigger.to_state.state != trigger.from_state.state }}’
      action:
    • service: notify.notify
      data_template:
      message: “Door was {{ states(‘lock.locked’) }}.”
      data:
      title: ‘Front door’
      data:
      tag: ‘front-door-notification’

And a log from the last run, which exhibited this problem:

2018-09-26 07:50:23 INFO (MainThread) [homeassistant.helpers.script] Script Front door notifications: Executing step call service
2018-09-26 07:50:23 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=notify, service_data=title=Front door, message=Door was unlocked., data=tag=front-door-notification, service=notify>
2018-09-26 07:50:23 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state group.all_locks=locked; friendly_name=all locks, hidden=True, entity_id=(‘lock.locked’,), auto=True, order=26 @ 2018-09-26T07:30:47.821056-07:00>, entity_id=group.all_locks, new_state=<state group.all_lo
cks=unlocked; friendly_name=all locks, hidden=True, entity_id=(‘lock.locked’,), auto=True, order=26 @ 2018-09-26T07:50:23.725531-07:00>>

[…]

2018-09-26 07:50:28 INFO (MainThread) [homeassistant.helpers.script] Script Front door notifications: Executing step call service
2018-09-26 07:50:28 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=notify, service_data=title=Front door, message=Door was locked., data=tag=front-door-notification, service=notify>
2018-09-26 07:50:28 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state group.all_locks=unlocked; friendly_name=all locks, hidden=True, entity_id=(‘lock.locked’,), auto=True, order=26 @ 2018-09-26T07:50:23.725531-07:00>, entity_id=group.all_locks, new_state=<state group.all_
locks=locked; friendly_name=all locks, hidden=True, entity_id=(‘lock.locked’,), auto=True, order=26 @ 2018-09-26T07:50:28.811320-07:00>>

Any ideas?

2

It seems like this might be an unavoidable consequence of these messages going through GCM.

“GCM does not guarantee the order of delivery.”

I just switched my automation to say “Door lock was operated”, which is a bit less useful but is at least accurate.

3

Do you only see the latest message or all of them? If all of them what about putting a time stamp in your message to give you an idea of when the event happened?

They may still arrive out of order but you should then be able to tell the correct order.

message: “Door was {{ states('lock.locked') }} at {{ now().strftime("%Y-%m-%d %H:%M:%S") }}."

4

Do you only see the latest message or all of them?

Since I’m using a message tag, I only see one of them.

If all of them what about putting a time stamp in your message to give you an idea of when the event happened?

If I remove the message tag, that might be useful - I could scan through and find the latest event. Though the system’s built-in notification timestamps might work just as well as anything I can add to the message. I’ll experiment a bit with this to see how usable it is. Thanks.