home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
73.83k stars 30.91k forks source link

pychromecast.socket_client heartbeat timeout, resetting connection and other errors #54557

Closed u8915055 closed 1 year ago

u8915055 commented 3 years ago

The problem

All google home devices on the home network are systematically registering logging entry WARNING messages about timing out on the heartbeat. We have about 10 devices on the network and every one of them is doing it. We have google home mini's, max, home hub, original google home.

Another interesting thing happens when i try to turn on one of the google home devices in home assistant. When i push the power button on say a google home mini, i get this message:

2021-08-12 11:03:04 ERROR (Thread-12) [homeassistant.components.cast.media_player] Failed to cast media https://www.home-assistant.io/images/cast/splash.png. Please make sure the URL is: Reachable from the cast device and either a publicly resolvable hostname or an IP address

Which is weird because its trying to cast a PNG image to a google home mini device. Almost seems like its identifying the devices as the wrong model. I tried turning on another google home mini, same error message.

What is version of Home Assistant Core has the issue?

core-2021.8.6

What was the last working version of Home Assistant Core?

unknown

What type of installation are you running?

Home Assistant Core

Integration causing the issue

Google Cast

Link to integration documentation on our website

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

Example YAML snippet

No response

Anything in the logs that might be useful for us?

2021-08-12 12:09:44 WARNING (Thread-21) [pychromecast.socket_client] [Kitchen Hub(192.168.1.116):8009] Heartbeat timeout, resetting connection
2021-08-12 12:11:23 WARNING (Thread-21) [pychromecast.socket_client] [Kitchen Hub(192.168.1.116):8009] Heartbeat timeout, resetting connection
2021-08-12 12:13:03 WARNING (Thread-21) [pychromecast.socket_client] [Kitchen Hub(192.168.1.116):8009] Heartbeat timeout, resetting connection
2021-08-12 12:13:26 WARNING (Thread-21) [pychromecast.socket_client] [Kitchen Hub(192.168.1.116):8009] Heartbeat timeout, resetting connection
2021-08-12 12:14:09 WARNING (Thread-21) [pychromecast.socket_client] [Kitchen Hub(192.168.1.116):8009] Heartbeat timeout, resetting connection
2021-08-12 12:14:11 ERROR (Thread-32) [homeassistant.components.cast.media_player] Failed to cast media https://www.home-assistant.io/images/cast/splash.png. Please ma
ke sure the URL is: Reachable from the cast device and either a publicly resolvable hostname or an IP address
2021-08-12 12:14:32 WARNING (Thread-21) [pychromecast.socket_client] [Kitchen Hub(192.168.1.116):8009] Heartbeat timeout, resetting connection


### Additional information

_No response_
probot-home-assistant[bot] commented 3 years ago

cast documentation cast source (message by IssueLinks)

probot-home-assistant[bot] commented 3 years ago

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

u8915055 commented 3 years ago

I will add to this that i removed the cast integration, rebooted and re-added the cast integration.. now it only discovers one of my devices! A nest hub. Yet i have a bonjour discovery app on my mac and i can see all 12 google devices there and they all seem to be functional.. so this may be a separate issue but wanted to bring this up..

u8915055 commented 3 years ago

Going to add a bit more here.. i checked all google devices.. the ones that cant be discovered (all but one) are running firmware version 250118 and cast version 1.54.2050118. The one device i can discover, which is a nest hub, is running firmware version 1.20210119.2.1390060 and cast version 1.52.260996.

emontnemery commented 3 years ago

Can you explain your setup in some more detail:

As a workaround you can add a list of known hosts in the integration options: https://www.home-assistant.io/integrations/cast/#known-hosts, that does require that the Chrome Casts have stable IP-addresses though

emontnemery commented 3 years ago

One more thing, would you mind to create a separate issue for the attempt to cast a PNG to your google home mini device?

u8915055 commented 3 years ago

HI there, i will create a separate issue for the PNG thing.

As for my environment, i run HA core on a mac mini running catalina, not in a container, connected to the LAN. Nothing has changed in my environment. Im using ubiquiti Unifi devices.. three access points and a USG as the router. Everything else seems to be working fine. Let me know if you need anything else.. happy to test anything.

picotrain77 commented 3 years ago

Have exactly the same log entries as the OP on all google hubs and chromecast’s and always have. Also all my devices are fixed IP.

DatCFC commented 3 years ago

I will add to this that i removed the cast integration, rebooted and re-added the cast integration.. now it only discovers one of my devices! A nest hub. Yet i have a bonjour discovery app on my mac and i can see all 12 google devices there and they all seem to be functional.. so this may be a separate issue but wanted to bring this up..

Only replying to say that I had the exact same behavior. I am able to add the device IP's, but mDNS does not discover them at all.

pergolafabio commented 3 years ago

is there an update here? i cant use cast too on my hub and on my older chromecast if i just turn on the entity, without even casting i already see the error below:

ERROR (Thread-12) [homeassistant.components.cast.media_player] Failed to cast media https://www.home-assistant.io/images/cast/splash.png. Please make sure the URL is: Reachable from the cast device and either a publicly resolvable hostname or an IP address

emontnemery commented 3 years ago

@pergolafabio that's not what this issue is about, can you please open a new issue?

MaxK99 commented 2 years ago

Same issue also. Environment: HA OS 2021.12.6; RP4; Static IP for all Chromecast devices. Excellent Wi-Fi connection.

@emontnemery, anything I can do to help?

github-actions[bot] commented 2 years ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

ThatTallGuy21 commented 2 years ago

I'm on 2022.4.3 and am experiencing the same warning and errors as above. Is anyone still experiencing this? I have probably a dozen Google Nest smart speakers, displays, chromecasts, and chromecast audios all giving the same warning and errors. Going to attempt to delete and setup the integration again to see if that resolves it.

mrdanbostic commented 2 years ago

I tried to research my error here before coming to post here. Apologies if this was previously covered. Just installed a fresh install of HASS OS on an rpi4. . Have been testing the Google Cast integration & all tested media plays perfecly (mp3 audio files, casting using the Spotify integration, and YouTube). Speaker group playing works & end point media controls work as well. Have tested with a Nest Hub, a few Google minis, Chromecast, Android TV and TCL Smart TV. Even got the tts speech to work quite well. All changes to volume, channel, media, on the cast receiving device instantly reflect back in the entity properties. But when idle, this timeout error has been piling up.

2022-04-22 02:40:45 WARNING (Thread-10) [pychromecast.socket_client] [Bathroom Speaker(192.168.1.192):8009] Heartbeat timeout, resetting connection 2022-04-22 02:40:52 ERROR (Thread-10) [pychromecast.socket_client] [Bathroom Speaker(192.168.1.192):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.192', 8009)), retrying in 5.0s

Thanks much to all in advance

k8gg commented 2 years ago

Here is mine over last few days. HAOS 7.6, core-2022.4.7, supervisor-2022.05.0, Chromecast 2nd generation (pic) with Cast FW 1.56.275994:

Is this the case where Chromecast would reset itself in the middle of the night every day? So the heartbeat timeout occured? And if that is the case, is the solution being we make the warning / error timeout a bit longer in pychromecast?

2022-05-02 02:25:29 WARNING (Thread-6) [pychromecast.socket_client] [Chromecast(192.168.1.20):8009] Heartbeat timeout, resetting connection
2022-05-02 02:25:44 ERROR (Thread-6) [pychromecast.socket_client] [Chromecast(192.168.1.20):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.20', 8009)), retrying in 5.0s
2022-05-03 02:03:27 WARNING (Thread-6) [pychromecast.socket_client] [Chromecast(192.168.1.20):8009] Heartbeat timeout, resetting connection
2022-05-03 02:03:34 ERROR (Thread-6) [pychromecast.socket_client] [Chromecast(192.168.1.20):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.20', 8009)), retrying in 5.0s
2022-05-04 04:31:40 WARNING (Thread-6) [pychromecast.socket_client] [Chromecast(192.168.1.20):8009] Heartbeat timeout, resetting connection
2022-05-04 04:31:55 ERROR (Thread-6) [pychromecast.socket_client] [Chromecast(192.168.1.20):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.20', 8009)), retrying in 5.0s
2022-05-05 04:10:10 WARNING (Thread-6) [pychromecast.socket_client] [Chromecast(192.168.1.20):8009] Heartbeat timeout, resetting connection
2022-05-05 04:10:25 ERROR (Thread-6) [pychromecast.socket_client] [Chromecast(192.168.1.20):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.1.20', 8009)), retrying in 5.0s
ThatTallGuy21 commented 2 years ago

I've been having these issues consistently for the last several months. I continue to upgrade HA Core and Supervisor without noticing any changes. I've also removed the Google Cast integration and completely re-setup in HA the Google Cast devices and temporarily turned UDP back on in my router, and have noticed no difference. My guess is that these errors are happening for devices that don't get used that often, such as on a daily or weekly basis. That's what it looks like on my side at least. Is anyone else noticing the same thing? Currently, I'm running HA Core 2022.6.6, Supervisor 2022.07.0, and HA OS 8.2 so I'm relatively current.

Error logs:

[Master Bathroom Mini(192.168.87.127):8009] Failed to connect to service ServiceInfo(type='host', data=('192.168.87.127', 8009)), retrying in 5.0s 7:12:58 AM – (ERROR) /usr/local/lib/python3.9/site-packages/pychromecast/socket_client.py - message first occurred at July 7, 2022 at 2:02:21 AM and shows up 32 times [Home Group(192.168.87.130):32152] Error communicating with socket, resetting connection 7:12:58 AM – (WARNING) /usr/local/lib/python3.9/site-packages/pychromecast/socket_client.py - message first occurred at July 7, 2022 at 2:09:38 AM and shows up 15 times [Home Group(192.168.87.130):32152] Error reading from socket. 7:12:58 AM – (ERROR) /usr/local/lib/python3.9/site-packages/pychromecast/socket_client.py - message first occurred at July 7, 2022 at 2:09:38 AM and shows up 15 times [Gina's Carport Mini(192.168.87.59):8009] Heartbeat timeout, resetting connection 7:09:39 AM – (WARNING) /usr/local/lib/python3.9/site-packages/pychromecast/socket_client.py - message first occurred at July 7, 2022 at 2:02:14 AM and shows up 18 times

bbow987 commented 2 years ago

I'm seeing the same - however, what I noticed is that when trying to trigger an automation I was using entity and not device when toggling an input_boolean. Once updated, it appears to be working just fine. Now... I don't quite understand when I toggle off, I still get the google home screen even though it's set to 'last input' on the TV....

HAEdwin commented 2 years ago

Same here with three devices (one of which is my Google Hub) it fills the log frequently.

2022-09-28 22:58:59.722 WARNING (Thread-6) [pychromecast.socket_client] [Googlehub(172.16.0.50):8009] Heartbeat timeout, resetting connection
2022-09-28 22:59:29.742 ERROR (Thread-6) [pychromecast.socket_client] [Googlehub(172.16.0.50):8009] Failed to connect to service ServiceInfo(type='host', data=('172.16.0.50', 8009)), retrying in 5.0s
marcmontecalvo commented 2 years ago

Same as everyone else. I have a bunch of google mini's and they are all filling the logs up with this:

Logger: pychromecast.socket_client
Source: /usr/local/lib/python3.10/site-packages/pychromecast/socket_client.py:672
First occurred: October 14, 2022 at 2:48:23 AM (21 occurrences)
Last logged: 4:17:44 AM

[Living Room speaker(10.10.10.205):8009] Heartbeat timeout, resetting connection
[Annabella’s Room Speaker(10.10.10.16):8009] Heartbeat timeout, resetting connection
[Office Speaker(10.10.10.17):8009] Heartbeat timeout, resetting connection
[Mia's Room speaker(10.10.10.19):8009] Heartbeat timeout, resetting connection
[Vincenzo’s room Speaker(10.10.10.225):8009] Heartbeat timeout, resetting connection

I'm on HA 2022.10.4.

Lordnnud commented 2 years ago

I get these messages continually 👎 2022-11-04 17:12:37.889 INFO (Thread-7) [pychromecast.socket_client] [Living Room TV(192.168.1.60):8009] Connection reestablished! 2022-11-04 17:12:47.014 WARNING (MainThread) [meross_iot.model.http.device] Provided bind_time is not int neither datetime. It will be ignored. 2022-11-04 17:13:50.657 WARNING (Thread-7) [pychromecast.socket_client] [Living Room TV(192.168.1.60):8009] Heartbeat timeout, resetting connection 2022-11-04 17:13:50.659 INFO (Thread-7) [pychromecast.controllers] Receiver:channel_disconnected 2022-11-04 17:13:51.822 INFO (Thread-7) [pychromecast.socket_client] [Living Room TV(192.168.1.60):8009] Connection reestablished! 2022-11-04 17:14:45.917 WARNING (Thread-7) [pychromecast.socket_client] [Living Room TV(192.168.1.60):8009] Heartbeat timeout, resetting connection 2022-11-04 17:14:45.918 INFO (Thread-7) [pychromecast.controllers] Receiver:channel_disconnected 2022-11-04 17:14:47.031 WARNING (MainThread) [meross_iot.model.http.device] Provided bind_time is not int neither datetime. It will be ignored. 2022-11-04 17:14:47.122 INFO (Thread-7) [pychromecast.socket_client] [Living Room TV(192.168.1.60):8009] Connection reestablished! 2022-11-04 17:15:59.736 WARNING (Thread-7) [pychromecast.socket_client] [Living Room TV(192.168.1.60):8009] Heartbeat timeout, resetting connection 2022-11-04 17:15:59.737 INFO (Thread-7) [pychromecast.controllers] Receiver:channel_disconnected 2022-11-04 17:16:00.842 INFO (Thread-7) [pychromecast.socket_client] [Living Room TV(192.168.1.60):8009] Connection reestablished! 2022-11-04 17:16:20.940 WARNING (Thread-7) [pychromecast.socket_client] [Living Room TV(192.168.1.60):8009] Heartbeat timeout, resetting connection 2022-11-04 17:16:20.942 INFO (Thread-7) [pychromecast.controllers] Receiver:channel_disconnected

Home Assistant 2022.10.5 Supervisor 2022.10.2 Operating System 9.2 Frontend 20221010.0 - latest

ThatTallGuy21 commented 2 years ago

Just as an aside. I got tired of these warnings and errors clogging up my log, and this not getting any traction. Despite the errors, it never seemed to cause an issue for me, so I instead updated my config (i.e. logger) so that it only shows me critical and fatal level errors for "pychromecast". Now I don't have to think about it.

Lordnnud commented 2 years ago

@ThatTallGuy21 could you share that part of your config file please? Soulds like a handy work around until a fix is provided.

Thanks

ThatTallGuy21 commented 2 years ago

@ThatTallGuy21 could you share that part of your config file please? Soulds like a handy work around until a fix is provided.

Thanks

Sure thing. The below was added into my config.yaml file.

# Suppresses the logging of some noisy errors and warnings that resolve themselves
# See https://www.home-assistant.io/integrations/logger/ for more info
logger:
# Logger will now ONLY display the types of logged items: errors, fatal, and critical
  default: error
  logs: 
# Logger for google/google nest timeout and reconnection warnings and errors - only want to see fatal and critical errors
    pychromecast: fatal 
Lordnnud commented 2 years ago

Thanks @ThatTallGuy21

Oddly, the dahboard integration has stopped flashing on and off in sync with the messages, so the integration seems to be working better....Happy days!

HAEdwin commented 1 year ago

I wouldn't mind if it skips a beat once in a while and ignores this in the log. Put a counter on it and only alert if it misses 5 beats one after the other. This way you don't have to exclude it in the logging an maybe mis it when some real issue is going on.

jriker1 commented 1 year ago

Same here though this has been open a long time. I just freshly reinstalled Home Assistant and am using the Android TV integration. All my NVidia Shields show in the GUI and update but getting these errors in the logs:

2023-02-23 15:20:40.310 WARNING (Thread-5) [pychromecast.socket_client] [SHIELD(192.168.0.55):8009] Heartbeat timeout, resetting connection 2023-02-23 15:20:40.700 WARNING (Thread-4) [pychromecast.socket_client] [SHIELD(192.168.0.56):8009] Heartbeat timeout, resetting connection

Note I can ping the Shields when this is happening from a laptop on the network.

chiahsing commented 1 year ago

+1 to the heartbeat log.

This happens to my nest hub that I used to cast the Lovelace dashboard. When this happens, I also saw that the state of the nest hub changed from playing to off, and then unavailable, and then off again.

issue-triage-workflows[bot] commented 1 year ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.