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 Integration Not Working/Crashing Home Asisstant #117827

Closed
glimberg opened this issue May 21, 2024 · 23 comments
Closed

Nest Integration Not Working/Crashing Home Asisstant #117827

glimberg opened this issue May 21, 2024 · 23 comments
Assignees

Comments

@glimberg
Copy link

The problem

I noticed my Nest panels were no longer populated in my dashboard. I started investigation and noticed that the Nest integration completely stopped working recently running on my ODroid M1. Trying to reload the integration causes Home Assistant to completely freeze up & restart. Trying to even delete the integration causes the same to happen. Enabling debug logging doesn't seem to provide any insight into the issue that I can discern.

What version of Home Assistant Core has the issue?

core-2024.5.4

What was the last working version of Home Assistant Core?

core-2024.4.?

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Nest

Link to integration documentation on our website

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

Diagnostics information

This log is starting up with the integration enabled:
home-assistant_2024-05-21T01-16-46.017Z.log

Upon trying to delete the integration, the following line is printed to the log:

2024-05-20 18:18:04.438 DEBUG (MainThread) [homeassistant.components.nest] Deleting subscriber 'projects/${MY_PROJECT}/subscriptions/home-assistant-3WvSmApvVt'

HA goes non responsive for several minutes, then we get:

2024-05-20 18:26:04.858 DEBUG (ThreadPoolExecutor-1_0) [google_nest_sdm.google_nest_subscriber] Deleting subscription 'projects/${MY_PROJECT}/subscriptions/home-assistant-3WvSmApvVt'
2024-05-20 18:27:26.871 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/aiohttp/http_websocket.py", line 715, in ping
    await self._send_frame(message, WSMsgType.PING)
  File "/usr/local/lib/python3.12/site-packages/aiohttp/http_websocket.py", line 682, in _send_frame
    self._write(header + message)
  File "/usr/local/lib/python3.12/site-packages/aiohttp/http_websocket.py", line 702, in _write
    raise ConnectionResetError("Cannot write to closing transport")
ConnectionResetError: Cannot write to closing transport
2024-05-20 18:27:26.895 WARNING (MainThread) [aioesphomeapi.connection] ratgdov25i-1bc009 @ 10.187.10.12: Connection error occurred: ratgdov25i-1bc009 @ 10.187.10.12: EOF received
2024-05-20 18:27:27.096 WARNING (MainThread) [zigpy_deconz.uart] Lost connection: SerialException('device reports readiness to read but returned no data (device disconnected or multiple access on port?)')
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/serial_asyncio_fast/__init__.py", line 132, in _read_ready
    data = self._serial.read(self._max_read_size)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/serial/serialposix.py", line 595, in read
    raise SerialException(
serial.serialutil.SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)
2024-05-20 18:27:30.003 WARNING (MainThread) [homeassistant.components.esphome.manager] Error getting setting up connection for 10.187.10.12: Connection closed
2024-05-20 18:27:30.084 WARNING (Thread-17 (_do_shutdown)) [homeassistant.util.executor] Thread[SyncWorker_0] is still running at shutdown: File "/usr/local/lib/python3.12/threading.py", line 1030, in _bootstrap
    self._bootstrap_inner()
  File "/usr/local/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.12/threading.py", line 1010, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.12/concurrent/futures/thread.py", line 92, in _worker
    work_item.run()
  File "/usr/local/lib/python3.12/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/mikrotik/hub.py", line 185, in update_devices
    active = self.do_arp_ping(
  File "/usr/src/homeassistant/homeassistant/components/mikrotik/hub.py", line 202, in do_arp_ping
    data = self.command(cmd, params)
  File "/usr/src/homeassistant/homeassistant/components/mikrotik/hub.py", line 225, in command
    return list(self.api(cmd=cmd, **params))
  File "/usr/local/lib/python3.12/site-packages/librouteros/api.py", line 35, in __call__
    yield from self.readResponse()
  File "/usr/local/lib/python3.12/site-packages/librouteros/api.py", line 67, in readResponse
    reply_word, words = self.readSentence()
  File "/usr/local/lib/python3.12/site-packages/librouteros/api.py", line 53, in readSentence
    reply_word, words = self.protocol.readSentence()
  File "/usr/local/lib/python3.12/site-packages/librouteros/protocol.py", line 187, in readSentence
    sentence = tuple(word for word in iter(self.readWord, ''))
  File "/usr/local/lib/python3.12/site-packages/librouteros/protocol.py", line 187, in <genexpr>
    sentence = tuple(word for word in iter(self.readWord, ''))
  File "/usr/local/lib/python3.12/site-packages/librouteros/protocol.py", line 196, in readWord
    byte = self.transport.read(1)
  File "/usr/local/lib/python3.12/site-packages/librouteros/connections.py", line 25, in read
    data += self.sock.recv((length - len(data)))
2024-05-20 18:27:30.163 WARNING (Thread-17 (_do_shutdown)) [homeassistant.util.executor] Thread[SyncWorker_1] is still running at shutdown: File "/usr/local/lib/python3.12/threading.py", line 1030, in _bootstrap
    self._bootstrap_inner()
  File "/usr/local/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.12/threading.py", line 1010, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.12/concurrent/futures/thread.py", line 92, in _worker
    work_item.run()
  File "/usr/local/lib/python3.12/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.12/site-packages/paho/mqtt/client.py", line 1044, in reconnect
    sock = self._create_socket_connection()
  File "/usr/local/lib/python3.12/site-packages/paho/mqtt/client.py", line 3685, in _create_socket_connection
    return socket.create_connection(addr, timeout=self._connect_timeout, source_address=source)
  File "/usr/local/lib/python3.12/socket.py", line 837, in create_connection
    sock.connect(sa)
2024-05-20 18:27:30.656 WARNING (Thread-17 (_do_shutdown)) [homeassistant.util.executor] Thread[SyncWorker_1] is still running at shutdown: File "/usr/local/lib/python3.12/threading.py", line 1030, in _bootstrap
    self._bootstrap_inner()
  File "/usr/local/lib/python3.12/threading.py", line 1073, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.12/threading.py", line 1010, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.12/concurrent/futures/thread.py", line 92, in _worker
    work_item.run()
  File "/usr/local/lib/python3.12/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.12/site-packages/paho/mqtt/client.py", line 1044, in reconnect
    sock = self._create_socket_connection()
  File "/usr/local/lib/python3.12/site-packages/paho/mqtt/client.py", line 3685, in _create_socket_connection
    return socket.create_connection(addr, timeout=self._connect_timeout, source_address=source)
  File "/usr/local/lib/python3.12/socket.py", line 837, in create_connection
    sock.connect(sa)
tail: home-assistant.log has been replaced; following end of new file

HA then comes back, starts re-initializing everything, including Nest, and fails all over again. Can't get out of this loop

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Plenty of stack traces.  Not sure how useful they are.

Additional information

This started happening somewhere in the core-2024.05 series, but I'm not sure exactly where.

@home-assistant
Copy link

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

One of the interesting exceptions is here:

2024-05-20 18:10:40.905 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry Home for nest
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 575, in async_setup
    result = await component.async_setup_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/nest/__init__.py", line 202, in async_setup_entry
    await subscriber.start_async()
  File "/usr/local/lib/python3.12/site-packages/google_nest_sdm/google_nest_subscriber.py", line 438, in start_async
    await self._subscriber_factory.async_new_subscriber(
  File "/usr/local/lib/python3.12/site-packages/google_nest_sdm/google_nest_subscriber.py", line 291, in async_new_subscriber
    return await loop.run_in_executor(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
asyncio.exceptions.CancelledError: Global task timeout

@allenporter
Copy link
Contributor

Would you be up for enabling debug home in configuration.yaml? This may catch things like running unsafe operations in the wrong thread.

homeassistant:
  debug: True

@allenporter
Copy link
Contributor

Also, can you try this with custom components disabled in safe mode? https://www.home-assistant.io/docs/troubleshooting_general/#restarting-home-assistant-in-safe-mode

@glimberg
Copy link
Author

Here are logs with

homeassistant:
  debug: True

home-assistant_2024-05-21T02-49-06.245Z.log

I'll try safe mode next

@glimberg
Copy link
Author

Still failed in safe mode

home-assistant_2024-05-21T03-01-14.380Z.log

@glimberg
Copy link
Author

I see a couple merges referencing these issues, but I can't tell if they made it into 2024.5.5 or not. If they have, I'm still having the same issues. If the have not, is there any way to test the changes to see if they help resolve the issue?

@allenporter
Copy link
Contributor

They are in 2025.6 .. beta cut today, releasing next week

@glimberg
Copy link
Author

glimberg commented Jun 5, 2024

Unfortunately the nest integration still won't start up after upgrading to 2024.6

2024-06-05 16:00:19.391 ERROR (MainThread) [homeassistant.components.mqtt.client] Failed to connect to MQTT server due to exception: timed out
2024-06-05 16:01:03.443 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: {('nest', 'b702ae3ddd2546bcfb89e8ef0ad007cc'): 1381502.322325195}
2024-06-05 16:02:03.507 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: {('nest', 'b702ae3ddd2546bcfb89e8ef0ad007cc'): 1381502.322325195}
2024-06-05 16:03:03.575 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: {('nest', 'b702ae3ddd2546bcfb89e8ef0ad007cc'): 1381502.322325195}
2024-06-05 16:04:03.644 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: {('nest', 'b702ae3ddd2546bcfb89e8ef0ad007cc'): 1381502.322325195}
2024-06-05 16:05:03.709 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: {('nest', 'b702ae3ddd2546bcfb89e8ef0ad007cc'): 1381502.322325195}
2024-06-05 16:05:05.146 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry Home for nest
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 594, in async_setup
    result = await component.async_setup_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/nest/__init__.py", line 203, in async_setup_entry
    await subscriber.start_async()
  File "/usr/local/lib/python3.12/site-packages/google_nest_sdm/google_nest_subscriber.py", line 436, in start_async
    await self._subscriber_factory.async_new_subscriber(
  File "/usr/local/lib/python3.12/site-packages/google_nest_sdm/google_nest_subscriber.py", line 289, in async_new_subscriber
    return await loop.run_in_executor(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
asyncio.exceptions.CancelledError: Global task timeout
2024-06-05 16:05:05.154 WARNING (MainThread) [homeassistant.bootstrap] Setup timed out for stage 2 waiting on set() - moving forward

@glimberg
Copy link
Author

glimberg commented Jun 5, 2024

It's no longer causing HA to go temporarily non-responsive at least. But still not working.

@glimberg
Copy link
Author

glimberg commented Jun 5, 2024

Still can't delete the integration either to try & start over. I got these debug messages, and the subscription in GCP PubSub was deleted, but the integration is still present in HA 30 minutes later

2024-06-05 16:09:29.957 DEBUG (MainThread) [homeassistant.components.nest] Deleting subscriber 'projects/$PROJECT/subscriptions/home-assistant-3WvSmApvVt'
2024-06-05 16:17:30.548 DEBUG (SyncWorker_7) [google_nest_sdm.google_nest_subscriber] Deleting subscription 'projects/$PROJECT/subscriptions/home-assistant-3WvSmApvVt'

@allenporter
Copy link
Contributor

Ok progress. That exception trace is the exact code I changed trying to find the issue. This is a much more informative error message about the problem. I'll have a look and suggest further action or add more instrumentation.

Thank you for your patience! 🙏

@TMulderNL
Copy link

TMulderNL commented Jun 11, 2024

I've been following this issue since a while now and hoped that my google integrations (nest and calendar) would work after this update (to core 2024.6.2), but alas.

At the integration page I get this error message now (didn't get that one before the update):
Subscriber error: Failed to create subscriber 'projects/homeassistant-405516/subscriptions/home-assistant-rMabLKRfOx':

And in the logs I see this error:

Logger: homeassistant.config_entries
Source: [config_entries.py:594](http://config_entries.py:594/)
First occurred: 9:23:39 PM (1 occurrences)
Last logged: 9:23:39 PM

Error setting up entry [[email protected]](mailto:[email protected]) for google
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 594, in async_setup
    result = await component.async_setup_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/google/__init__.py", line 170, in async_setup_entry
    await session.async_ensure_token_valid()
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 531, in async_ensure_token_valid
    new_token = await self.implementation.async_refresh_token(self.token)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 103, in async_refresh_token
    new_token = await self._async_refresh_token(token)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 193, in _async_refresh_token
    new_token = await self._token_request(
                ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/config_entry_oauth2_flow.py", line 212, in _token_request
    resp = await session.post(self.token_url, data=data)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/aiohttp/client.py", line 507, in _request
    with timer:
  File "/usr/local/lib/python3.12/site-packages/aiohttp/helpers.py", line 735, in __exit__
    raise asyncio.TimeoutError from None
TimeoutError

If this aint the same issue as the one above I can remove this comment.
If any other information will be helpful just tell me.

@allenporter
Copy link
Contributor

@TMulderNL does not look like the same issue. That appears to look like an issue i see when folks have ad blockers on that block google from the network, or another kind of ipv6 issue.

@glimberg
Copy link
Author

Unfortunately, with it starting to really heat up in these parts, the W.A.F. (wife acceptance factor) has gotten critically low in recent days and I'm spending my afternoon replacing the Nest with an Ecobee now.

@allenporter
Copy link
Contributor

OK i would suggest double checking you don't have an ad blocker or ipv6 misconfiguration that is blocking google. Essentially its timing out opening a connection. I was confused because of how its failing looks like a deadlock or broken subscriber thread but i also realize that an unexpected network issue could be breaking an assumption in the client library.

@glimberg
Copy link
Author

I do have AdGuard on the network, and that was the first thing I checked when issues popped up. There were no reported blocks for the IP addresses associated with my HAAS installation. I also use GCP daily for work, so if AdGuard was interfering there, I'd definitely know!

@allenporter
Copy link
Contributor

The logs above look truncated or missing 'info' so its hard to tell exactly what is happening so if you are in fact interested in continuing to diagnose this i might suggest this log setup

logger:
  default: info
  logs:
    homeassistant.components.nest: debug
    google_nest_sdm: debug
    google_nest_sdm.device: debug
    google_nest_sdm.device_manager: debug
    google_nest_sdm.google_nest_subscriber: debug
    google_nest_sdm.event: debug

@georgepstaylor
Copy link

fwiw I'm also having this issue, with the same error message in the logs.

I'm also unable to remove the integration - no error, it just refuses to delete.

I have triple checked the setup in both Google Cloud and the Nest/Google Device Console too. Nothing has changed in my setup and this has been happily working for months now.

@allenporter
Copy link
Contributor

Can you please file your own issue report and fill out the bug template? I can dedup if the root cause seems similar.

@mlamport
Copy link

mlamport commented Sep 2, 2024

My Google Nest Thermostat has stopped working for a number of months now. I have upgrade to the latest HA and still no luck. Error message:

Logger: homeassistant.components.nest
Source: components/nest/init.py:209
integration: Google Nest (documentation, issues)
First occurred: 22:03:00 (2 occurrences)
Last logged: 22:03:24

Configuration error: Failed to create subscriber 'projects/central-embassy-393721/subscriptions/home-assistant-PjK2swRbH0' id was not found

@allenporter
Copy link
Contributor

@mlamport please report a separate issue? it looks like for some reason your subscriber, which is created as part of setup, does not exist. I have heard that there may be an issue where the subscribers will be automatically deleted, so maybe we need to detect this and re-create it. As a workaround in the mean time, deleting the integration and re-adding it should re-create the subscriber.

@allenporter
Copy link
Contributor

Closing since information needed was not provided. Please reopen a new issue when ready to diagnose.

@github-actions github-actions bot locked and limited conversation to collaborators Dec 16, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

5 participants