Timeout when waiting for status response from Spotify app

[Marcos-kp]

Describe the bug A clear and concise description of what the bug is.

• [x] Using latest version of spotcast
• [x] I have setup the Spotify integration in Home Assistant
• [ ] I am using multiple accounts
• [x] Using latest stable version of Home Assistant
• [x] I have Spotify Premium
• [x] I'm attaching relevant logs with level debug for component spotcast (see README)
• [x] I'm using entity_id in the service call and have tried device_name but the issue remains

Describe the bug When calling the spotcast.start service and playing in my Google Nest Mini, I hear a chime but nothing happens. Got this log:

This error originated from a custom integration.

Logger: homeassistant.core Source: custom_components/spotcast/spotify_controller.py:102 Integration: Spotcast (documentation, issues)

Error executing service: <ServiceCall spotcast.start (c:xxx): uri=spotify:playlist:xxx, random_song=True, shuffle=True, entity_id=media_player.xxx, repeat=off, force_playback=False, offset=0, start_volume=101, ignore_fully_played=False> Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/core.py", line 1507, in catch_exceptions await coro_or_task File "/usr/src/homeassistant/homeassistant/core.py", line 1530, in _execute_service await self._hass.async_add_executor_job(handler.job.target, service_call) File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 52, in run result = self.fn(*self.args, **self.kwargs) File "/config/custom_components/spotcast/init.py", line 147, in start_casting spotify_device_id = spotcast_controller.get_spotify_device_id( File "/config/custom_components/spotcast/spotcast_controller.py", line 202, in get_spotify_device_id spotify_cast_device.startSpotifyController(access_token, expires) File "/config/custom_components/spotcast/spotcast_controller.py", line 84, in startSpotifyController sp.launch_app() File "/config/custom_components/spotcast/spotify_controller.py", line 102, in launch_app raise LaunchError( pychromecast.error.LaunchError:

This made my Google Nest Mini to change its status to Unknown until the same automation called the same service with a different playlist and it started playing. This looks intermittent and I couldn't find a trigger to replicate the behaviour.

Environment (please complete the following information):

• HA version: [core-2021.8.8 - supervisor-2021.06.8]
• spotcast version: [3.6.16]

Configuration Add your configuration

Additional context Add any other context about the problem here.

[fcusson]

I've had the same issue will working on a PR. The issue seems to have been limited to monday-tuesday. I've been doing extensive testing for #251 and haven't replicated the issue yet since yesterday.

[kylepotts]

Its possible Spotify changes their auth mechanism or it might be different for different devices.

If you can try following these docs https://github.com/home-assistant-libs/pychromecast#exploring-existing-namespaces and seeing if it follows the same auth mechanism we have coded for that would be helpful. I would ask that you share that network dump but it could contain sensitive info so thats not a great idea,

[JamieEC]

I am also facing this issue. Any workarounds?

[cjborchert]

Hey there, just started having this issue in the last 24 hours after using Spotcast flawlessly for a month or so. Anything else I can try or information I can provice that could be useful?

I can't come up with a theory on what caused the issue to surface, as I did not directly make any changes to Spotcast, the Spotify integration, my Spotify accounts or anything to do with my Google devices, Google Home app settings, etc. I used Spotcast successfully last night to start a lullaby playlist in my son's room. An hour later I rebooted Home Assistant a few times in an attempt to get some disconnected ZigBee devices back onto the network, and then ran into this issue when I tried to restart the automation running the lullaby playlist. Without success, I've removed and reinstalled Spotcast, the Spotify integration, as well as recreating the Spotify app with new oauth credentials, regenerating fresh sp_dc & sp_key cookies, and relinking Home Assistant with Google Home.

When I call spotcast.start from Home Assistant, my Google cast devices make a single chime and then nothing happens. This happens consistently on a Google Home (old speaker-only unit) and a Google Nest with display since last night.

I am using the latest versions: Home Assistant: 2022.11.4 Spotcast: v3.6.30

Here is the logging I have showing the same pychromecast timeout error as above. I have multiple accounts enabled in the config for Spotast, and the issue occurs in the same way whether I directly specify either account or leave it on default.

This error originated from a custom integration.

Logger: homeassistant.core Source: custom_components/spotcast/spotify_controller.py:104 Integration: Spotcast (documentation, issues) First occurred: 3:12:24 PM (1 occurrences) Last logged: 3:12:24 PM

Error executing service: <ServiceCall spotcast.start (c:xxx): entity_id=media_player.xxx, account=xxx, shuffle=True, start_volume=25, random_song=True, uri=spotify:playlist:xxx, repeat=off, offset=0, ignore_fully_played=False, limit=20, force_playback=False> Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/core.py", line 1762, in catch_exceptions await coro_or_task File "/usr/src/homeassistant/homeassistant/core.py", line 1787, in _execute_service await self._hass.async_add_executor_job( File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run result = self.fn(*self.args, **self.kwargs) File "/config/custom_components/spotcast/init.py", line 190, in start_casting spotify_device_id = spotcast_controller.get_spotify_device_id( File "/config/custom_components/spotcast/spotcast_controller.py", line 240, in get_spotify_device_id spotify_cast_device.startSpotifyController(access_token, expires) File "/config/custom_components/spotcast/spotcast_controller.py", line 95, in startSpotifyController sp.launch_app() File "/config/custom_components/spotcast/spotify_controller.py", line 104, in launch_app raise LaunchError( pychromecast.error.LaunchError: Timeout when waiting for status response from Spotify app

Cheers!

[selfisch]

Hey there, same here since today. Worked fine for several weeks. Already created new token for all accounts. Really anoying, but my guess is, that spotcast is not the root cause.

[CubicrootXYZ]

Same for me since yesterday. Seems like it is a Spotify issue if multiple person's encounter this?

[maelhouck]

Echoing the issue since yesterday. Tried reinstalling Spotcast, changing credentials, restarting HA, reloading the Spotify integration. Nothing is currently working to cast audio to the speakers.

[TheMrDec]

Well, at least I am not just an idiot. I reinstalled spotcast, reset keys, made a new api for testing, and even went so far as to adjust firewall rules but no dice. I get a timeout error every time. I suspect the auth codeflow might have been altered again.

[cjborchert]

The following worked for me. What a great integration and community! #365

[wautersj]

I'm experiencing this behaviour again. A lot like the comments above.

It might have to do with Spotify changing their auth/handshake flow?

[MerekW]

I'm experiencing this behaviour again. A lot like the comments above.

It might have to do with Spotify changing their auth/handshake flow?

I am experiencing this today - anyone have thoughts on cause/fix?

[olqmin]

How lucky I am. I just got tuned the setup for the first time and getting the same error, from what I'm reading, it seems to be something due to a change from spotify's end

[Electronlibre2012]

here is the error log:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 226, in handle_call_service
    await hass.services.async_call(
  File "/usr/src/homeassistant/homeassistant/core.py", line 1974, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2018, in _execute_service
    return await self._hass.async_add_executor_job(target, service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/spotcast/__init__.py", line 221, in start_casting
    spotify_device_id = spotcast_controller.get_spotify_device_id(
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/spotcast/spotcast_controller.py", line 250, in get_spotify_device_id
    spotify_cast_device.startSpotifyController(access_token, expires)
  File "/config/custom_components/spotcast/spotcast_controller.py", line 95, in startSpotifyController
    sp.launch_app()
  File "/config/custom_components/spotcast/spotify_controller.py", line 104, in launch_app
    raise LaunchError(
pychromecast.error.LaunchError: Timeout when waiting for status response from Spotify app

Really bad, is there any solution please?

[fcusson]

@Electronlibre2012, as stated in previous comments, you can call directly the spotify device id, but this is limited for Chromecast devices.

No need to post more logs that gives the same information, I'm currently on vacation so I don't quite have the time to explore an alternative to fetch the device Id so if people can help that would be useful

[TheMrDec]

I can poke at it a bit but as per usual, devs made changes during the time of year when I have the highest work load. I will try to take a look at this this weekend.

[idogrf]

having the same issue @fcusson calling the spotify device id directly did not work for me either (trying to cast to a google nest mini 2) I'm getting a 404 Device not found error

btw, trying to follow the instructions in the readme file to get the device ID leads to a different page than the one intended - might be a part of the change spotify implemented - Spotify developer console

[GSzabados]

If there isn't an actively playing device or an open session to Spotify, then https://api.spotify.com/v1/me/player/devices returns an empty list, which should contain all the available devices to start playing on. Actually that is expected, and the issue was traced back originally to pychromecast. https://github.com/home-assistant-libs/pychromecast/issues/520

{
  "devices": []
}

[GSzabados]

The response from the Spotify app on the cast device does not contain the deviceID what Spotcast utilising to get the accesstoken from the desktop player API, so Spotcast is unable to take control of the Spotify cast, so pychromecast times out. It is the case when the device is idle. If the device is already playing something, then the response from the Spotify app contains the deviceID and there isn't any error.

My guess it is an upstream change in how the Spotify app behaves on the cast device, as it used to provide the deviceID, but not anymore.

As it is beyond my understanding, I am not sure, why the deviceID is not provided anymore. Is it pychromecast or Spotcast initiating the Spotify app incorrectly, or what is causing it? But what is sure, that the Spotify app starts on the cast device, as it sends an info response, but why isn't any deviceID assigned is a good question.

[CubicrootXYZ]

The following worked for me. What a great integration and community! #365

From what I was able to research from that link some users back then were successful by setting the spotify device ID in the data field of the spotcast call. Unfortunately I was not able to get that to work with my setup.

[TheMrDec]

I have played with this a little bit between Crota's End raid attempts. Hard cod8ng the DeviceID has not worked from what I can tell.

I am going to try to grab the traffic that is sent when Spotify themselves opens a session on the cast device. Maybe we can use the same call somehow is pychromecast of r spotcast

[TheMrDec]

Looks like the connection starts out with an unsolicited MDNS query response over UDP. This is followed up by a query from my Google Home Mini to 8.8.8.8 for apresolve.spotify.com. The query response returns an A record which the Mini then begins a crypt handshake to. I am going to try manually sending a few MDNS packets to my Mini and see if I can recreate this behavior.

Nope. I'm blind.

[TheMrDec]

I am not sure what to make of this. It seems that the Google Home Mini is sending out periodic MDNS packets which contain the device ID for google cast. The issue is, the PTR records in these packets are .local so I dont believe they can be what the spotify system is using to init a session on the device. Sanitized packet for anyone else to look at attached. Maybe I dont fully understand how MDNS works yet. sample packet data.txt

[matwojcik]

Hint with device_id works for me only when the device is already active. When it stops being active, then it disappears from https://api.spotify.com/v1/me/player/devices and when I try to start playing, it returns 404 :/

[barzag]

L'indice ne device_idfonctionne pour moi que lorsque l'appareil est déjà actif. Lorsqu'il cesse d'être actif, il disparaît https://api.spotify.com/v1/me/player/deviceset lorsque j'essaie de commencer à jouer, il renvoie 404 :/

same for me

[TheMrDec]

I am still gathering more data but the biggest issue: I think the the traffic that reaches out to spotify's servers is encrypted with a key I dont have access to. I have tried snooping multiple spotify clients while switching the output to the google home speaker and all of them start with encrypted application data. I will need to reread the docs for spot dev to see if they mentioned a change.

[GSzabados]

@TheMrDec, this issue has been resolved and everything is working again with the latest release of Spotcast, if you haven't updated yet!

[TheMrDec]

Well, grand. That is great news for everyone else. Mine on the other hand is still not functional. I will investigate and probably open a new issue since it is unrelated. Might have to do with my firewall being a royal pain though so who knows.

[GSzabados]

Mine on the other hand is still not functional.

Look at this issue, and the solution in the end. https://github.com/fondberg/spotcast/issues/398

Otherwise, have you updated the custom component to version 3.7.1?

https://github.com/fondberg/spotcast/releases/tag/v3.7.1

And have you restarted since your Home Assistant?

[TheMrDec]

Look at this issue, and the solution in the end. #398

Yeah, I saw that. Evidently I missed something in the documentation.

Otherwise, have you updated the custom component to version 3.7.1?

Yes.

And have you restarted since your Home Assistant?

Yes.

Like I said, this warrants further investigation from a different perspective. I was taking an overly technical approach to diag under the pretext that it wasnt working for anyone. Now that I am aware my issue is unique, I need to start over from the simpler steps.

[iZac85]

I've had the same issue for a couple of weeks now, but updating Spotcast from v3.7.0 to v3.7.1 hopefully solved the issue (at least it worked again just now)! :)

[Henk72]

I had the same issue today with version v3.7.1. One day it works, the next day it doesn't. It's quite frustrating.

[NeilS1966]

I updated to v3.7.1, but the problem remains.

[TheMrDec]

I had the same issue today with version v3.7.1. One day it works, the next day it doesn't. It's quite frustrating.

I have noticed that roughly every third day, my task errors out looking for the cast device at the wrong IP address. I have set my dnsmasq server to hold a reservation for my google home mini in hopes that this fixes the error.

[hmmbob]

Frustratingly, I am seeing this error over and over again. The funny thing is - playing starts just completely fine for about 1 sec, and then it stops (probably due to this check/error):

2023-10-04 10:58:29.236 ERROR (MainThread) [homeassistant.components.script.start_music_t] Slaaptijd: Error executing script. Unexpected error for call_service at pos 2: Timeout when waiting for status response from Spotify app
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 468, in _async_step
await getattr(self, handler)()
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 704, in _async_call_service_step
response_data = await self._async_run_long_action(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 666, in _async_run_long_action
return long_task.result()
^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/core.py", line 2012, in async_call
response_data = await coro
^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/core.py", line 2056, in _execute_service
return await self._hass.async_add_executor_job(target, service_call)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/concurrent/futures/thread.py", line 58, in run
result = self.fn(*self.args, **self.kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/config/custom_components/spotcast/__init__.py", line 221, in start_casting
spotify_device_id = spotcast_controller.get_spotify_device_id(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/config/custom_components/spotcast/spotcast_controller.py", line 301, in get_spotify_device_id
spotify_cast_device.start_spotify_controller(access_token, expires)
File "/config/custom_components/spotcast/spotcast_controller.py", line 104, in start_spotify_controller
sp.launch_app()
File "/config/custom_components/spotcast/spotify_controller.py", line 110, in launch_app
raise LaunchError(
pychromecast.error.LaunchError: Timeout when waiting for status response from Spotify app
2023-10-04 10:58:29.251 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140663668132032] Timeout when waiting for status response from Spotify app
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 226, in handle_call_service
await hass.services.async_call(
File "/usr/src/homeassistant/homeassistant/core.py", line 2012, in async_call
response_data = await coro
^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/core.py", line 2049, in _execute_service
return await target(service_call)
^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/components/script/__init__.py", line 605, in _service_handler
response = await self._async_start_run(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/components/script/__init__.py", line 563, in _async_start_run
script_result = await coro
^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/components/script/__init__.py", line 594, in _async_run
return await self.script.async_run(script_vars, context)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 1578, in async_run
return await asyncio.shield(run.async_run())
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 420, in async_run
await self._async_step(log_exceptions=False)
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 470, in _async_step
self._handle_exception(
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 493, in _handle_exception
raise exception
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 468, in _async_step
await getattr(self, handler)()
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 704, in _async_call_service_step
response_data = await self._async_run_long_action(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/script.py", line 666, in _async_run_long_action
return long_task.result()
^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/core.py", line 2012, in async_call
response_data = await coro
^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/core.py", line 2056, in _execute_service
return await self._hass.async_add_executor_job(target, service_call)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/concurrent/futures/thread.py", line 58, in run
result = self.fn(*self.args, **self.kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/config/custom_components/spotcast/__init__.py", line 221, in start_casting
spotify_device_id = spotcast_controller.get_spotify_device_id(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/config/custom_components/spotcast/spotcast_controller.py", line 301, in get_spotify_device_id
spotify_cast_device.start_spotify_controller(access_token, expires)
File "/config/custom_components/spotcast/spotcast_controller.py", line 104, in start_spotify_controller
sp.launch_app()
File "/config/custom_components/spotcast/spotify_controller.py", line 110, in launch_app
raise LaunchError(
pychromecast.error.LaunchError: Timeout when waiting for status response from Spotify app

[Henk72]

Today it failed again

File "/usr/local/lib/python3.11/site-packages/spotipy/client.py", line 307, in _internal_call raise SpotifyException( spotipy.exceptions.SpotifyException: http status: 429, code:-1 - /v1/me/player: Max Retries, reason: too many 502 error responses

I got feedback that this 502 error is not related and potentially an API call failure (my error in some spotcast settings)

[theyo-tester]

I have the same error. I'm using a Wiim Pro, integrated as a chromecast device.

The error arises only if I use the home assistant entity id, or the friendly name defined in hass. If I use the spotify device id (or the spotify friendly name), it works. So it seems that spotify doesn't want to stream the music directly to the device, and this is maybe because spotcast doesn't find the spotify device id and then it raises a timeout error (because spotify doesn't respond for whatever reason)

I may also add, that before the device was not added to the spotify list (so I had to stream first from the spotify app to the device) playing spotify was not possible at all. But this is maybe the expected behavior and I just didn't know this requirement.

[pratahsinnetamby]

I'm having the same issue. It's been working years and stopped working recently (not sure of the exact date).

Tried re-installing integration but still no luck.

UPDATE: Upgrade spotcast integration (HACS) and it started working again!

[Anon666333]

Is there any update on where we stand with this issue?

[TheMrDec]

I started seeing the error again. I advanced my task trigger by 5 minutes and suddenly everything works perfectly fine. Moved it back to 0630 and it starts erroring out again. I do have one other task being called at 0630 but it's a zigbee call that shouldn't be taking anywhere near enough time to cause API calls to time out like this.

[GSzabados]

You can increase the debug level of the component to see more messages in the log.

But otherwise, it is a generic error. It means that it has not received an answer (expected answer) from the device on time. There should be an underlying cause, what does it receive then... So, there should be another error which would tell a bit more.

[coserotondo]

I'm using spotcast on my Sony Bravia Google TV and I've several time timeout issue.

I changed increased the timeout value in spotify_controller.py row 78 from def launch_app(self, timeout=10): to def launch_app(self, timeout=30): Increasing the timeout form 10 to 30 seconds.

It seems to be working fine now.

Maybe the code could be changed to make the timeout a user configurable parameter.

[Ziperro]

I changed increased the timeout value in spotify_controller.py row 78 from def launch_app(self, timeout=10): to def launch_app(self, timeout=30): Increasing the timeout form 10 to 30 seconds.

After two weeks of testing it happened again. But it looks it helps.

[bruvv]

I added a PR for this to have it be configurable in the UI: https://github.com/fondberg/spotcast/pull/424