Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Nest Cameras/Doorbell showing too many API calls since latest HA update #130061

Closed
Velionis opened this issue Nov 7, 2024 · 48 comments · Fixed by #130265
Closed

Nest Cameras/Doorbell showing too many API calls since latest HA update #130061

Velionis opened this issue Nov 7, 2024 · 48 comments · Fixed by #130265
Assignees

Comments

@Velionis
Copy link

Velionis commented Nov 7, 2024

The problem

I am receiving the error error below since the latest HA update for my Nest doorbell camera. It also seems like cameras are also affected based on this thread https://community.home-assistant.io/t/google-nest-cameras-not-working-after-latest-home-assistant-update/791628

Failed to start WebRTC stream: Nest API error: Too Many Requests response from API (429): RESOURCE_EXHAUSTED (429): Rate limited for the ExecuteDeviceCommand API for the user.

I assume it is related to the new camera changes in the 2024.11 update. It was working fine before then.

What version of Home Assistant Core has the issue?

core-2024.11.0

What was the last working version of Home Assistant Core?

core-2024.10.4

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Google Nest

Link to integration documentation on our website

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

Diagnostics information

nest-01JB0SMBHCYG2NXA7D104GMJAP-Front door-3f2d7977e8184487d1a66382a9f3eca2.json

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

@home-assistant
Copy link

home-assistant bot commented Nov 7, 2024

Hey there @allenporter, mind taking a look at this issue as it has been labeled with an integration (nest) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of nest can trigger bot actions by commenting:

  • @home-assistant close Closes the issue.
  • @home-assistant rename Awesome new title Renames the issue.
  • @home-assistant reopen Reopen the issue.
  • @home-assistant unassign nest Removes the current integration label and assignees on the issue, add the integration domain after the command.
  • @home-assistant add-label needs-more-information Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue.
  • @home-assistant remove-label needs-more-information Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

(message by CodeOwnersMention)


nest documentation
nest source
(message by IssueLinks)

@allenporter
Copy link
Contributor

How long was the stream open here?

i'm seeing these counters:

{
    "command": {
      "sdm.devices.commands.CameraLiveStream.GenerateWebRtcStream_count": 52,
      "sdm.devices.commands.CameraLiveStream.GenerateWebRtcStream_sum": 31924,
      "sdm.devices.commands.CameraLiveStream.StopWebRtcStream_count": 19,
      "sdm.devices.commands.CameraLiveStream.StopWebRtcStream_sum": 30070,
      "fetch_image_count": 1,
      "fetch_image_sum": 496,
      "sdm.devices.commands.CameraLiveStream.ExtendWebRtcStream_count": 112180,
      "sdm.devices.commands.CameraLiveStream.ExtendWebRtcStream_sum": 23248068
    },
}

where there were 50 streams created but over 100k streams extended! which seems indeed like a bug.

Can you turn on debug logging and capture debug logs? I think we could see what the timings are between extending the stream.

@Velionis
Copy link
Author

Velionis commented Nov 8, 2024

I usually check the camera through the day but never leave it open for more than 10-15 seconds at a time. I usually check it most of the time on my phone. When the error started happening, it usually doesn't even give me a chance to view the camera, even after several minutes.

I've attached some debug logs of when it throws the error. I've attached debug logs, one while it works before it breaks
home-assistant_nest_2024-11-08T04-17-36.590Z.log

and the other while it throws the error consistently for a long time.
home-assistant_nest_2024-11-08T04-31-28.104Z.log

Please let me know if you need anything else.

@allenporter
Copy link
Contributor

Thank you the detail is very helpful. I think a problem is that once the stream expires then fails to renew, it repeatedly hammers the API trying to extend the stream. We may not be able to avoid occasionally going over the rate limit, but once this happens it guarantees it won't stop.

@ssewell
Copy link

ssewell commented Nov 8, 2024

I'm experiencing the same issue immediately after updating from HA 2024.10.4 to HA 2024.11.0. I tried fully cycling the VM running Home Assistant, then allowed for a cooling off period, but it appears that system unconditionally ends up in that API hammering loop.

The interesting thing is, if I rollback to a VM snapshot I took just prior to the upgrade, it starts working immediately. A bit surprising, because I expected the API limits to still be in play, but it's apparently only being exhausted by the behavior of 2024.11.0.

@allenporter
Copy link
Contributor

allenporter commented Nov 8, 2024

Thanks for the report, it definitely seems consistent with a stream expiration code issue. Working on a fix.

@Velionis
Copy link
Author

Velionis commented Nov 9, 2024

Thank you for the help so far! I saw that 2024.11.1 came out with the fix related to this issue. I installed it and restarted HA, but still have the same issue unfortunately. Works for a bit then breaks again eventually.

@ssewell
Copy link

ssewell commented Nov 9, 2024

I'm seeing similar behavior. Working fine for a few minutes, then regressed back to the previous API rate limit.

@arnoudkooi
Copy link

I posted about this on Discord, also still seeing the issue 2024.11.1

@malrogers7
Copy link

I think I'm getting the same issue. On 2024.11.0, it stopped working completely with the 'Failed to start webRTC stream' error.

Now on 2024.11.1, it doesn't stop completely, but I get the following error in the logs every time I try to access a Nest camera/doorbell through Home Assistant:

Logger: homeassistant.components.websocket_api.http.connection
Source: components/websocket_api/connection.py:315
integration: Home Assistant WebSocket API (documentation, issues)
First occurred: 10:53:33 (19 occurrences)
Last logged: 11:05:19
[140612343083456] Error handling message: Cannot handle WebRTC candidate (home_assistant_error) Kiosk from 192.168.0.13 (Mozilla/5.0 (Linux; Android 12; SM-T503 Build/SP1A.210812.016; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/130.0.6723.107 Safari/537.36)

@allenporter
Copy link
Contributor

Re-opening as I think there still may be an issue here where too many streams are opened in parallel with the go2rtc fallback change, but i'm going to investigate a little more.

@MrJ-d40
Copy link

MrJ-d40 commented Nov 10, 2024

Hey @allenporter, at least for me I still have this issue. Thanks for looking into this :)

@allenporter
Copy link
Contributor

Part of the issue may be that both types of streams are now opened with go2rtc as described in #129987 -- it does both HLS and WebRTC which maybe generate a strem twice. One workaround can be to temporarily disable the new go2rtc for RTSP cameras. I don't have any other better ideas yet.

@IngeJones
Copy link

Is the intended behaviour that the Nest camera should stop streaming when I close the page containing the card in my browser? The state of the camera in the battery camera's own device page says "Streaming" whenever I look. As a battery camera it shouldn't be, unless something is holding it open when not required. Didn't know if this could be connected with the issue.

@allenporter
Copy link
Contributor

@IngeJones nest camera APIs have no state, and so it has to either show up as streaming or off and so it shows up as streaming. Don't worry, it's not draining your battery when not in use.

@PedroKTFC
Copy link

Just to add: I have a Nest thermostat as well as a doorbell and this issue is stopping me controlling my thermostat from HA.

@ssewell
Copy link

ssewell commented Nov 11, 2024

Part of the issue may be that both types of streams are now opened with go2rtc as described in #129987 -- it does both HLS and WebRTC which maybe generate a strem twice. One workaround can be to temporarily disable the new go2rtc for RTSP cameras. I don't have any other better ideas yet.

Is there a user-facing configuration that allows one to disable the new go2rtc functionality (globally or perhaps on a more granular basis)? The release notes for 2024.11 don't seem to mention anything.

@allenporter
Copy link
Contributor

Just to add: I have a Nest thermostat as well as a doorbell and this issue is stopping me controlling my thermostat from HA.

I recommend either rolling back home assistant versions or disabling cameras if you need a workaround.

@IngeJones
Copy link

Is there a user-facing configuration that allows one to disable the new go2rtc functionality (globally or perhaps on a more granular basis)? The release notes for 2024.11 don't seem to mention anything.

I'd love the choice per camera, or even per streaming card. Obviously I don't know whether it's feasible or how much work it would entail.

@allenporter
Copy link
Contributor

go2rtc is part of default_config which you can disable and add back integrations you want. You are welcome to discuss feature requests or additional support in the community forums.

@Intecpsp
Copy link

I recommend either rolling back home assistant versions or disabling cameras if you need a workaround.

Which HA version? Just disabling the camera entities in HA, or somehow disabling from the GCloud side?

@allenporter
Copy link
Contributor

Folks say this started in 2024.11.0 and I included some fixes in 2024.11.1 that were bugs of trying to refresh the stream way way too much.

If someone is experiencing the API rate limitinf in 2024.11.1 or later I would love more data about the API calls you see when debug log is enabled and including diagnostics which includes request count stats.
I thought this could be related to the new camera type but realized the strama should be reused already and not necessary create new requests.

@drsmarsden
Copy link

I have it in 2024.11.1

What exact logging needs to be enable?

@jlayze
Copy link

jlayze commented Nov 13, 2024

I have 3 cameras and I turned on debug logging. I can see the 3 API calls go out, and then I see a long list of:

ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [547733947584] Error handling message: Cannot handle WebRTC candidate (home_assistant_error) Jason from 127.0.0.1 (Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/130.0.0.0 Safari/537.36)

Before finally getting:

ERROR (MainThread) [homeassistant.components.camera.webrtc] Error handling WebRTC offer: Nest API error: Too Many Requests response from API (429): RESOURCE_EXHAUSTED (429): Rate limited for the ExecuteDeviceCommand API for the user.

This is not consistent, because sometimes after the long list of "cannot handle WebRTC candidate" I will get a response and cameras will work.

Cameras:
Nest Cam w/ Floodlight
Nest Cam Outdoor (1st Gen) - recently migrated to Google Home
Nest Hello Doorbell (1st Gen) - recently migrated to Google Home

@PedroKTFC
Copy link

I recommend either rolling back home assistant versions or disabling cameras if you need a workaround.

Which HA version? Just disabling the camera entities in HA, or somehow disabling from the GCloud side?

I disabled the camera entity and that allowed me to use my thermostat again.

@eb360341
Copy link

i have 2 thermostats and 4 cams, my thought process is that if you have the cam or the thermostat on the dashboard, it requests every sec or something like that. In the pub/sub api and the other api enabled, there were almost about 10,000 requests in an hr alone and with 99 percent error rate coming from home assistant. when i remove most of the nest devices and say keep one cam or both thermostats, i am able to access in and out the cams and thermostats without getting the timeout error so quickly but i still do get it so def a bug in the way its requesting

@allenporter
Copy link
Contributor

i have 2 thermostats and 4 cams, my thought process is that if you have the cam or the thermostat on the dashboard, it requests every sec or something like that. In the pub/sub api and the other api enabled, there were almost about 10,000 requests in an hr alone and with 99 percent error rate coming from home assistant. when i remove most of the nest devices and say keep one cam or both thermostats, i am able to access in and out the cams and thermostats without getting the timeout error so quickly but i still do get it so def a bug in the way its requesting

There is a bug in steam expiration handling in 2024.11.0 fixed in 2024.11.1 that would send many requests. As I mentioned above looking to understand more debug logs from 2024.11.1 if this is still happening. (Pubsub should be unrelated, nothing to do with this and errors there should be ignored as it's part of how streaming pull works.)

So far the only report is about 3 requests being sent which is totally normal.

@eb360341
Copy link

eb360341 commented Nov 14, 2024

gotcha, just checked my OS, it is currently
Core
2024.11.1
Supervisor
2024.11.2
... i am assuming the bug is still persistant. whenever i have just the 3 cams and 2 thermostats, it pretty much always says the request error

@Velionis
Copy link
Author

Velionis commented Nov 14, 2024

@allenporter Apologies for not sending logs earlier. The camera has been showing the error for a few days now. It has not let me view the camera at any point until I restart HA and then it works for a little bit only. The logs include me attempting to open up the camera 2-3 times earlier. I am on 2024.11.1.

home-assistant_nest_2024-11-14T16-42-23.335Z.log

@allenporter
Copy link
Contributor

ok it looks like some of the fixes in 2024.12 could help namely #130265 -- i can see from your logs once it fails, its sending one request per second to try extending the stream. That shouldn't happen anymore after the next patch release.

As a workaround you can either go backwards to 2024.10 or disable camera entities.

@eb360341
Copy link

eb360341 commented Nov 15, 2024 via email

@allenporter
Copy link
Contributor

Thank you all for your patience in resolving this. Appreciate the time you took in providing debug logs and details.

@DerAutomatiker
Copy link

Screenshot_2024-11-16-09-11-10-52_c3a231c25ed346e59462e84656a70e50

I'm on 11.2 and it's better than before but still not reliable..
What exact logs do you need?

@PedroKTFC
Copy link

PedroKTFC commented Nov 16, 2024

11.2 seems to have solved the problem for my Nest cam but now my EZVIZ camera isn't working|! In11.1 the stream was working perfectly, coming up really quickly but now at best I get a snapshot while if I go into the device and click on the camera entity I get "Failed to start WebRTC stream: Unknown command.". I know it's not Nest related but I wonder if the fix for the Nest has caused this? And to add, the PTZ movement buttons work!

@PedroKTFC
Copy link

Bad form to reply to yourself I know, sorry! Just to update on my EZVIZ camera, I've restarted HA and it's now working! A bit odd - I'll monitor it over the next few days.

@IngeJones
Copy link

Nest cameras a lot better in 11.2 for me. I can actually see some live streaming now. I did have to start HA a second time after installing the update before the error message cleared. I'll post again when I've had longer to test. The Reolink cameras were improved right from the first version of this, as in they now stream live rather than jerkily every 5 or so seconds.

@allenporter
Copy link
Contributor

If you have problems with other cameras and webrtc you can file a report with that integration or go2rtc

@allenporter
Copy link
Contributor

At the end of the day the nest API still has rate limits and we can't entirely stop it, but sounds clear the root problems are addressed by fixing the expiration error handling. Thanks.

@IngeJones
Copy link

Reolink and Nest cameras still stable here after several hours. It seems now to be working as intended.

@arnoudkooi
Copy link

Since today, Im seeing the issue again :(
Looking in the google cloud console, I see the error rate is stadily growing over the days (I have 1 camera)
It still is way less then before the fix around 0,2 request per second vs >2 requests per second.

Google Chrome20241120 - 2103

@allenporter
Copy link
Contributor

Since today, Im seeing the issue again :( Looking in the google cloud console, I see the error rate is stadily growing over the days (I have 1 camera) It still is way less then before the fix around 0,2 request per second vs >2 requests per second.

Can you confirm what home assistant version?

It should be max 1 request every 30 seconds.

@arnoudkooi
Copy link

Can you confirm what home assistant version?
It should be max 1 request every 30 seconds.

This was 2024.11.2. I downgraded 2024.10.4 since, see below graph
Google Chrome20241121 - 0740

@GuyCoz
Copy link

GuyCoz commented Nov 21, 2024

image
It has certainly decreased the number of calls (updated to 2024.11.2 at 4am on Sunday), but it is creeping back up over time to around 5 requests/minute.

A restart resets it.

@allenporter
Copy link
Contributor

Can you enable debug logging and capture requests being sent?

@allenporter allenporter reopened this Nov 22, 2024
@arnoudkooi
Copy link

arnoudkooi commented Nov 22, 2024

Does below give enough information to troubleshoot?
I upgraded to 2024.11.3 and start seeing the errors again after.

2024-11-22 16:35:13.719 WARNING (SyncWorker_0) [homeassistant.loader] 
We found a custom integration hacs which has not been tested by Home Assistant. 
This component might cause stability problems, be sure to disable it if you 
experience issues with Home Assistant

2024-11-22 16:35:21.872 WARNING (MainThread) [hass_nabucasa.cloud_api] 
Fetched https://alexa-api.nabucasa.com/access_token (400) 

2024-11-22 16:36:04.648 WARNING (MainThread) [homeassistant.components.light] 
Setup of light platform hue is taking over 10 seconds.

2024-11-22 16:36:19.761 WARNING (MainThread) [homeassistant.core] 
Something is blocking Home Assistant from wrapping up the start up phase. 
[... component list omitted for brevity ...]
The system is waiting for tasks: 
{<Task pending name='Task-419' coro=<AbstractConfig.async_initialize.<locals>.
sync_google() running at /usr/src/homeassistant/homeassistant/components/
google_assistant/helpers.py:114> wait_for=<_GatheringFuture pending 
cb=[Task.task_wakeup()]> cb=[set.remove()]>}

2024-11-22 18:03:23.613 DEBUG (MainThread) [homeassistant.components.nest.camera] 
Extending WebRTC stream [REDACTED-STREAM-ID-1]

2024-11-22 18:03:23.614 DEBUG (MainThread) [google_nest_sdm.auth] 
request[post]=https://smartdevicemanagement.googleapis.com/v1/enterprises/
[REDACTED-ENTERPRISE-ID]/devices/[REDACTED-DEVICE-ID]:executeCommand

2024-11-22 18:03:23.614 DEBUG (MainThread) [google_nest_sdm.auth] 
request[post json]={'command': 'sdm.devices.commands.CameraLiveStream.
ExtendWebRtcStream', 'params': {'mediaSessionId': '[REDACTED-STREAM-ID-1]'}}

2024-11-22 18:03:23.756 DEBUG (MainThread) [homeassistant.components.nest.camera] 
Extending WebRTC stream [REDACTED-STREAM-ID-2]

2024-11-22 18:03:23.757 DEBUG (MainThread) [google_nest_sdm.auth] 
request[post]=https://smartdevicemanagement.googleapis.com/v1/enterprises/
[REDACTED-ENTERPRISE-ID]/devices/[REDACTED-DEVICE-ID]:executeCommand

2024-11-22 18:03:23.757 DEBUG (MainThread) [google_nest_sdm.auth] 
request[post json]={'command': 'sdm.devices.commands.CameraLiveStream.
ExtendWebRtcStream', 'params': {'mediaSessionId': '[REDACTED-STREAM-ID-2]'}}

2024-11-22 18:03:24.559 DEBUG (MainThread) [homeassistant.components.nest.camera] 
Failed to refresh stream: Bad Request response from API (400): FAILED_PRECONDITION 
(400): WebRtc error caused by invalid session or user id mismatch.

2024-11-22 18:03:24.562 DEBUG (MainThread) [homeassistant.components.nest.camera] 
Scheduling stream refresh for 2024-11-22 17:11:00.187090+00:00

2024-11-22 18:03:25.188 DEBUG (MainThread) [homeassistant.components.nest.camera] 
Failed to refresh stream: Bad Request response from API (400): FAILED_PRECONDITION 
(400): WebRtc error caused by invalid session or user id mismatch.

2024-11-22 18:03:25.189 DEBUG (MainThread) [homeassistant.components.nest.camera] 
Scheduling stream refresh for 2024-11-22 17:11:00.814098+00:00

@allenporter
Copy link
Contributor

These errors are normal to happen from time to time because the API has a rate limit. What we're looking for is evidence that the integration is sending repeated requests that are inappropriate. It should be backing off every time there is an error and refreshing at a slower rate.

@GuyCoz
Copy link

GuyCoz commented Nov 26, 2024

From the log, it does seem to be backing off as expected:
^^^^^^^^^^^^ AttributeError: 'list' object has no attribute 'object_key' 2024-11-26 10:17:04.140 ERROR (MainThread) [custom_components.nest_protect] Unknown exception. Please create an issue on GitHub with your logfile. Updates paused for 5 minutes. Traceback (most recent call last): File "/config/custom_components/nest_protect/__init__.py", line 208, in _async_subscribe_for_data dict(b, **buckets.get(b.object_key, {})) for b in [data.updated_buckets] ^^^^^^^^^^^^ AttributeError: 'list' object has no attribute 'object_key' 2024-11-26 10:22:08.686 ERROR (MainThread) [custom_components.nest_protect] Unknown exception. Please create an issue on GitHub with your logfile. Updates paused for 5 minutes. Traceback (most recent call last): File "/config/custom_components/nest_protect/__init__.py", line 208, in _async_subscribe_for_data dict(b, **buckets.get(b.object_key, {})) for b in [data.updated_buckets] ^^^^^^^^^^^^ AttributeError: 'list' object has no attribute 'object_key' 2024-11-26 10:25:17.639 DEBUG (MainThread) [google_nest_sdm.event] EventMessage raw_data={'eventId': 'cad01280-af90-44eb-bc39-943c9ed32887', 'timestamp': '2024-11-26T10:25:15.277156Z', 'resourceUpdate': {'name': 'enterprises/8f6de1dd-c199-46e1-9137-e9151cc93691/devices/AVPHwEtLniBPBm8W0keqjNtvPZw-EFgn9la7A9eFuHZnyz2uRe68Nv5AoQW49MmDfZOzMiSnYHZRXwLybviscYUt_gQYCrw', 'traits': {'sdm.devices.traits.Temperature': {'ambientTemperatureCelsius': 21.719986}}}, 'userId': 'AVPHwEvAAfdfycNvGQ6-9bIzQxPeiKHIdVrmeEkZzdhu_g', 'resourceGroup': ['enterprises/8f6de1dd-c199-46e1-9137-e9151cc93691/devices/AVPHwEtLniBPBm8W0keqjNtvPZw-EFgn9la7A9eFuHZnyz2uRe68Nv5AoQW49MmDfZOzMiSnYHZRXwLybviscYUt_gQYCrw']} 2024-11-26 10:25:17.639 DEBUG (MainThread) [google_nest_sdm.device] Processing update cad01280-af90-44eb-bc39-943c9ed32887 @ 2024-11-26 10:25:15.277156+00:00 2024-11-26 10:25:17.640 DEBUG (MainThread) [google_nest_sdm.device] Trait update {'sdm.devices.traits.Temperature': {'ambientTemperatureCelsius': 21.719986}, 'name': 'enterprises/8f6de1dd-c199-46e1-9137-e9151cc93691/devices/AVPHwEtLniBPBm8W0keqjNtvPZw-EFgn9la7A9eFuHZnyz2uRe68Nv5AoQW49MmDfZOzMiSnYHZRXwLybviscYUt_gQYCrw'} 2024-11-26 10:27:09.282 ERROR (MainThread) [custom_components.nest_protect] Unknown exception. Please create an issue on GitHub with your logfile. Updates paused for 5 minutes. Traceback (most recent call last): File "/config/custom_components/nest_protect/__init__.py", line 208, in _async_subscribe_for_data dict(b, **buckets.get(b.object_key, {})) for b in [data.updated_buckets] ^^^^^^^^^^^^ AttributeError: 'list' object has no attribute 'object_key' 2024-11-26 10:32:09.871 ERROR (MainThread) [custom_components.nest_protect] Unknown exception. Please create an issue on GitHub with your logfile. Updates paused for 5 minutes. Traceback (most recent call last): File "/config/custom_components/nest_protect/__init__.py", line 208, in _async_subscribe_for_data dict(b, **buckets.get(b.object_key, {})) for b in [data.updated_buckets] ^^^^^^^^^^^^ AttributeError: 'list' object has no attribute 'object_key'

Just had a thought - I have the Nest Protect Integration too, which I think uses the same API - perhaps this could be the cause? Will investigate. Edit: OK, seems it does not use Google SDM.

@allenporter
Copy link
Contributor

I'm not aware of any ongoing issue here, so we need more details to investigate. Pleasen reopen a new issue with debug logs and diagnostics since its a different root cause.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging a pull request may close this issue.