Did you see the issue during this time? The lines “Serving /api/nest/event_media/…” are showing the requests arriving, then reading the media files from disk so you can see exactly which files it was looking for.
Now that you mention, I don’t recognize that event. There’s nothing in my Google Nest event log and my automation hasn’t been fired at 07:46. The closest event was at 07:31, but the event ID from the “Serving /api/nest/event_media/…” log statement does not match the one I received at 07.31 from my HA automation.
Also there exist no file created at 07:46, so even if it’s an older file, it’s weird that it takes so long to finally download it?
That is the time when an automation ran or when the notification happened (what we are debugging right?) or when it was shown in the media player. That is not a new event.
- The automation ran at 7:30. I received a notification but with no image as usual.
- The “Serving /api/nest/event_media/…” log statement was written at 7:46. I don’t know what event it is refering to, because there is no event at that time.
- I only have an MP4 from 7:31, but it was never attached and I cannot find any
homeassistant.components.http.viewlog statements from 7:30-7:31.
The images are just to show you that I received the event with no image attachment, and that I cannot find any events from 7:46
Ok, so that means the mobile app did not talk to home assistant? The request never arrived…
(7:46 is request time not event time)
Yes, but why is the request being made so late, when no event happened around 7:46?
I mean, I need you to tell me… were you viewing the media player to check if the media existed?
From this test we can see the media was recorded successfully. I don’t think I see from this detail if there is a problem with the automation requesting the image, but it doesn’t appear to arrive.
I was just wondering why the request was made at 7:46, when no event happened during that time.
But yes I agree. The media is indeed recorded and saved successfully, but still no image in the notification. I can see from another thread, that I’m not the only one having this problem:
Yes, it seems like the mobile app isn’t making the request to fetch the image? Not sure if thats the same request and it happens much later or what, but it might be good to try again and see what a normal working path looks like then what the failure one looks like. I recommend excluding stuff outside of the time range that is relevant to the notifications.
What do you mean exactly by " the mobile app isn’t making the request to fetch the image?". Are you referring to the “/api/nest/event_media/…” request? Because I’m pretty sure it does, but the image doesn’t seem to be available at the time it is requesting the image.
I’ve recently tried to set a delay of 1 minute.
So just to summarize:
- Person detected event triggers
- 1 minute delay
- Send notification and attach image and video
It seems to work 90% of the time now, which is better than 1%, but there’s as you can see still a few clip previews missing.
Hi,
We turned up logging so we can see the requests arriving to home assistant. My impression is we saw the media saved on disk but didn’t see the requests for the media in the logs.
Hmm I think I see two patterns.
- The media is being requested by the automation before it is done saving it
- The media is never saved
Because as mentioned. It helped a lot after setting a delay for 1 minute, so that must mean that it just needs a little time to get ready, but in situations where this is not the case, I get the following error message in the log:
2023-01-08 12:56:02.101 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] The current deadline value is 10 seconds.
2023-01-08 12:56:02.102 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] Snoozing lease management for 4.392832 seconds.
2023-01-08 12:56:04.591 DEBUG (Thread-Heartbeater) [google.cloud.pubsub_v1.subscriber._protocol.heartbeater] Sent heartbeat.
2023-01-08 12:56:05.653 DEBUG (MainThread) [homeassistant.components.http.auth] Authenticated 87.49.147.137 for /api/nest/event_media/34bf6f2934862c9538f6f3ace8125419/WyIxNjMzMjA2MTk3IiwgIjY4OTAzNjY3OCJd using bearer token
2023-01-08 12:56:05.653 DEBUG (MainThread) [homeassistant.components.http.view] Serving /api/nest/event_media/34bf6f2934862c9538f6f3ace8125419/WyIxNjMzMjA2MTk3IiwgIjY4OTAzNjY3OCJd to 87.49.147.137 (auth: True)
2023-01-08 12:56:05.662 DEBUG (MainThread) [google_nest_sdm.event_media] No persisted media for event id <EventToken event_session_id1633206197 event_id=689036678>
2023-01-08 12:56:05.662 DEBUG (MainThread) [homeassistant.components.nest] No event found for event_id 'WyIxNjMzMjA2MTk3IiwgIjY4OTAzNjY3OCJd'
This is from one of the two notifications with a 404 you see on the attached images where it says “2 t. siden” and “3 t. siden”. Here I waited 1 minute, and you can see the request is being made by the HTTP service, but no persisted media for the given event is found.
Do you have the log entries for that event where it is received and published?
I suggest disabling everything under google.cloud.pubsub_v1.subscriber as it is not really relevant.
Not sure if this is what you mean, but this is one minute before. When the event actually occurred:
2023-01-08 12:55:00.694 DEBUG (MainThread) [google_nest_sdm.event] EventMessage raw_data={'eventId': '77c0fa90-23b3-4c99-9383-7a306cbd6bdd', 'timestamp': '2023-01-08T11:54:56.601Z', 'resourceUpdate': {'name': 'enterprises/20acf40f-33eb-4019-92be-686e464ca919/devices/AVPHwEttFask-hEGzUkEqFXAXRywmTXJC8OzVvlPp6JNKb-npc5vmk9y4EvuTPed1cjGE_oNRT4IVHafgrf9D21Ln_fMaA', 'events': {'sdm.devices.events.CameraPerson.Person': {'eventSessionId': '1633206197', 'eventId': '689036678', 'zones': ['']}}}, 'userId': 'AVPHwEt1g5AoYr8Ti49Qygg1LXO6us7Rw83iNkEgnwcQ', 'eventThreadId': '8c70fa62-3e1d-4223-8711-ac2dec050d34', 'resourceGroup': ['enterprises/20acf40f-33eb-4019-92be-686e464ca919/devices/AVPHwEttFask-hEGzUkEqFXAXRywmTXJC8OzVvlPp6JNKb-npc5vmk9y4EvuTPed1cjGE_oNRT4IVHafgrf9D21Ln_fMaA'], 'eventThreadState': 'STARTED'}
2023-01-08 12:55:00.694 DEBUG (MainThread) [google_nest_sdm.device] Processing update 77c0fa90-23b3-4c99-9383-7a306cbd6bdd @ 2023-01-08 11:54:56.601000+00:00
2023-01-08 12:55:00.694 DEBUG (MainThread) [google_nest_sdm.event_media] Event Update dict_keys(['1633206197'])
2023-01-08 12:55:00.723 DEBUG (MainThread) [google_nest_sdm.camera_traits] Ignoring event, not the right type: <ImageEventBase {'event_type': 'sdm.devices.events.CameraPerson.Person', 'event_data': {'eventSessionId': '1633206197', 'eventId': '689036678', 'zones': ['']}, 'timestamp': '2023-01-08T11:54:56.601000+00:00', 'event_image_type': 'image/jpeg'} sessions=1>
2023-01-08 12:55:00.739 INFO (MainThread) [google_nest_sdm.event_media] Checking cache size 314
2023-01-08 12:55:00.739 DEBUG (MainThread) [homeassistant.components.nest] Event Update dict_keys(['sdm.devices.events.CameraPerson.Person'])
2023-01-08 12:55:00.741 INFO (MainThread) [homeassistant.components.automation.person_set_for_dorklokke_test] Person set for dørklokke (test): Running automation actions
2023-01-08 12:55:00.741 INFO (MainThread) [homeassistant.components.automation.person_set_for_dorklokke_test] Person set for dørklokke (test): Executing step delay 0:01:00
2023-01-08 12:55:00.743 DEBUG (Thread-CallbackRequestDispatcher) [google.cloud.pubsub_v1.subscriber._protocol.dispatcher] Handling 1 batched requests
OK thanks for the detail. I’m finding it difficult to read this one small piece at a time, os how about we move this into a github issue under home assistant Core? That will help me since it will ask you for full diagnostics information which will include details about all your devices, etc. Then you can include the logs for one single end-to-end event from the time the message is delivered to the time the notification is fired, including your automation examples, etc in one place (excluding the stuff that isn’t relevant). Would you be up for doing that? I think we have everything we need for a full issue now.
From the looks of this, it appears like the nest person event did not include a CameraClipPreviewEvent.
Sure, I will do that 
Can someone link to that github issue? I think pretty much everyone experiences this with nest doorbell. Ive got a bad feeling it basically takes google minutes to upload the MP4, making it unusable for the use cases we care about.
Yes. The issue has been closed, but I’m not really sure if the issue is actually fixed. The new version of Home Assistant Core has caused a new error, which I’m also linking to from the issue.
You can find it here: Problems retrieving videos/clips from Google Nest Camera · Issue #85551 · home-assistant/core (github.com)