Nest Doorbell (battery) does not store all videos into media folder

LukasMendez · December 22, 2022, 10:37am

Hi.

I’m to add clip previews to my notifications from my Google Nest Doorbell (Battery, but wired).
I keep getting a “Response status code was unacceptable: 404” when sending the notification to my iOS device doing exactly what is described here.

I noticed that when checking my media, not all of the events are saved. It is in fact very sporadic, sometimes videos are saved, and sometimes they are not, but events are always fired.

For example this morning at 5:56 AM i received a person detected event, but the image/video failed to be attached to the notification. I’m not sure how the API works, but I assume that it tries to fetch the videos from the media folder, so if nothing exist, that will explain why it gives me a 404 not found.

But the main question is, why is there no video?

This is the log I got from this morning:

2022-12-22 05:56:16.787 DEBUG (Thread-ConsumeBidirectionalStream) [google.cloud.pubsub_v1.subscriber._protocol.streaming_pull_manager] Processing 1 received message(s), currently on hold 0 (bytes 0).

2022-12-22 05:56:16.868 DEBUG (Thread-ConsumeBidirectionalStream) [google.cloud.pubsub_v1.subscriber._protocol.streaming_pull_manager] Released held message, scheduling callback for it, still on hold 0 (bytes 0).

2022-12-22 05:56:16.870 DEBUG (MainThread) [google_nest_sdm.event] EventMessage raw_data={'eventId': '58479af0-97aa-4a1f-aeab-9a36be8df98a', 'timestamp': '2022-12-22T04:56:12.441Z', 'resourceUpdate': {'name': 'enterprises/20acf40f-33eb-4019-92be-686e464ca919/devices/AVPHwEu2vapwfh6htn0AlI9ROe4noq5HBAE-wLPpru07J69eKaVUpBb8duVWRoBfQa8wFZDQUvW0xJKjbMe9VNlPApRNRg', 'events': {'sdm.devices.events.CameraPerson.Person': {'eventSessionId': '1661185442', 'eventId': '1709122460', 'zones': ['Zone 1']}}}, 'userId': 'AVPHwEt1g5AoYr8Ti49Qygg1LXO6us7Rw83iNkEgnwcQ', 'eventThreadId': 'd8ed5568-ea73-4632-a1f8-66febeed61b4', 'resourceGroup': ['enterprises/20acf40f-33eb-4019-92be-686e464ca919/devices/AVPHwEu2vapwfh6htn0AlI9ROe4noq5HBAE-wLPpru07J69eKaVUpBb8duVWRoBfQa8wFZDQUvW0xJKjbMe9VNlPApRNRg'], 'eventThreadState': 'STARTED'}

2022-12-22 05:56:16.870 DEBUG (MainThread) [google_nest_sdm.device] Processing update 58479af0-97aa-4a1f-aeab-9a36be8df98a @ 2022-12-22 04:56:12.441000+00:00

2022-12-22 05:56:16.870 DEBUG (MainThread) [google_nest_sdm.event_media] Event Update dict_keys(['1661185442'])

2022-12-22 05:56:16.873 DEBUG (MainThread) [homeassistant.components.nest.media_source] Loaded event store with 2 records

2022-12-22 05:56:16.874 INFO (MainThread) [google_nest_sdm.event_media] Checking cache size 42

2022-12-22 05:56:16.874 DEBUG (MainThread) [homeassistant.components.nest] Event Update dict_keys(['sdm.devices.events.CameraPerson.Person'])

2022-12-22 05:56:16.875 INFO (MainThread) [homeassistant.components.automation.person_set_fra_kamera_test] Person set fra kamera (Test): Running automation actions

2022-12-22 05:56:16.876 INFO (MainThread) [homeassistant.components.automation.person_set_fra_kamera_test] Person set fra kamera (Test): Executing step call service

2022-12-22 05:56:16.878 DEBUG (Thread-CallbackRequestDispatcher) [google.cloud.pubsub_v1.subscriber._protocol.dispatcher] Handling 1 batched requests

2022-12-22 05:56:17.736 DEBUG (Thread-ConsumeBidirectionalStream) [google.cloud.pubsub_v1.subscriber._protocol.streaming_pull_manager] Processing 1 received message(s), currently on hold 0 (bytes 0).

2022-12-22 05:56:17.804 DEBUG (Thread-ConsumeBidirectionalStream) [google.cloud.pubsub_v1.subscriber._protocol.streaming_pull_manager] Released held message, scheduling callback for it, still on hold 0 (bytes 0).

2022-12-22 05:56:17.805 DEBUG (Thread-ConsumeBidirectionalStream) [google.cloud.pubsub_v1.subscriber._protocol.streaming_pull_manager] Processing 1 received message(s), currently on hold 0 (bytes 0).

2022-12-22 05:56:17.806 DEBUG (MainThread) [google_nest_sdm.event] EventMessage raw_data={'eventId': '24895d96-8fef-4bed-acb7-1c94224e6204', 'timestamp': '2022-12-22T04:56:12.441Z', 'resourceUpdate': {'name': 'enterprises/20acf40f-33eb-4019-92be-686e464ca919/devices/AVPHwEu2vapwfh6htn0AlI9ROe4noq5HBAE-wLPpru07J69eKaVUpBb8duVWRoBfQa8wFZDQUvW0xJKjbMe9VNlPApRNRg', 'events': {'sdm.devices.events.CameraPerson.Person': {'eventSessionId': '1661185442', 'eventId': '1709122460', 'zones': ['Zone 1']}}}, 'userId': 'AVPHwEt1g5AoYr8Ti49Qygg1LXO6us7Rw83iNkEgnwcQ', 'eventThreadId': 'd8ed5568-ea73-4632-a1f8-66febeed61b4', 'resourceGroup': ['enterprises/20acf40f-33eb-4019-92be-686e464ca919/devices/AVPHwEu2vapwfh6htn0AlI9ROe4noq5HBAE-wLPpru07J69eKaVUpBb8duVWRoBfQa8wFZDQUvW0xJKjbMe9VNlPApRNRg'], 'eventThreadState': 'UPDATED'}

2022-12-22 05:56:17.806 DEBUG (MainThread) [google_nest_sdm.device] Processing update 24895d96-8fef-4bed-acb7-1c94224e6204 @ 2022-12-22 04:56:12.441000+00:00

2022-12-22 05:56:17.806 DEBUG (MainThread) [google_nest_sdm.event_media] Event Update dict_keys(['1661185442'])

2022-12-22 05:56:17.811 INFO (MainThread) [google_nest_sdm.event_media] Checking cache size 42

2022-12-22 05:56:17.812 DEBUG (MainThread) [google_nest_sdm.event] EventMessage raw_data={'eventId': '24895d96-8fef-4bed-acb7-1c94224e6204', 'timestamp': '2022-12-22T04:56:12.441Z', 'resourceUpdate': {'name': 'enterprises/20acf40f-33eb-4019-92be-686e464ca919/devices/AVPHwEu2vapwfh6htn0AlI9ROe4noq5HBAE-wLPpru07J69eKaVUpBb8duVWRoBfQa8wFZDQUvW0xJKjbMe9VNlPApRNRg', 'events': {}}, 'userId': 'AVPHwEt1g5AoYr8Ti49Qygg1LXO6us7Rw83iNkEgnwcQ', 'eventThreadId': 'd8ed5568-ea73-4632-a1f8-66febeed61b4', 'resourceGroup': ['enterprises/20acf40f-33eb-4019-92be-686e464ca919/devices/AVPHwEu2vapwfh6htn0AlI9ROe4noq5HBAE-wLPpru07J69eKaVUpBb8duVWRoBfQa8wFZDQUvW0xJKjbMe9VNlPApRNRg'], 'eventThreadState': 'UPDATED'}

2022-12-22 05:56:17.812 DEBUG (Thread-CallbackRequestDispatcher) [google.cloud.pubsub_v1.subscriber._protocol.dispatcher] Handling 1 batched requests

2022-12-22 05:56:17.879 DEBUG (Thread-ConsumeBidirectionalStream) [google.cloud.pubsub_v1.subscriber._protocol.streaming_pull_manager] Released held message, scheduling callback for it, still on hold 0 (bytes 0).

2022-12-22 05:56:17.880 DEBUG (MainThread) [google_nest_sdm.event] EventMessage raw_data={'eventId': '5a385b3f-b0cf-4e2f-a74e-5b6913a60396', 'timestamp': '2022-12-22T04:56:10.722Z', 'resourceUpdate': {'name': 'enterprises/20acf40f-33eb-4019-92be-686e464ca919/devices/AVPHwEttFask-hEGzUkEqFXAXRywmTXJC8OzVvlPp6JNKb-npc5vmk9y4EvuTPed1cjGE_oNRT4IVHafgrf9D21Ln_fMaA', 'events': {'sdm.devices.events.CameraPerson.Person': {'eventSessionId': '1633205949', 'eventId': '1284977112', 'zones': ['']}}}, 'userId': 'AVPHwEt1g5AoYr8Ti49Qygg1LXO6us7Rw83iNkEgnwcQ', 'eventThreadId': '0a676d7f-52db-4033-a4e0-d14211b9b820', 'resourceGroup': ['enterprises/20acf40f-33eb-4019-92be-686e464ca919/devices/AVPHwEttFask-hEGzUkEqFXAXRywmTXJC8OzVvlPp6JNKb-npc5vmk9y4EvuTPed1cjGE_oNRT4IVHafgrf9D21Ln_fMaA'], 'eventThreadState': 'STARTED'}

2022-12-22 05:56:17.880 DEBUG (MainThread) [google_nest_sdm.device] Processing update 5a385b3f-b0cf-4e2f-a74e-5b6913a60396 @ 2022-12-22 04:56:10.722000+00:00

2022-12-22 05:56:17.880 DEBUG (MainThread) [google_nest_sdm.event_media] Event Update dict_keys(['1633205949'])

2022-12-22 05:56:17.904 DEBUG (MainThread) [google_nest_sdm.camera_traits] Ignoring event, not the right type: <ImageEventBase {'event_type': 'sdm.devices.events.CameraPerson.Person', 'event_data': {'eventSessionId': '1633205949', 'eventId': '1284977112', 'zones': ['']}, 'timestamp': '2022-12-22T04:56:10.722000+00:00', 'event_image_type': 'image/jpeg'} sessions=1>

2022-12-22 05:56:17.926 INFO (MainThread) [google_nest_sdm.event_media] Checking cache size 227

2022-12-22 05:56:17.926 DEBUG (MainThread) [homeassistant.components.nest] Event Update dict_keys(['sdm.devices.events.CameraPerson.Person'])

2022-12-22 05:56:17.931 INFO (MainThread) [homeassistant.components.automation.person_set_for_dorklokke_test] Person set for dørklokke (test): Running automation actions

2022-12-22 05:56:17.931 INFO (MainThread) [homeassistant.components.automation.person_set_for_dorklokke_test] Person set for dørklokke (test): Executing step call service

2022-12-22 05:56:17.935 DEBUG (Thread-CallbackRequestDispatcher) [google.cloud.pubsub_v1.subscriber._protocol.dispatcher] Handling 1 batched requests

2022-12-22 05:56:18.723 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] The current deadline value is 10 seconds.

2022-12-22 05:56:18.724 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] Snoozing lease management for 8.704772 seconds.

2022-12-22 05:56:19.414 INFO (MainThread) [homeassistant.components.mobile_app.notify] mobile_app push notification rate limits for iPhone (57): 1 sent, 500 allowed, 0 errors, resets in 19:03:40

2022-12-22 05:56:19.486 INFO (MainThread) [homeassistant.components.mobile_app.notify] mobile_app push notification rate limits for iPhone (57): 1 sent, 500 allowed, 0 errors, resets in 19:03:40

2022-12-22 05:56:20.011 DEBUG (MainThread) [homeassistant.components.nest] No Nest Device found for '84f0bc207e506bcbc7f48d32ad5c491d'

2022-12-22 05:56:20.081 DEBUG (MainThread) [google_nest_sdm.event_media] No persisted media for event id <EventToken event_session_id1633205949 event_id=1284977112>

2022-12-22 05:56:20.083 DEBUG (MainThread) [homeassistant.components.nest] No event found for event_id 'WyIxNjMzMjA1OTQ5IiwgIjEyODQ5NzcxMTIiXQ=='

2022-12-22 05:56:24.391 DEBUG (Thread-Heartbeater) [google.cloud.pubsub_v1.subscriber._protocol.heartbeater] Sent heartbeat.

LukasMendez · December 23, 2022, 3:36pm

Do you know something about this @allenporter?

allenporter · December 23, 2022, 6:09pm

Hi,
The error message:

2022-12-22 05:56:20.011 DEBUG (MainThread) [homeassistant.components.nest] No Nest Device found for '84f0bc207e506bcbc7f48d32ad5c491d'

Seems to indicate the device id in the path is incorrect, so maybe start with that?

LukasMendez · December 23, 2022, 6:33pm

@allenporter Ok, is there any way that I can validate and check the device ID? I got the device ID from the trigger itself.

allenporter · December 23, 2022, 6:50pm

I suggest creating another trigger and confirming it is correct. (Using a trigger makes sense to me)

allenporter · December 23, 2022, 6:50pm

What’s the automation yaml look like?

allenporter · December 23, 2022, 6:52pm

I take it you have seen the examples? Google Nest - Home Assistant

The device is comes directly from the template variable so that has to be correct. Are you specifying the same way or manually?

LukasMendez · December 23, 2022, 8:37pm

This is what my automation URL looks like. So it’s almost copy paste from the documentation.

alias: Person seen (test)
description: Used for testing
trigger:
  - platform: device
    device_id: 34bf6f2934862c9538f6f3ace8125419
    domain: nest
    type: camera_person
condition: []
action:
  - service: notify.mobile_app_iphone_57
    data:
      message: >
        Device ID: {{ trigger.event.data.device_id }} Event ID: {{
        trigger.event.data.nest_event_id }}
      title: Der er set en person fra dørklokke kamera! (TEST)
      data:
        image: >
          /api/nest/event_media/{{ trigger.event.data.device_id }}/{{
          trigger.event.data.nest_event_id }}/thumbnail
        video: >
          /api/nest/event_media/{{ trigger.event.data.device_id }}/{{
          trigger.event.data.nest_event_id  }}
mode: single

LukasMendez · December 23, 2022, 8:38pm

Right now I’m using the input given from the trigger it self. I have previously tried specifying it manually just for debugging purposes, but it gives me the same error.

allenporter · December 23, 2022, 8:50pm

Perhaps you can capture the automation traces. Are you in fact seeing that the events contain the wrong device id? that is pretty odd.

allenporter · December 23, 2022, 8:58pm

It seems like you have multiple automations going on here, including one with an invalid device id. You can turn up debug logging for google_nest_sdm.event_media if you’d like more details about the media fetching side of things.

LukasMendez · December 23, 2022, 9:06pm

That’s correct. I have two cameras. A Nest Doorbell and an Outdoor Camera. They are both used in the same kind of automation. I once thought the outdoor camera could be used for downloading clip previews, but as I read in the documentation this is not possible. I just haven’t disabled the automation yet. I might do it and only focus on the doorbell, as this is where I’d like to get the media.
But I haven’t tried adding debug logs for google_nest_sdm.event_media, so I will try that and let you know if I find something useful

allenporter · December 23, 2022, 9:53pm

Ok that explains things, but still odd why the device is not found. Maybe it doesn’t support media (see supported devices)

As for the doorbell, here’s how it works for background:

server publishes a message
home assistant subscriber fetches the media for the message
home assistant published the event for the device
automation delivers notification with a URL back to get the media from home assistant

After #2 media will show up in the media player.

LukasMendez · December 24, 2022, 10:05am

In order to attach the media to a notification, does the media file have to exist locally in HA?

And yes it should support media, shouldn’t it?

allenporter · December 24, 2022, 1:41pm

Yes, the media has to be detached before it can be attached to a notification.

LukasMendez · December 26, 2022, 8:25pm

Alright. After some testing and debugging I realized that only some of the events are saved as MP4. Most of them are saved as .GIF.

I don’t really know why some of the MP4 clips are missing, maybe you know?

Another thing is. The event happened at 21.00.34 (9:00 PM), but the thumbnail took 4 minutes to get into the media folder (see image above, where it says 21.04 = 9:04 PM), which probably explains why it gives me a 404 when trying to attach it to my notification.

Do you know why some clips are missing and why it takes so long for the media to become available?

I’ve only had luck once as you can see in the following screenshot:

LukasMendez · December 26, 2022, 8:29pm

Also not sure if you can see something useful from these logs:

2022-12-26 21:00:34.417 DEBUG (MainThread) [google_nest_sdm.event] EventMessage raw_data={'eventId': '81637bf9-94a7-4e64-9187-f17020ed5652', 'timestamp': '2022-12-26T20:00:30.572Z', 'resourceUpdate': {'name': 'enterprises/20acf40f-33eb-4019-92be-686e464ca919/devices/AVPHwEttFask-hEGzUkEqFXAXRywmTXJC8OzVvlPp6JNKb-npc5vmk9y4EvuTPed1cjGE_oNRT4IVHafgrf9D21Ln_fMaA', 'events': {'sdm.devices.events.CameraPerson.Person': {'eventSessionId': '1633206030', 'eventId': '1040756873', 'zones': ['']}}}, 'userId': 'AVPHwEt1g5AoYr8Ti49Qygg1LXO6us7Rw83iNkEgnwcQ', 'eventThreadId': '2bb62b3c-bac6-4af4-b937-b07d3e16f6bd', 'resourceGroup': ['enterprises/20acf40f-33eb-4019-92be-686e464ca919/devices/AVPHwEttFask-hEGzUkEqFXAXRywmTXJC8OzVvlPp6JNKb-npc5vmk9y4EvuTPed1cjGE_oNRT4IVHafgrf9D21Ln_fMaA'], 'eventThreadState': 'STARTED'}
2022-12-26 21:00:34.417 DEBUG (MainThread) [google_nest_sdm.device] Processing update 81637bf9-94a7-4e64-9187-f17020ed5652 @ 2022-12-26 20:00:30.572000+00:00
2022-12-26 21:00:34.417 DEBUG (MainThread) [google_nest_sdm.event_media] Event Update dict_keys(['1633206030'])
2022-12-26 21:00:34.429 DEBUG (MainThread) [google_nest_sdm.camera_traits] Ignoring event, not the right type: <ImageEventBase {'event_type': 'sdm.devices.events.CameraPerson.Person', 'event_data': {'eventSessionId': '1633206030', 'eventId': '1040756873', 'zones': ['']}, 'timestamp': '2022-12-26T20:00:30.572000+00:00', 'event_image_type': 'image/jpeg'} sessions=1>
2022-12-26 21:00:34.441 INFO (MainThread) [google_nest_sdm.event_media] Checking cache size 254
2022-12-26 21:00:34.441 DEBUG (MainThread) [homeassistant.components.nest] Event Update dict_keys(['sdm.devices.events.CameraPerson.Person'])
2022-12-26 21:00:34.443 DEBUG (Thread-CallbackRequestDispatcher) [google.cloud.pubsub_v1.subscriber._protocol.dispatcher] Handling 1 batched requests
2022-12-26 21:00:34.444 INFO (MainThread) [homeassistant.components.automation.person_set_for_dorklokke_test] Person set for dørklokke (test): Running automation actions
2022-12-26 21:00:34.445 INFO (MainThread) [homeassistant.components.automation.person_set_for_dorklokke_test] Person set for dørklokke (test): Executing step call service
2022-12-26 21:00:34.945 INFO (MainThread) [homeassistant.components.mobile_app.notify] mobile_app push notification rate limits for iPhone (57): 14 sent, 500 allowed, 0 errors, resets in 3:59:25
2022-12-26 21:00:35.262 INFO (MainThread) 
2022-12-26 21:00:35.354 DEBUG (MainThread) [google_nest_sdm.event_media] No persisted media for event id <EventToken event_session_id1633206030 event_id=1040756873>

allenporter · December 26, 2022, 8:43pm

It first gets the mp4, then it is converting the mp4 to a .gif depending on the format that it is asked for. (e.g. you ask for image thumbnail and video, then its going to also create your thumbnail gif in addition to the mp4 video). If you sort by name you should be easier to see them matched up.

The thumbnail is created at request time so it is not surprising it is created later.

allenporter · December 26, 2022, 8:45pm

What is interesting to try to find is the request from the mobile app to your home assistant instance. I am not sure how to enable tracing for that to see why its getting a 404 error. The code is here: core/homeassistant/components/nest at 08586868f5adf5d6b23ec8254333588b018ef11d · home-assistant/core · GitHubinit.py#L349

Maybe turning up debug logging for homeassistant.components.http can give us details about the requests arriving.

LukasMendez · January 3, 2023, 6:54am

I’ve tried turning it on. I’m still unable to find anything useful, and the issue still remains the same.

2023-01-03 07:31:11.475 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] The current deadline value is 10 seconds.
2023-01-03 07:31:11.475 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] Snoozing lease management for 0.991000 seconds.
2023-01-03 07:31:12.467 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] The current deadline value is 10 seconds.
2023-01-03 07:31:12.467 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] Snoozing lease management for 8.705722 seconds.
2023-01-03 07:31:13.055 DEBUG (Thread-ConsumeBidirectionalStream) [google.cloud.pubsub_v1.subscriber._protocol.streaming_pull_manager] Processing 1 received message(s), currently on hold 0 (bytes 0).
2023-01-03 07:31:13.120 DEBUG (Thread-ConsumeBidirectionalStream) [google.cloud.pubsub_v1.subscriber._protocol.streaming_pull_manager] Released held message, scheduling callback for it, still on hold 0 (bytes 0).
2023-01-03 07:31:13.122 DEBUG (MainThread) [google_nest_sdm.event] EventMessage raw_data={'eventId': 'ad8eb510-be91-49d5-9c06-a68089f0261c', 'timestamp': '2023-01-03T06:30:46.710Z', 'resourceUpdate': {'name': 'enterprises/20acf40f-33eb-4019-92be-686e464ca919/devices/AVPHwEttFask-hEGzUkEqFXAXRywmTXJC8OzVvlPp6JNKb-npc5vmk9y4EvuTPed1cjGE_oNRT4IVHafgrf9D21Ln_fMaA', 'events': {'sdm.devices.events.CameraPerson.Person': {'eventSessionId': '1633206153', 'eventId': '536232160', 'zones': ['']}, 'sdm.devices.events.CameraClipPreview.ClipPreview': {'eventSessionId': '1633206153', 'previewUrl': 'https://nest-camera-frontend.googleapis.com/frontend/encrypted/clippreview/AVh7NxuDps3LODSTPuOGyVYnDmHFlmon14O34dFPUnZQQ8Qb27shrZKG0GK8EbdUoNOLXLrorYWyENl_2-eXlyuv-BTACfzEc6HGfJNYixA2IUbkY5WptlJGNDKGuxRPxhDiGZb_719LIEFRvH70UEbEI6y0Zhe_MqpnLGBoj1fI5peOA5CGORb9Q3CXY3TmWduvg62IE9d1ZbXe5vjkmXkstS6KiiE9ivn1V7gOAzf4Ese1PS-LWh8pA2BLbB0_8zAHEyCNK1C63d_0JDWhYP8QBAxwSX0GMyo6cfgsf2_nXKfLCuWZBru8'}}}, 'userId': 'AVPHwEt1g5AoYr8Ti49Qygg1LXO6us7Rw83iNkEgnwcQ', 'eventThreadId': '0fbcb6e4-abc8-46da-a6d8-3eaea41252a8', 'resourceGroup': ['enterprises/20acf40f-33eb-4019-92be-686e464ca919/devices/AVPHwEttFask-hEGzUkEqFXAXRywmTXJC8OzVvlPp6JNKb-npc5vmk9y4EvuTPed1cjGE_oNRT4IVHafgrf9D21Ln_fMaA'], 'eventThreadState': 'ENDED'}
2023-01-03 07:31:13.122 DEBUG (MainThread) [google_nest_sdm.device] Processing update ad8eb510-be91-49d5-9c06-a68089f0261c @ 2023-01-03 06:30:46.710000+00:00
2023-01-03 07:31:13.123 DEBUG (MainThread) [google_nest_sdm.event_media] Event Update dict_keys(['1633206153'])
2023-01-03 07:31:13.177 INFO (MainThread) [google_nest_sdm.event_media] Checking cache size 292
2023-01-03 07:31:13.177 DEBUG (MainThread) [google_nest_sdm.event] EventMessage raw_data={'eventId': 'ad8eb510-be91-49d5-9c06-a68089f0261c', 'timestamp': '2023-01-03T06:30:46.710Z', 'resourceUpdate': {'name': 'enterprises/20acf40f-33eb-4019-92be-686e464ca919/devices/AVPHwEttFask-hEGzUkEqFXAXRywmTXJC8OzVvlPp6JNKb-npc5vmk9y4EvuTPed1cjGE_oNRT4IVHafgrf9D21Ln_fMaA', 'events': {}}, 'userId': 'AVPHwEt1g5AoYr8Ti49Qygg1LXO6us7Rw83iNkEgnwcQ', 'eventThreadId': '0fbcb6e4-abc8-46da-a6d8-3eaea41252a8', 'resourceGroup': ['enterprises/20acf40f-33eb-4019-92be-686e464ca919/devices/AVPHwEttFask-hEGzUkEqFXAXRywmTXJC8OzVvlPp6JNKb-npc5vmk9y4EvuTPed1cjGE_oNRT4IVHafgrf9D21Ln_fMaA'], 'eventThreadState': 'ENDED'}
2023-01-03 07:31:13.178 DEBUG (Thread-CallbackRequestDispatcher) [google.cloud.pubsub_v1.subscriber._protocol.dispatcher] Handling 1 batched requests
2023-01-03 07:31:14.286 DEBUG (Thread-Heartbeater) [google.cloud.pubsub_v1.subscriber._protocol.heartbeater] Sent heartbeat.
2023-01-03 07:31:14.379 INFO (MainThread) [custom_components.xiaomi_miot.sensor] Get xiaomi message for 6171332823 failed: {'code': 0, 'message': 'ok', 'result': {'messages': [{'msg_id': 1609177418802147328, 'uid': 6171332823, 'type': 6, 'sender_uid': 0, 'did': '415461925', 'title': 'Mopping completed. Please remove my water tank.', 'content': 'Margarita', 'img_url': '', 'params': {'body': {'alertType': '', 'did': '415461925', 'event': '18.2', 'extra': [], 'homeRoomExtra': {'homeName': '', 'roomName': 'Living room'}, 'home_id': 994001003101, 'identify': '415461925', 'model': 'dreame.vacuum.mc1808', 'msgId': '1609177418802147328', 'name': 'Margarita', 'owner_uid': 6171332823, 'priority': '', 'time': 1672492768, 'us_id': 0, 'value': []}, 'devicePush': True, 'model': 'dreame.vacuum.mc1808', 'type': 'scene'}, 'is_new': 1, 'status': 0, 'ctime': 1672492768, 'last_modify': 1672492768, 'home_id': 0, 'home_owner': 0}, {'msg_id': 1609196976678121472, 'uid': 6171332823, 'type': 6, 'sender_uid': 0, 'did': '415462665', 'title': 'Mopping completed. Please remove my water tank.', 'content': 'Consuela', 'img_url': '', 'params': {'body': {'alertType': '', 'did': '415462665', 'event': '18.2', 'extra': [], 'homeRoomExtra': {'homeName': '', 'roomName': 'Dining room'}, 'home_id': 994001003101, 'identify': '415462665', 'model': 'dreame.vacuum.mc1808', 'msgId': '1609196976678121472', 'name': 'Consuela', 'owner_uid': 6171332823, 'priority': '', 'time': 1672497431, 'us_id': 0, 'value': []}, 'devicePush': True, 'model': 'dreame.vacuum.mc1808', 'type': 'scene'}, 'is_new': 1, 'status': 0, 'ctime': 1672497431, 'last_modify': 1672497431, 'home_id': 0, 'home_owner': 0}]}}
2023-01-03 07:31:16.330 ERROR (SyncWorker_8) [custom_components.xiaomi_vacuum.miio.miioprotocol] Unable to discover a device at address 192.168.87.165
2023-01-03 07:31:16.332 ERROR (SyncWorker_8) [custom_components.xiaomi_vacuum.miio.device] Unable to request properties [{'did': 'audio_volume', 'siid': 24, 'piid': 1}, {'did': 'audio_language', 'siid': 24, 'piid': 3}, {'did': 'timezone', 'siid': 25, 'piid': 1}]
2023-01-03 07:31:18.684 DEBUG (MainThread) [homeassistant.components.http.auth] Authenticated 172.30.32.2 for /api/config using bearer token
2023-01-03 07:31:18.684 DEBUG (MainThread) [homeassistant.components.http.view] Serving /api/config to 172.30.32.2 (auth: True)
2023-01-03 07:31:18.691 DEBUG (MainThread) [homeassistant.components.http.auth] Authenticated 172.30.32.2 for /api/states/binary_sensor.backups_stale using bearer token
2023-01-03 07:31:18.692 DEBUG (MainThread) [homeassistant.components.http.view] Serving /api/states/binary_sensor.backups_stale to 172.30.32.2 (auth: True)
2023-01-03 07:31:21.173 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] The current deadline value is 10 seconds.
2023-01-03 07:31:21.173 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] Snoozing lease management for 3.161242 seconds.
2023-01-03 07:31:24.335 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] The current deadline value is 10 seconds.
2023-01-03 07:31:24.335 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] Snoozing lease management for 1.148191 seconds.
2023-01-03 07:31:25.484 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] The current deadline value is 10 seconds.
2023-01-03 07:31:25.484 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] Snoozing lease management for 0.673444 seconds.
2023-01-03 07:31:26.157 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] The current deadline value is 10 seconds.
2023-01-03 07:31:26.158 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] Snoozing lease management for 3.141306 seconds.
2023-01-03 07:31:28.708 DEBUG (MainThread) [homeassistant.components.http.auth] Authenticated 172.30.32.2 for /api/config using bearer token
2023-01-03 07:31:28.708 DEBUG (MainThread) [homeassistant.components.http.view] Serving /api/config to 172.30.32.2 (auth: True)
2023-01-03 07:31:28.716 DEBUG (MainThread) [homeassistant.components.http.auth] Authenticated 172.30.32.2 for /api/states/binary_sensor.backups_stale using bearer token
2023-01-03 07:31:28.716 DEBUG (MainThread) [homeassistant.components.http.view] Serving /api/states/binary_sensor.backups_stale to 172.30.32.2 (auth: True)
2023-01-03 07:31:29.299 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] The current deadline value is 10 seconds.
2023-01-03 07:31:29.300 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] Snoozing lease management for 1.173129 seconds.
2023-01-03 07:31:29.391 INFO (MainThread) [custom_components.xiaomi_miot.sensor] Get xiaomi message for 6171332823 failed: {'code': 0, 'message': 'ok', 'result': {'messages': [{'msg_id': 1609177418802147328, 'uid': 6171332823, 'type': 6, 'sender_uid': 0, 'did': '415461925', 'title': 'Mopping completed. Please remove my water tank.', 'content': 'Margarita', 'img_url': '', 'params': {'body': {'alertType': '', 'did': '415461925', 'event': '18.2', 'extra': [], 'homeRoomExtra': {'homeName': '', 'roomName': 'Living room'}, 'home_id': 994001003101, 'identify': '415461925', 'model': 'dreame.vacuum.mc1808', 'msgId': '1609177418802147328', 'name': 'Margarita', 'owner_uid': 6171332823, 'priority': '', 'time': 1672492768, 'us_id': 0, 'value': []}, 'devicePush': True, 'model': 'dreame.vacuum.mc1808', 'type': 'scene'}, 'is_new': 1, 'status': 0, 'ctime': 1672492768, 'last_modify': 1672492768, 'home_id': 0, 'home_owner': 0}, {'msg_id': 1609196976678121472, 'uid': 6171332823, 'type': 6, 'sender_uid': 0, 'did': '415462665', 'title': 'Mopping completed. Please remove my water tank.', 'content': 'Consuela', 'img_url': '', 'params': {'body': {'alertType': '', 'did': '415462665', 'event': '18.2', 'extra': [], 'homeRoomExtra': {'homeName': '', 'roomName': 'Dining room'}, 'home_id': 994001003101, 'identify': '415462665', 'model': 'dreame.vacuum.mc1808', 'msgId': '1609196976678121472', 'name': 'Consuela', 'owner_uid': 6171332823, 'priority': '', 'time': 1672497431, 'us_id': 0, 'value': []}, 'devicePush': True, 'model': 'dreame.vacuum.mc1808', 'type': 'scene'}, 'is_new': 1, 'status': 0, 'ctime': 1672497431, 'last_modify': 1672497431, 'home_id': 0, 'home_owner': 0}]}}
2023-01-03 07:31:30.473 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] The current deadline value is 10 seconds.
2023-01-03 07:31:30.473 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] Snoozing lease management for 0.184532 seconds.
2023-01-03 07:31:30.658 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] The current deadline value is 10 seconds.
2023-01-03 07:31:30.658 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] Snoozing lease management for 4.006882 seconds.
2023-01-03 07:31:31.299 ERROR (SyncWorker_19) [custom_components.xiaomi_vacuum.miio.miioprotocol] Unable to discover a device at address 192.168.87.138
2023-01-03 07:31:31.301 ERROR (SyncWorker_19) [custom_components.xiaomi_vacuum.miio.device] Unable to request properties [{'did': 'battery', 'siid': 2, 'piid': 1}, {'did': 'state', 'siid': 2, 'piid': 2}, {'did': 'error', 'siid': 3, 'piid': 1}, {'did': 'status', 'siid': 3, 'piid': 2}, {'did': 'brush_left_time', 'siid': 26, 'piid': 1}, {'did': 'brush_life_level', 'siid': 26, 'piid': 2}, {'did': 'filter_life_level', 'siid': 27, 'piid': 1}, {'did': 'filter_left_time', 'siid': 27, 'piid': 2}, {'did': 'brush_left_time2', 'siid': 28, 'piid': 1}, {'did': 'brush_life_level2', 'siid': 28, 'piid': 2}, {'did': 'operating_mode', 'siid': 18, 'piid': 1}, {'did': 'area', 'siid': 18, 'piid': 3}, {'did': 'timer', 'siid': 18, 'piid': 2}, {'did': 'fan_speed', 'siid': 18, 'piid': 6}]
2023-01-03 07:31:34.666 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] The current deadline value is 10 seconds.
2023-01-03 07:31:34.666 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] Snoozing lease management for 1.980856 seconds.
2023-01-03 07:31:36.295 WARNING (MainThread) [homeassistant.helpers.entity] Update of vacuum.margarita is taking over 10 seconds
2023-01-03 07:31:36.308 ERROR (SyncWorker_19) [custom_components.xiaomi_vacuum.miio.miioprotocol] Unable to discover a device at address 192.168.87.138
2023-01-03 07:31:36.310 ERROR (SyncWorker_19) [custom_components.xiaomi_vacuum.miio.device] Unable to request properties [{'did': 'last_clean', 'siid': 18, 'piid': 13}, {'did': 'total_clean_count', 'siid': 18, 'piid': 14}, {'did': 'total_area', 'siid': 18, 'piid': 15}, {'did': 'total_log_start', 'siid': 18, 'piid': 16}, {'did': 'button_led', 'siid': 18, 'piid': 17}, {'did': 'clean_success', 'siid': 18, 'piid': 18}, {'did': 'water_level', 'siid': 18, 'piid': 20}, {'did': 'life_sieve', 'siid': 19, 'piid': 1}, {'did': 'life_brush_side', 'siid': 19, 'piid': 2}, {'did': 'life_brush_main', 'siid': 19, 'piid': 3}, {'did': 'dnd_enabled', 'siid': 20, 'piid': 1}, {'did': 'dnd_start_time', 'siid': 20, 'piid': 2}, {'did': 'dnd_stop_time', 'siid': 20, 'piid': 3}, {'did': 'map_view', 'siid': 23, 'piid': 1}]
2023-01-03 07:31:36.647 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] The current deadline value is 10 seconds.
2023-01-03 07:31:36.647 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] Snoozing lease management for 2.309587 seconds.
2023-01-03 07:31:38.732 DEBUG (MainThread) [homeassistant.components.http.auth] Authenticated 172.30.32.2 for /api/config using bearer token
2023-01-03 07:31:38.732 DEBUG (MainThread) [homeassistant.components.http.view] Serving /api/config to 172.30.32.2 (auth: True)
2023-01-03 07:31:38.740 DEBUG (MainThread) [homeassistant.components.http.auth] Authenticated 172.30.32.2 for /api/states/binary_sensor.backups_stale using bearer token
2023-01-03 07:31:38.740 DEBUG (MainThread) [homeassistant.components.http.view] Serving /api/states/binary_sensor.backups_stale to 172.30.32.2 (auth: True)
2023-01-03 07:31:38.957 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] The current deadline value is 10 seconds.
2023-01-03 07:31:38.958 DEBUG (Thread-LeaseMaintainer) [google.cloud.pubsub_v1.subscriber._protocol.leaser] Snoozing lease management for 6.459608 seconds.
2023-01-03 07:31:41.312 ERROR (SyncWorker_19) [custom_components.xiaomi_vacuum.miio.miioprotocol] Unable to discover a device at address 192.168.87.138
2023-01-03 07:31:41.313 ERROR (SyncWorker_19) [custom_components.xiaomi_vacuum.miio.device] Unable to request properties [{'did': 'audio_volume', 'siid': 24, 'piid': 1}, {'did': 'audio_language', 'siid': 24, 'piid': 3}, {'did': 'timezone', 'siid': 25, 'piid': 1}]