Chromecast Audio power on/off button connection issues through HASS only

Third party integrations
1

Just was having some weird behavior over the past week with my chromecast audios (CCA’s) relating to not being able to power up CCA’s in HASS after they’ve been powered off in HASS (though can power up from iPhone apps).

HASS properly autodetects an “all home speakers” CCA meda_player (a group defined in the GoogleHome app to tether multiple CCA’s together) as well connects to the CCA’s that I’ve defined in configration.yaml. But after I power off the “all home speakers” media_player in HASS, HASS can’t start it or play streams on it. This only happens randomly though – sometimes HASS can power on the “all home speakers” media_player. In the cases when HASS can’t power up the CCA’s though, I can power them up using any iPhone app that sends audio to CCA’s (Spotify, Pocketcasts, Pandora, TuneIn Radio, SoundCloud, etc). Then HASS can control the “all home speakers” media_player again. I think this user had a similar experience: ChromeCast Audio idle after reboot HA

Setup:
I have four CCA’s around the house and a GoogleHome-defined ‘group’ that holds all of them inside a separate media_player called “all home speakers” (“all home speakers” gets auto-detected by HASS. I’ve also specified the individual CCA IP’s in my configuration.yaml). I have their IP addresses reserved in my router to ensure they get static local IP’s.

Complicators:
It crossed my mind that there is also weird behavior that the “all home speakers” group has a duplicate “all home speakers 2” group that shows up sometimes (I’ve hidden that media_player in my customize: area of configuration.yaml). One CCA is connected to my 2.4GHz while the other three are on 5GHz. Also one has a weak wifi signal, but none of that explains why the whole group won’t play once turned off. Separate issues?

Configuration:
Here is my configuration.yaml pertaining to the CCA’s

homeassistant:
  customize:
    media_player.all_home_speakers_2:
        hidden: true

media_player:
  # Google Chromecasts
  - platform: cast
    host: 192.168.1.7
  - platform: cast
    host: 192.168.1.8
  - platform: cast
    host: 192.168.1.9
  - platform: cast
    host: 192.168.1.10

I’ve reserved each IP in my router as a static local address, so there shouldn’t be an issue with configuration.yaml IP’s not matching actual IP’s.

Errors:
Here are some errors that cropped up via home-assistant.log (could this be from the weak wifi signal? The CCA with the weak signal usually has a coherent stream of audio playing from it / doesn’t sound choppy – though I wasn’t testing it during the times of these error messages)

2017-06-22 05:08:56 ERROR (Thread-34) [pychromecast.socket_client] Error reading from socket.
2017-06-22 05:08:56 ERROR (Thread-19) [pychromecast.socket_client] Error reading from socket.
2017-06-22 05:08:56 WARNING (Thread-19) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-22 05:08:56 ERROR (Thread-20) [pychromecast.socket_client] Error reading from socket.
2017-06-22 05:08:56 ERROR (Thread-17) [pychromecast.socket_client] Error reading from socket.
2017-06-22 05:08:56 ERROR (Thread-18) [pychromecast.socket_client] Error reading from socket.
2017-06-22 05:08:56 ERROR (Thread-19) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:08:56 WARNING (Thread-20) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-22 05:08:56 WARNING (Thread-17) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-22 05:08:56 WARNING (Thread-34) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-22 05:08:56 WARNING (Thread-18) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-22 05:08:56 ERROR (Thread-20) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:08:56 ERROR (Thread-18) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:08:56 ERROR (Thread-17) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:08:56 ERROR (Thread-34) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:21 WARNING (Thread-21) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:21 WARNING (Thread-35) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:21 WARNING (Thread-23) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-14) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-13) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-27) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-33) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-28) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-29) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-37) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-26) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-15) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-16) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-25) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-36) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-22) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-24) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-32) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-30) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:26 WARNING (Thread-31) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-22 05:09:28 ERROR (Thread-35) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:28 ERROR (Thread-21) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:28 ERROR (Thread-23) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:29 ERROR (Thread-28) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:29 ERROR (Thread-27) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:29 ERROR (Thread-33) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:29 ERROR (Thread-14) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:29 ERROR (Thread-13) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:29 ERROR (Thread-26) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:29 ERROR (Thread-36) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:29 ERROR (Thread-25) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:29 ERROR (Thread-16) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:29 ERROR (Thread-15) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:29 ERROR (Thread-24) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:29 ERROR (Thread-22) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:29 ERROR (Thread-30) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:29 ERROR (Thread-32) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 05:09:29 ERROR (Thread-31) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-22 08:48:37 WARNING (Thread-21) [pychromecast.socket_client] Heartbeat timeout, resetting connection

I’ll try to test this out a bit more and update this thread as I learn more.

2

First off I’d remove all the ip addresses and just put

- platform: cast

It will pick them all up, and might explain why you’re getting erroneous behaviour around the “everywhere” player (because this isn’t actually a device, it’s a pretend device that you made in your Google Home app that when you cast to it it plays from all the other devices)

Also, check double check your logs… I randomly have times where I’m expecting something out of the CCAs and nothing happens, check the log and find that pychromecast has been falling to the connect for the previous 30 minutes. I haven’t got to the bottom of why yet, but either a reboot or just waiting an arbitrary amount of time fixes the problem. If you can pin down a trace in the log to a reproducable circumstance then report it on GitHub and hopefully somebody can fix it. (I haven’t reported yet because mine appears completely random so I can’t say how to reproduce the error). I’ll happily test any theories you have to see if I get the same error messages under the same circumstances.

1 Like
3

Thanks for the suggestions. I tried your idea of removing the defined IP’s and that does seem to make HASS take less time to start up. However, the duplicate “all home speakers” group still shows up (in fact, now there’s a triplicate group!).

I recently learned that discover: has an option to ignore components. I’m considering implementing discover: ignore: for CCA’s and then defining them again. I’ll let yo know if that fixes connectivity.

I’m still getting these random connection errors too. When I run a script to turn on, turn up volume, and play a link, I still get a slew of errors related to NotConnected("Chromecast is connecting...") It turns out, now it seems, that I have to restart HASS to get the devices to work again, rather than play a stream through an iPhone/Chromecast app. So that appears to be slightly different behavior than when I was using CCA IP’s.

Here my full log just in case it’s helpful somehow

2017-06-26 10:26:50 WARNING (MainThread) [homeassistant.setup] Setup of media_player is taking over 10 seconds.
2017-06-26 10:26:51 WARNING (MainThread) [homeassistant.components.media_player] Setup of platform cast is taking over 10 seconds.
2017-06-26 11:48:20 WARNING (Thread-15) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-26 11:50:29 WARNING (Thread-15) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-26 12:30:23 ERROR (Thread-17) [pychromecast.socket_client] Error reading from socket.
2017-06-26 12:30:23 WARNING (Thread-17) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-26 12:30:23 ERROR (Thread-17) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-26 12:46:26 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal read error on SSL transport
Traceback (most recent call last):
  File "/usr/lib/python3.4/asyncio/selector_events.py", line 825, in _read_ready
    data = self._sock.recv(self.max_size)
  File "/usr/lib/python3.4/ssl.py", line 730, in recv
    return self.read(buflen)
  File "/usr/lib/python3.4/ssl.py", line 619, in read
    v = self._sslobj.read(len or 1024)
OSError: [Errno 113] No route to host
2017-06-26 17:55:18 ERROR (Thread-22) [pychromecast.socket_client] Error reading from socket.
2017-06-26 17:55:18 WARNING (Thread-22) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-26 17:55:18 ERROR (Thread-22) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-26 18:17:52 WARNING (MainThread) [homeassistant.helpers.entity] Update for media_player.tv_pc is already in progress
2017-06-26 18:17:54 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.4/asyncio/tasks.py", line 233, in _step
    result = coro.throw(exc)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/core.py", line 1021, in _event_to_service_call
    yield from service_handler.func(service_call)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/__init__.py", line 389, in async_service_handler
    yield from getattr(player, method['method'])(**params)
  File "/usr/lib/python3.4/asyncio/futures.py", line 388, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.4/asyncio/tasks.py", line 286, in _wakeup
    value = future.result()
  File "/usr/lib/python3.4/asyncio/futures.py", line 277, in result
    raise self._exception
  File "/usr/lib/python3.4/concurrent/futures/thread.py", line 54, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/cast.py", line 273, in turn_off
    self.cast.quit_app()
  File "/home/homeassistant/.homeassistant/deps/pychromecast/__init__.py", line 273, in quit_app
    self.socket_client.receiver_controller.stop_app()
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 845, in stop_app
    inc_session_id=True, callback_function=callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/controllers/__init__.py", line 84, in send_message
    self.namespace, data, inc_session_id, callback_function)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 603, in send_platform_message
    inc_session_id, callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 554, in send_message
    self._ensure_channel_connected(destination_id)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 640, in _ensure_channel_connected
    no_add_request_id=True)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 590, in send_message
    raise NotConnected("Chromecast is connecting...")
pychromecast.error.NotConnected: Chromecast is connecting...
2017-06-26 18:20:53 ERROR (Thread-3) [homeassistant.components.switch.broadlink] Input strings must be a multiple of 16 in length
2017-06-26 18:20:54 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.4/asyncio/tasks.py", line 233, in _step
    result = coro.throw(exc)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/core.py", line 1021, in _event_to_service_call
    yield from service_handler.func(service_call)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/__init__.py", line 389, in async_service_handler
    yield from getattr(player, method['method'])(**params)
  File "/usr/lib/python3.4/asyncio/futures.py", line 388, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.4/asyncio/tasks.py", line 286, in _wakeup
    value = future.result()
  File "/usr/lib/python3.4/asyncio/futures.py", line 277, in result
    raise self._exception
  File "/usr/lib/python3.4/concurrent/futures/thread.py", line 54, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/cast.py", line 269, in turn_on
    CAST_SPLASH, pychromecast.STREAM_TYPE_BUFFERED)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/controllers/media.py", line 466, in play_media
    callback_function=app_launched_callback)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 806, in launch_app
    self.update_status(lambda response:
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 797, in update_status
    callback_function=callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/controllers/__init__.py", line 84, in send_message
    self.namespace, data, inc_session_id, callback_function)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 603, in send_platform_message
    inc_session_id, callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 590, in send_message
    raise NotConnected("Chromecast is connecting...")
pychromecast.error.NotConnected: Chromecast is connecting...
2017-06-26 21:02:36 ERROR (Thread-27) [pychromecast.socket_client] Error reading from socket.
2017-06-26 21:02:36 WARNING (Thread-27) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-26 21:02:36 ERROR (Thread-27) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-26 22:03:48 ERROR (Thread-22) [pychromecast.socket_client] Error reading from socket.
2017-06-26 22:03:48 WARNING (Thread-22) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-26 22:03:48 ERROR (Thread-22) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-26 22:12:48 ERROR (Thread-27) [pychromecast.socket_client] Error reading from socket.
2017-06-26 22:12:48 WARNING (Thread-27) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-26 22:12:48 ERROR (Thread-27) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-26 22:13:48 ERROR (Thread-17) [pychromecast.socket_client] Error reading from socket.
2017-06-26 22:13:48 WARNING (Thread-17) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-26 22:13:48 ERROR (Thread-17) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-26 22:29:28 ERROR (Thread-27) [pychromecast.socket_client] Error reading from socket.
2017-06-26 22:29:28 WARNING (Thread-27) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-26 22:29:28 ERROR (Thread-27) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-26 23:57:04 ERROR (Thread-22) [pychromecast.socket_client] Error reading from socket.
2017-06-26 23:57:04 WARNING (Thread-22) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-26 23:57:04 ERROR (Thread-22) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 00:11:07 ERROR (Thread-27) [pychromecast.socket_client] Error reading from socket.
2017-06-27 00:11:07 WARNING (Thread-27) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-27 00:11:07 ERROR (Thread-27) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 00:45:27 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.4/asyncio/tasks.py", line 233, in _step
    result = coro.throw(exc)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/core.py", line 1021, in _event_to_service_call
    yield from service_handler.func(service_call)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/__init__.py", line 389, in async_service_handler
    yield from getattr(player, method['method'])(**params)
  File "/usr/lib/python3.4/asyncio/futures.py", line 388, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.4/asyncio/tasks.py", line 286, in _wakeup
    value = future.result()
  File "/usr/lib/python3.4/asyncio/futures.py", line 277, in result
    raise self._exception
  File "/usr/lib/python3.4/concurrent/futures/thread.py", line 54, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/cast.py", line 273, in turn_off
    self.cast.quit_app()
  File "/home/homeassistant/.homeassistant/deps/pychromecast/__init__.py", line 273, in quit_app
    self.socket_client.receiver_controller.stop_app()
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 845, in stop_app
    inc_session_id=True, callback_function=callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/controllers/__init__.py", line 84, in send_message
    self.namespace, data, inc_session_id, callback_function)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 603, in send_platform_message
    inc_session_id, callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 554, in send_message
    self._ensure_channel_connected(destination_id)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 640, in _ensure_channel_connected
    no_add_request_id=True)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 590, in send_message
    raise NotConnected("Chromecast is connecting...")
pychromecast.error.NotConnected: Chromecast is connecting...
2017-06-27 01:01:04 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal read error on SSL transport
Traceback (most recent call last):
  File "/usr/lib/python3.4/asyncio/selector_events.py", line 825, in _read_ready
    data = self._sock.recv(self.max_size)
  File "/usr/lib/python3.4/ssl.py", line 730, in recv
    return self.read(buflen)
  File "/usr/lib/python3.4/ssl.py", line 619, in read
    v = self._sslobj.read(len or 1024)
OSError: [Errno 113] No route to host
2017-06-27 01:16:14 ERROR (Thread-22) [pychromecast.socket_client] Error reading from socket.
2017-06-27 01:16:14 WARNING (Thread-22) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-27 01:16:14 ERROR (Thread-22) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 02:03:49 ERROR (Thread-17) [pychromecast.socket_client] Error reading from socket.
2017-06-27 02:03:49 WARNING (Thread-17) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-27 02:03:49 ERROR (Thread-17) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 02:04:14 WARNING (Thread-19) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-27 02:04:18 WARNING (Thread-24) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-27 02:04:19 WARNING (Thread-14) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-27 02:04:44 ERROR (Thread-19) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 02:04:48 ERROR (Thread-24) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 02:04:49 ERROR (Thread-14) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 02:05:07 ERROR (Thread-22) [pychromecast.socket_client] Error reading from socket.
2017-06-27 02:05:07 WARNING (Thread-22) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-27 02:05:07 ERROR (Thread-22) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 02:18:47 WARNING (Thread-20) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-27 02:18:47 WARNING (Thread-15) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-27 02:18:49 WARNING (Thread-23) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-27 02:18:52 ERROR (Thread-23) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 02:18:54 ERROR (Thread-20) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 02:18:54 ERROR (Thread-15) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 02:19:03 ERROR (Thread-17) [pychromecast.socket_client] Error reading from socket.
2017-06-27 02:19:03 WARNING (Thread-17) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-27 02:19:03 ERROR (Thread-17) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 02:34:27 WARNING (Thread-18) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-27 02:34:30 WARNING (Thread-25) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-27 02:34:33 WARNING (Thread-13) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-27 02:34:57 ERROR (Thread-18) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 02:35:00 ERROR (Thread-25) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 02:35:03 ERROR (Thread-13) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 02:35:30 ERROR (Thread-27) [pychromecast.socket_client] Error reading from socket.
2017-06-27 02:35:30 WARNING (Thread-27) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-27 02:35:30 ERROR (Thread-27) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 03:03:26 WARNING (Thread-16) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-27 03:03:31 WARNING (Thread-26) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-27 03:03:34 WARNING (Thread-21) [pychromecast.socket_client] Heartbeat timeout, resetting connection
2017-06-27 03:03:38 ERROR (Thread-21) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 03:03:38 ERROR (Thread-26) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 04:56:13 ERROR (Thread-22) [pychromecast.socket_client] Error reading from socket.
2017-06-27 04:56:13 WARNING (Thread-22) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-27 04:56:13 ERROR (Thread-22) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 04:56:26 ERROR (Thread-17) [pychromecast.socket_client] Error reading from socket.
2017-06-27 04:56:26 WARNING (Thread-17) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-27 04:56:26 ERROR (Thread-17) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 04:59:16 ERROR (Thread-27) [pychromecast.socket_client] Error reading from socket.
2017-06-27 04:59:16 WARNING (Thread-27) [pychromecast.socket_client] Error communicating with socket, resetting connection
2017-06-27 04:59:16 ERROR (Thread-27) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-06-27 09:00:04 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.4/asyncio/tasks.py", line 233, in _step
    result = coro.throw(exc)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/core.py", line 1021, in _event_to_service_call
    yield from service_handler.func(service_call)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/__init__.py", line 389, in async_service_handler
    yield from getattr(player, method['method'])(**params)
  File "/usr/lib/python3.4/asyncio/futures.py", line 388, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.4/asyncio/tasks.py", line 286, in _wakeup
    value = future.result()
  File "/usr/lib/python3.4/asyncio/futures.py", line 277, in result
    raise self._exception
  File "/usr/lib/python3.4/concurrent/futures/thread.py", line 54, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/cast.py", line 269, in turn_on
    CAST_SPLASH, pychromecast.STREAM_TYPE_BUFFERED)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/controllers/media.py", line 466, in play_media
    callback_function=app_launched_callback)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 806, in launch_app
    self.update_status(lambda response:
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 797, in update_status
    callback_function=callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/controllers/__init__.py", line 84, in send_message
    self.namespace, data, inc_session_id, callback_function)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 603, in send_platform_message
    inc_session_id, callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 554, in send_message
    self._ensure_channel_connected(destination_id)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 640, in _ensure_channel_connected
    no_add_request_id=True)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 590, in send_message
    raise NotConnected("Chromecast is connecting...")
pychromecast.error.NotConnected: Chromecast is connecting...
2017-06-27 09:00:15 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.4/asyncio/tasks.py", line 233, in _step
    result = coro.throw(exc)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/core.py", line 1021, in _event_to_service_call
    yield from service_handler.func(service_call)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/__init__.py", line 389, in async_service_handler
    yield from getattr(player, method['method'])(**params)
  File "/usr/lib/python3.4/asyncio/futures.py", line 388, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.4/asyncio/tasks.py", line 286, in _wakeup
    value = future.result()
  File "/usr/lib/python3.4/asyncio/futures.py", line 277, in result
    raise self._exception
  File "/usr/lib/python3.4/concurrent/futures/thread.py", line 54, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/cast.py", line 309, in play_media
    self.cast.media_controller.play_media(media_id, media_type)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/controllers/media.py", line 466, in play_media
    callback_function=app_launched_callback)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 806, in launch_app
    self.update_status(lambda response:
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 797, in update_status
    callback_function=callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/controllers/__init__.py", line 84, in send_message
    self.namespace, data, inc_session_id, callback_function)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 603, in send_platform_message
    inc_session_id, callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 590, in send_message
    raise NotConnected("Chromecast is connecting...")
pychromecast.error.NotConnected: Chromecast is connecting...
2017-06-27 09:41:07 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.4/asyncio/tasks.py", line 233, in _step
    result = coro.throw(exc)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/core.py", line 1021, in _event_to_service_call
    yield from service_handler.func(service_call)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/__init__.py", line 389, in async_service_handler
    yield from getattr(player, method['method'])(**params)
  File "/usr/lib/python3.4/asyncio/futures.py", line 388, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.4/asyncio/tasks.py", line 286, in _wakeup
    value = future.result()
  File "/usr/lib/python3.4/asyncio/futures.py", line 277, in result
    raise self._exception
  File "/usr/lib/python3.4/concurrent/futures/thread.py", line 54, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/cast.py", line 309, in play_media
    self.cast.media_controller.play_media(media_id, media_type)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/controllers/media.py", line 466, in play_media
    callback_function=app_launched_callback)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 806, in launch_app
    self.update_status(lambda response:
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 797, in update_status
    callback_function=callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/controllers/__init__.py", line 84, in send_message
    self.namespace, data, inc_session_id, callback_function)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 603, in send_platform_message
    inc_session_id, callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 590, in send_message
    raise NotConnected("Chromecast is connecting...")
pychromecast.error.NotConnected: Chromecast is connecting...
2017-06-27 09:47:18 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.4/asyncio/tasks.py", line 233, in _step
    result = coro.throw(exc)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/core.py", line 1021, in _event_to_service_call
    yield from service_handler.func(service_call)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/__init__.py", line 389, in async_service_handler
    yield from getattr(player, method['method'])(**params)
  File "/usr/lib/python3.4/asyncio/futures.py", line 388, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.4/asyncio/tasks.py", line 286, in _wakeup
    value = future.result()
  File "/usr/lib/python3.4/asyncio/futures.py", line 277, in result
    raise self._exception
  File "/usr/lib/python3.4/concurrent/futures/thread.py", line 54, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/cast.py", line 309, in play_media
    self.cast.media_controller.play_media(media_id, media_type)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/controllers/media.py", line 466, in play_media
    callback_function=app_launched_callback)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 806, in launch_app
    self.update_status(lambda response:
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 797, in update_status
    callback_function=callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/controllers/__init__.py", line 84, in send_message
    self.namespace, data, inc_session_id, callback_function)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 603, in send_platform_message
    inc_session_id, callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 590, in send_message
    raise NotConnected("Chromecast is connecting...")
pychromecast.error.NotConnected: Chromecast is connecting...
2017-06-27 10:21:39 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.4/asyncio/tasks.py", line 233, in _step
    result = coro.throw(exc)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/core.py", line 1021, in _event_to_service_call
    yield from service_handler.func(service_call)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/__init__.py", line 389, in async_service_handler
    yield from getattr(player, method['method'])(**params)
  File "/usr/lib/python3.4/asyncio/futures.py", line 388, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.4/asyncio/tasks.py", line 286, in _wakeup
    value = future.result()
  File "/usr/lib/python3.4/asyncio/futures.py", line 277, in result
    raise self._exception
  File "/usr/lib/python3.4/concurrent/futures/thread.py", line 54, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/cast.py", line 309, in play_media
    self.cast.media_controller.play_media(media_id, media_type)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/controllers/media.py", line 466, in play_media
    callback_function=app_launched_callback)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 806, in launch_app
    self.update_status(lambda response:
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 797, in update_status
    callback_function=callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/controllers/__init__.py", line 84, in send_message
    self.namespace, data, inc_session_id, callback_function)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 603, in send_platform_message
    inc_session_id, callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 590, in send_message
    raise NotConnected("Chromecast is connecting...")
pychromecast.error.NotConnected: Chromecast is connecting...

I’ll keep you posted if I find out any more.

1 Like
4

Yeah, I get random errors like that, and as I said I can’t seem to pin down a cause, it seems totally random here at the moment. Hopefully one of us will notice a pattern!

5

Thanks for the fast reply. I was editing my last post when you answered: I noticed I’m actually still getting duplicate (and now triplicate) groups detected in HASS.

I’ve also noticed that it seems only the “all home speakers” group is having trouble playing. Could this be the connection issue? Maybe the CCA software group re-establishes itself over time and HASS picks up the new instances as new media_player devices? That would explain connection problems (if HASS was trying to control a CCA software group that no longer existed).

Are you getting any duplicate CCA groups in your setup (Developer Tools > States > media_player.YOUR_CCA_GROUP_NAME_2 ) during connection errors?

6

No, I don’t get any duplicates, but then I don’t use discovery.

I have 3 chromecasts, and then an “everywhere” group, my configuration just has:

- platform: cast

…and I get 4 media players appear in the interface (one for each CCA, and one for “Everywhere”).

The only thing I have is just randomly something will happen that should have been accompanied by a TTS notification, or I’ll go to cast things and it doesn’t work, when I look in the logs I find the pychromecast errors. Sometimes I just leave it a while and it fixes itself, sometimes I reboot and it’s fine as soon as it reloads. As I say, can’t pin down a pattern to the failures, it just seems totally random here.

7

No worries, thanks for trying.

Well! I can confirm that my error messages are a result of a stream trying to run to one of my “everywhere” groups that is no longer a viable instance. I tested my groups by running JSON commands from the Developer Tools > Services > Service Data interface:

Domain: media_player
Service: play_media
Service Data (JSON, optional):

{
   "entity_id" : "media_player.all_home_speakers_3",
   "media_content_id" : "http://72.10.14.138:8000/JAZZMP3.mp3",
   "media_content_type" : "'audio/mp4'"
}

If I select the correct instance (all_home_speakers_2), then music plays through all the speakers and there are no errors. If I select one of the incorrect instances (all_home_speakers), no music plays but there’s no error message. If I select the other incorrect instance (all_home_speakers_3), no music plays and I get this error message:

2017-06-27 11:30:47 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.4/asyncio/tasks.py", line 233, in _step
    result = coro.throw(exc)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/core.py", line 1021, in _event_to_service_call
    yield from service_handler.func(service_call)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/__init__.py", line 389, in async_service_handler
    yield from getattr(player, method['method'])(**params)
  File "/usr/lib/python3.4/asyncio/futures.py", line 388, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.4/asyncio/tasks.py", line 286, in _wakeup
    value = future.result()
  File "/usr/lib/python3.4/asyncio/futures.py", line 277, in result
    raise self._exception
  File "/usr/lib/python3.4/concurrent/futures/thread.py", line 54, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/cast.py", line 309, in play_media
    self.cast.media_controller.play_media(media_id, media_type)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/controllers/media.py", line 466, in play_media
    callback_function=app_launched_callback)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 806, in launch_app
    self.update_status(lambda response:
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 797, in update_status
    callback_function=callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/controllers/__init__.py", line 84, in send_message
    self.namespace, data, inc_session_id, callback_function)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 603, in send_platform_message
    inc_session_id, callback_function_param)
  File "/home/homeassistant/.homeassistant/deps/pychromecast/socket_client.py", line 590, in send_message
    raise NotConnected("Chromecast is connecting...")
pychromecast.error.NotConnected: Chromecast is connecting...

To attempt to solve this, I’m now using this in my configuration.yaml (defining individual IP’s prevents me from seeing my “everywhere” group, plus I’m taking your advice :slight_smile: ):

discovery:
  ignore:
    - google_cast

media_player:
  # Google Chromecasts
  - platform: cast
#    host: 192.168.1.7
#  - platform: cast
#    host: 192.168.1.8
#  - platform: cast
#    host: 192.168.1.9
#  - platform: cast
#    host: 192.168.1.10

Hopefully this will fix half my problem. I’ll keep an eye out for the heartbeat errors now and see if I can pinpoint a cause.

UPDATE: No longer getting duplicate CCA “everywhere” group instances, but I am still getting the same connection error message :frowning:

8

You ever figure this out

9

nope :frowning: still getting errors in my log

10

You know… I’m not getting actual chromecast audio playback problems anymore. At least, I’ve had a long stretch of glitch-free use since updating to 49.0 or so (and now I’m at HASS 0.50.1). I do still get frequent WARNING (Thread-14) [pychromecast.socket_client] Heartbeat timeout, resetting connection errors in my log, but no actual playback issues.

I’ll edit/update this if I get errors again though. — Chromcast, I’ve got my eye on you…

11

Yep still an issue in 0.50.1:
This morning, the “everywhere”/“all home speakers” CCA group didn’t play. Manually initiating my radio stream script to play “everywhere” didn’t work either. But manually initiating my radio stream script to play just the bedroom worked.

2017-08-03 06:48:15 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.4/asyncio/tasks.py", line 233, in _step
    result = coro.throw(exc)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/core.py", line 1025, in _event_to_service_call
    yield from service_handler.func(service_call)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/__init__.py", line 409, in async_service_handler
    yield from getattr(player, method['method'])(**params)
  File "/usr/lib/python3.4/asyncio/futures.py", line 388, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.4/asyncio/tasks.py", line 286, in _wakeup
    value = future.result()
  File "/usr/lib/python3.4/asyncio/futures.py", line 277, in result
    raise self._exception
  File "/usr/lib/python3.4/concurrent/futures/thread.py", line 54, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.4/site-packages/homeassistant/components/media_player/cast.py", line 303, in play_media
    self.cast.media_controller.play_media(media_id, media_type)
  File "/srv/homeassistant/lib/python3.4/site-packages/pychromecast/controllers/media.py", line 466, in play_media
    callback_function=app_launched_callback)
  File "/srv/homeassistant/lib/python3.4/site-packages/pychromecast/socket_client.py", line 806, in launch_app
    self.update_status(lambda response:
  File "/srv/homeassistant/lib/python3.4/site-packages/pychromecast/socket_client.py", line 797, in update_status
    callback_function=callback_function_param)
  File "/srv/homeassistant/lib/python3.4/site-packages/pychromecast/controllers/__init__.py", line 84, in send_message
    self.namespace, data, inc_session_id, callback_function)
  File "/srv/homeassistant/lib/python3.4/site-packages/pychromecast/socket_client.py", line 603, in send_platform_message
    inc_session_id, callback_function_param)
  File "/srv/homeassistant/lib/python3.4/site-packages/pychromecast/socket_client.py", line 597, in send_message
    raise NotConnected("Chromecast is connecting...")
pychromecast.error.NotConnected: Chromecast is connecting...
12

I’m still not able to reliably stream to my “all home speakers” group, even though individual CCA’s work (HASS 0.52.1). Any chances some amazing programmer could take a look so I can try to impress a girl next week haha? Jk, I do really appreciate the work everyone does. Just reporting in with updates.

(Now that I have Tradfri lights, I may not be able to mine for CCA error messages until I figure out how to get my Tradfri gateway from spamming my error log)

13

Hi @Wheezy,

I had that issue purely with a CCA that I had called “Home”,
Not sure why but renaming into “House” fixed it. Wondering whether the “home” word is somehow recognised as a keyword and throwing spanners in the works

I do however have loads of errors like yours every day and tried a variation of defining IPs, just using Cast (discovery) and using Cast (discovery) + defining IP addresses. No Joy

And this morning it just won’t connect / recognise any CCA :cry:

I tried to clear the DB (actually I removed the link to my MySQL DB in recorder) and no difference…

2017-09-29 09:17:38 ERROR (Thread-6) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-09-29 09:17:39 ERROR (Thread-9) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-09-29 09:17:39 ERROR (Thread-3) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-09-29 09:17:48 ERROR (Thread-10) [pychromecast.socket_client] Failed to connect, retrying in 5.0s
2017-09-29 09:17:58 ERROR (MainThread) [homeassistant.components.media_player] Setup of platform cast is taking longer than 60 seconds. Startup will proceed without waiting any longer.
2017-09-29 09:17:58 ERROR (MainThread) [homeassistant.components.media_player] Setup of platform cast is taking longer than 60 seconds. Startup will proceed without waiting any longer.
2017-09-29 09:17:59 ERROR (MainThread) [homeassistant.components.media_player] Setup of platform cast is taking longer than 60 seconds. Startup will proceed without waiting any longer.
2017-09-29 09:17:59 ERROR (MainThread) [homeassistant.components.media_player] Setup of platform cast is taking longer than 60 seconds. Startup will proceed without waiting any longer.

any idea?

1 Like
14

Short update about the above: I rebooted my router (Virgin Media Hub3) and managed to reconnect.
I’m now wondering whether the issues are due to drops in the internet connection (Virgin auto updates/maintenance)?

@Wheezy out of interest do you have the same router by chance?

15

Thanks for helping to validate this as an issue. edif30 and I have been trying to gain some traction for it on the home-assistant github since May. Chromcast Audio would be a killer feature of HASS if it was stable.

My router is a Netgear N750 Wireless Dual Band Gigabit Router, Model WNDR4300. I wonder if rebooting or renaming the group changed the IP of your chromecast software group so that it wouldn’t collide with the IP of a chromecast audio device. That’s been my latest working theory for this problem, though it’s kind of a thin theory (there are IP collisions, but iPhone apps don’t have problems with them; so I wonder if that’s actually what HASS is hanging up on or not – not sure how to test it).

16

Interesting (?) bit for me I tend to see the errors mostly at around 2am BST and 4am BST. Not sure if it’s down to my router doing some maintenance or down to the chromecasts themselves doing something similar… (2 cca and a chromecast enabled onkyo av receiver)
I’ll probably get a proper router round black Friday time so if this issue is still not fixed by then I will have more info to provide I guess

17

0.55, python 3.6.2 and still same ole issue. I did learn something though… Seems that if your chromecast/google home goes into a “sleep mode”… the internet on that device has to wake back up. Now google home you’d think would always be sending keep alives since it is always listening… That’s not the case! They attempt to connect upon a wake word which then they will send the request upstream to the google servers. Now… this could become a problem for HA because it apparently depends on any cast device to be connected to the internet. I wonder if this logic can be scrapped from the component as a test to see what happens. IDK what was changed back in the early .04x releases but it has been bad since. Used to be great prior. Here is yet another one of my errors in the logs.

Oct 10 06:25:49 ha-pi hass[22179]: #033[31m2017-10-10 06:25:49 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved#033[0m
Oct 10 06:25:49 ha-pi hass[22179]: Traceback (most recent call last):
Oct 10 06:25:49 ha-pi hass[22179]: File "/usr/local/lib/python3.6/asyncio/tasks.py", line 182, in _step
Oct 10 06:25:49 ha-pi hass[22179]: result = coro.throw(exc)
Oct 10 06:25:49 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/homeassistant/core.py", line 1025, in _event_to_service_call
Oct 10 06:25:49 ha-pi hass[22179]: yield from service_handler.func(service_call)
Oct 10 06:25:49 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/homeassistant/components/media_player/__init__.py", line 408, in async_service_handler
Oct 10 06:25:49 ha-pi hass[22179]: yield from getattr(player, method['method'])(**params)
Oct 10 06:25:49 ha-pi hass[22179]: File "/usr/local/lib/python3.6/asyncio/futures.py", line 332, in __iter__
Oct 10 06:25:49 ha-pi hass[22179]: yield self  # This tells Task to wait for completion.
Oct 10 06:25:49 ha-pi hass[22179]: File "/usr/local/lib/python3.6/asyncio/tasks.py", line 250, in _wakeup
Oct 10 06:25:49 ha-pi hass[22179]: future.result()
Oct 10 06:25:49 ha-pi hass[22179]: File "/usr/local/lib/python3.6/asyncio/futures.py", line 245, in result
Oct 10 06:25:49 ha-pi hass[22179]: raise self._exception
Oct 10 06:25:49 ha-pi hass[22179]: File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
Oct 10 06:25:49 ha-pi hass[22179]: result = self.fn(*self.args, **self.kwargs)
Oct 10 06:25:49 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/homeassistant/components/media_player/cast.py", line 315, in play_media
Oct 10 06:25:49 ha-pi hass[22179]: self.cast.media_controller.play_media(media_id, media_type)
Oct 10 06:25:49 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/controllers/media.py", line 466, in play_media
Oct 10 06:25:49 ha-pi hass[22179]: callback_function=app_launched_callback)
Oct 10 06:25:49 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 806, in launch_app
Oct 10 06:25:49 ha-pi hass[22179]: self.update_status(lambda response:
Oct 10 06:25:49 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 797, in update_status
Oct 10 06:25:49 ha-pi hass[22179]: callback_function=callback_function_param)
Oct 10 06:25:49 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/controllers/__init__.py", line 84, in send_message
Oct 10 06:25:49 ha-pi hass[22179]: self.namespace, data, inc_session_id, callback_function)
Oct 10 06:25:49 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 603, in send_platform_message
Oct 10 06:25:49 ha-pi hass[22179]: inc_session_id, callback_function_param)
Oct 10 06:25:49 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 554, in send_message
Oct 10 06:25:49 ha-pi hass[22179]: self._ensure_channel_connected(destination_id)
Oct 10 06:25:49 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 640, in _ensure_channel_connected
Oct 10 06:25:49 ha-pi hass[22179]: no_add_request_id=True)
Oct 10 06:25:49 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 597, in send_message
Oct 10 06:25:49 ha-pi hass[22179]: raise NotConnected("Chromecast is connecting...")
Oct 10 06:25:49 ha-pi hass[22179]: pychromecast.error.NotConnected: Chromecast is connecting...#033[0m
Oct 10 06:28:09 ha-pi hass[22179]: #033[33m2017-10-10 06:28:09 WARNING (Thread-9) [pychromecast.socket_client] Heartbeat timeout, resetting connection#033[0m
Oct 10 06:28:39 ha-pi hass[22179]: #033[31m2017-10-10 06:28:39 ERROR (Thread-9) [pychromecast.socket_client] Failed to connect, retrying in 5.0s#033[0m
Oct 10 06:29:28 ha-pi hass[22179]: #033[33m2017-10-10 06:29:28 WARNING (Thread-9) [pychromecast.socket_client] Heartbeat timeout, resetting connection#033[0m
Oct 10 06:29:58 ha-pi hass[22179]: #033[31m2017-10-10 06:29:58 ERROR (Thread-9) [pychromecast.socket_client] Failed to connect, retrying in 5.0s#033[0m
Oct 10 06:32:59 ha-pi hass[22179]: #033[31m2017-10-10 06:32:59 ERROR (Thread-6) [pychromecast.socket_client] Error reading from socket.#033[0m
Oct 10 06:32:59 ha-pi hass[22179]: #033[33m2017-10-10 06:32:59 WARNING (Thread-6) [pychromecast.socket_client] Error communicating with socket, resetting connection#033[0m
Oct 10 06:32:59 ha-pi hass[22179]: #033[31m2017-10-10 06:32:59 ERROR (Thread-6) [pychromecast.socket_client] Failed to connect, retrying in 5.0s#033[0m
Oct 10 06:34:21 ha-pi hass[22179]: #033[33m2017-10-10 06:34:21 WARNING (Thread-9) [pychromecast.socket_client] Heartbeat timeout, resetting connection#033[0m
Oct 10 06:34:30 ha-pi hass[22179]: #033[31m2017-10-10 06:34:30 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved#033[0m
Oct 10 06:34:30 ha-pi hass[22179]: Traceback (most recent call last):
Oct 10 06:34:30 ha-pi hass[22179]: File "/usr/local/lib/python3.6/asyncio/tasks.py", line 182, in _step
Oct 10 06:34:30 ha-pi hass[22179]: result = coro.throw(exc)
Oct 10 06:34:30 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/homeassistant/core.py", line 1025, in _event_to_service_call
Oct 10 06:34:30 ha-pi hass[22179]: yield from service_handler.func(service_call)
Oct 10 06:34:30 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/homeassistant/components/media_player/__init__.py", line 408, in async_service_handler
Oct 10 06:34:30 ha-pi hass[22179]: yield from getattr(player, method['method'])(**params)
Oct 10 06:34:30 ha-pi hass[22179]: File "/usr/local/lib/python3.6/asyncio/futures.py", line 332, in __iter__
Oct 10 06:34:30 ha-pi hass[22179]: yield self  # This tells Task to wait for completion.
Oct 10 06:34:30 ha-pi hass[22179]: File "/usr/local/lib/python3.6/asyncio/tasks.py", line 250, in _wakeup
Oct 10 06:34:30 ha-pi hass[22179]: future.result()
Oct 10 06:34:30 ha-pi hass[22179]: File "/usr/local/lib/python3.6/asyncio/futures.py", line 245, in result
Oct 10 06:34:30 ha-pi hass[22179]: raise self._exception
Oct 10 06:34:30 ha-pi hass[22179]: File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
Oct 10 06:34:30 ha-pi hass[22179]: result = self.fn(*self.args, **self.kwargs)
Oct 10 06:34:30 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/homeassistant/components/media_player/cast.py", line 275, in turn_on
Oct 10 06:34:30 ha-pi hass[22179]: CAST_SPLASH, pychromecast.STREAM_TYPE_BUFFERED)
Oct 10 06:34:30 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/controllers/media.py", line 466, in play_media
Oct 10 06:34:30 ha-pi hass[22179]: callback_function=app_launched_callback)
Oct 10 06:34:30 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 806, in launch_app
Oct 10 06:34:30 ha-pi hass[22179]: self.update_status(lambda response:
Oct 10 06:34:30 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 797, in update_status
Oct 10 06:34:30 ha-pi hass[22179]: callback_function=callback_function_param)
Oct 10 06:34:30 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/controllers/__init__.py", line 84, in send_message
Oct 10 06:34:30 ha-pi hass[22179]: self.namespace, data, inc_session_id, callback_function)
Oct 10 06:34:30 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 603, in send_platform_message
Oct 10 06:34:30 ha-pi hass[22179]: inc_session_id, callback_function_param)
Oct 10 06:34:30 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 554, in send_message
Oct 10 06:34:30 ha-pi hass[22179]: self._ensure_channel_connected(destination_id)
Oct 10 06:34:30 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 640, in _ensure_channel_connected
Oct 10 06:34:30 ha-pi hass[22179]: no_add_request_id=True)
Oct 10 06:34:30 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 597, in send_message
Oct 10 06:34:30 ha-pi hass[22179]: raise NotConnected("Chromecast is connecting...")
Oct 10 06:34:30 ha-pi hass[22179]: pychromecast.error.NotConnected: Chromecast is connecting...#033[0m
Oct 10 06:34:40 ha-pi hass[22179]: #033[31m2017-10-10 06:34:40 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved#033[0m
Oct 10 06:34:40 ha-pi hass[22179]: Traceback (most recent call last):
Oct 10 06:34:40 ha-pi hass[22179]: File "/usr/local/lib/python3.6/asyncio/tasks.py", line 182, in _step
Oct 10 06:34:40 ha-pi hass[22179]: result = coro.throw(exc)
Oct 10 06:34:40 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/homeassistant/core.py", line 1025, in _event_to_service_call
Oct 10 06:34:40 ha-pi hass[22179]: yield from service_handler.func(service_call)
Oct 10 06:34:40 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/homeassistant/components/media_player/__init__.py", line 408, in async_service_handler
Oct 10 06:34:40 ha-pi hass[22179]: yield from getattr(player, method['method'])(**params)
Oct 10 06:34:40 ha-pi hass[22179]: File "/usr/local/lib/python3.6/asyncio/futures.py", line 332, in __iter__
Oct 10 06:34:40 ha-pi hass[22179]: yield self  # This tells Task to wait for completion.
Oct 10 06:34:40 ha-pi hass[22179]: File "/usr/local/lib/python3.6/asyncio/tasks.py", line 250, in _wakeup
Oct 10 06:34:40 ha-pi hass[22179]: future.result()
Oct 10 06:34:40 ha-pi hass[22179]: File "/usr/local/lib/python3.6/asyncio/futures.py", line 245, in result
Oct 10 06:34:40 ha-pi hass[22179]: raise self._exception
Oct 10 06:34:40 ha-pi hass[22179]: File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
Oct 10 06:34:40 ha-pi hass[22179]: result = self.fn(*self.args, **self.kwargs)
Oct 10 06:34:40 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/homeassistant/components/media_player/cast.py", line 287, in set_volume_level
Oct 10 06:34:40 ha-pi hass[22179]: self.cast.set_volume(volume)
Oct 10 06:34:40 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 855, in set_volume
Oct 10 06:34:40 ha-pi hass[22179]: 'volume': {'level': volume}})
Oct 10 06:34:40 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/controllers/__init__.py", line 84, in send_message
Oct 10 06:34:40 ha-pi hass[22179]: self.namespace, data, inc_session_id, callback_function)
Oct 10 06:34:40 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 603, in send_platform_message
Oct 10 06:34:40 ha-pi hass[22179]: inc_session_id, callback_function_param)
Oct 10 06:34:40 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 597, in send_message
Oct 10 06:34:40 ha-pi hass[22179]: raise NotConnected("Chromecast is connecting...")
Oct 10 06:34:40 ha-pi hass[22179]: pychromecast.error.NotConnected: Chromecast is connecting...#033[0m
Oct 10 06:34:51 ha-pi hass[22179]: #033[31m2017-10-10 06:34:51 ERROR (Thread-9) [pychromecast.socket_client] Failed to connect, retrying in 5.0s#033[0m
Oct 10 06:34:52 ha-pi hass[22179]: #033[31m2017-10-10 06:34:52 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved#033[0m
Oct 10 06:34:52 ha-pi hass[22179]: Traceback (most recent call last):
Oct 10 06:34:52 ha-pi hass[22179]: File "/usr/local/lib/python3.6/asyncio/tasks.py", line 182, in _step
Oct 10 06:34:52 ha-pi hass[22179]: result = coro.throw(exc)
Oct 10 06:34:52 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/homeassistant/core.py", line 1025, in _event_to_service_call
Oct 10 06:34:52 ha-pi hass[22179]: yield from service_handler.func(service_call)
Oct 10 06:34:52 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/homeassistant/components/media_player/__init__.py", line 408, in async_service_handler
Oct 10 06:34:52 ha-pi hass[22179]: yield from getattr(player, method['method'])(**params)
Oct 10 06:34:52 ha-pi hass[22179]: File "/usr/local/lib/python3.6/asyncio/futures.py", line 332, in __iter__
Oct 10 06:34:52 ha-pi hass[22179]: yield self  # This tells Task to wait for completion.
Oct 10 06:34:52 ha-pi hass[22179]: File "/usr/local/lib/python3.6/asyncio/tasks.py", line 250, in _wakeup
Oct 10 06:34:52 ha-pi hass[22179]: future.result()
Oct 10 06:34:52 ha-pi hass[22179]: File "/usr/local/lib/python3.6/asyncio/futures.py", line 245, in result
Oct 10 06:34:52 ha-pi hass[22179]: raise self._exception
Oct 10 06:34:52 ha-pi hass[22179]: File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
Oct 10 06:34:52 ha-pi hass[22179]: result = self.fn(*self.args, **self.kwargs)
Oct 10 06:34:52 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/homeassistant/components/media_player/cast.py", line 315, in play_media
Oct 10 06:34:52 ha-pi hass[22179]: self.cast.media_controller.play_media(media_id, media_type)
Oct 10 06:34:52 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/controllers/media.py", line 466, in play_media
Oct 10 06:34:52 ha-pi hass[22179]: callback_function=app_launched_callback)
Oct 10 06:34:52 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 806, in launch_app
Oct 10 06:34:52 ha-pi hass[22179]: self.update_status(lambda response:
Oct 10 06:34:52 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 797, in update_status
Oct 10 06:34:52 ha-pi hass[22179]: callback_function=callback_function_param)
Oct 10 06:34:52 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/controllers/__init__.py", line 84, in send_message
Oct 10 06:34:52 ha-pi hass[22179]: self.namespace, data, inc_session_id, callback_function)
Oct 10 06:34:52 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 603, in send_platform_message
Oct 10 06:34:52 ha-pi hass[22179]: inc_session_id, callback_function_param)
Oct 10 06:34:52 ha-pi hass[22179]: File "/srv/homeassistant/homeassistant_venv/lib/python3.6/site-packages/pychromecast/socket_client.py", line 597, in send_message
Oct 10 06:34:52 ha-pi hass[22179]: raise NotConnected("Chromecast is connecting...")
Oct 10 06:34:52 ha-pi hass[22179]: pychromecast.error.NotConnected: Chromecast is connecting...#033[0m```
1 Like
18

Thanks @edif30

Might be a stupid question, but would pinging the Chromecast at regular intervals stop it from going into sleep mode?
That could be a work around for the time being…

19

Not sure, however I also found another caveat. So not only does each cast device need internet access but check out the below.

I was using groups that I created in my Google Assistant app that would show up in HA as a media player. Default cast component would find all devices and virtual groups configured under the Google Assistant app.

Turns out those virtual groups change their IP among other identity properties as discovered with netdisco (re: balloob/pychromecast#167). This in turn would cause HA to lose connection with these cast devices (groups). A subsequent restart of HA would re-discover the groups on the new IP/identifiers and all was well. Seems the group would change these identifiers based on which device was the leader of the group. But I saw some inconsistency in this as well.

Once I removed the groups and statically configured the cast devices as hosts under the platform config, I then created a HA group such as group.google_home and I can cast to this group within HA. The audio sync is close enough compared to the group that was under my Google Assistant app. Thus I no longer get this error.

If this pull request (balloob/pychromecast#167) get’s implemented then I may try the Google Assistant groups again. But I figured to post this for anyone else in the same scenario.

1 Like
20

Thanks @edif30

I’ll try that and monitor the logs…
I’d still like it fixed if @balloob has time. There is a small delay in the devices being synced compared to ChromeCast groups, plus when I want to stop it I now have to switch each device off instead of switching the group off.