starred/spotify-player

Fork 0

mirror of https://github.com/aome510/spotify-player.git synced 2026-04-26 17:35:50 +03:00

[GH-ISSUE #710] playback stops intermittently #419

New issue

Open

opened 2026-03-02 23:47:22 +03:00 by kerem · 4 comments

kerem commented

2026-03-02 23:47:22 +03:00

Owner

Originally created by @earhax on GitHub (May 3, 2025).
Original GitHub issue: https://github.com/aome510/spotify-player/issues/710

Describe the bug
intermittently, playback just stops in the middle of a song, even with the Spotify app open in addition to Spotify-player CLI.

To Reproduce
use Spotify-player, play music in a playlist. after a few songs, playback randomly just stops dead. Happens to me all the time. but maybe i'm just lucky like that!

Expected behaviour
playing songs shouldn't just stop for no reason. playback should continue until stopped by the user.

Log and backtrace
Log and backtrace of a run reproducing the bug to help debug the issue, which are usually located in $HOME/.cache/spotify-player/.
i'm on my phone right now and don't have access to the log, but if this keeps up, I'll add the log later. also, i think $home only works on Mac. on PC it's probably %userprofile% and \ instead of / for the separator. might be worth noting in bug report steps/info.

Environment

OS: windows 10 pro
Application version: current/latest as of this report

Originally created by @earhax on GitHub (May 3, 2025). Original GitHub issue: https://github.com/aome510/spotify-player/issues/710 **Describe the bug** intermittently, playback just stops in the middle of a song, even with the Spotify app open in addition to Spotify-player CLI. **To Reproduce** use Spotify-player, play music in a playlist. after a few songs, playback randomly just stops dead. Happens to me all the time. but maybe i'm just lucky like that! **Expected behaviour** playing songs shouldn't just stop for no reason. playback should continue until stopped by the user. **Log and backtrace** Log and backtrace of a run reproducing the bug to help debug the issue, which are usually located in `$HOME/.cache/spotify-player/`. i'm on my phone right now and don't have access to the log, but if this keeps up, I'll add the log later. also, i think $home only works on Mac. on PC it's probably %userprofile% and \ instead of / for the separator. might be worth noting in bug report steps/info. **Environment** - OS: windows 10 pro - Application version: current/latest as of this report

kerem added the

bug

label

2026-03-02 23:47:22 +03:00

kerem commented

2026-03-02 23:47:23 +03:00

Author

Owner

@stevenwalton commented on GitHub (May 9, 2025):

This has been happening to me a lot lately. I was follow the log waiting for it to crash. Here's the tail.
_{^{Note that this has a max lifetime of a week and I redacted a few things like the access_token}}

Comments

It appears what is happening is that the server connection gets closed and after re-establishing the audio doesn't continue.
Sometimes I can continue by pressing play, but this doesn't always seem to be the case.
The log will say that it got a Paused pay event.
But most times when I press play the progress bar resumes but there is no audio (@earhax do you see this behavior?).
Because of this, I think the issue isn't just due to resolving the connection.
I think there's something a bit more complicated and may involve the connection to the audio device.

I notice some weird behavior in the logs when it is re-establishing connections.

# This log has the crash
$ cat ~/.cache/spotify-player/spotify-player-25-05-08-14-38.log \
    | grep "expires_in" \
    | sed -e 's/\([^Z]*\)[^,]*, [^}]*}, \([^,]*\).*/\1Z \2/g'
2025-05-08T21:38:31.306186Z expires_at: Some(2025-05-08T22:38:31.306172Z)
2025-05-08T22:41:43.967958Z expires_at: Some(2025-05-08T23:41:43.967954Z)
2025-05-08T23:42:04.108905Z expires_at: Some(2025-05-09T00:42:04.108904Z)
2025-05-09T00:25:38.313487Z expires_at: Some(2025-05-09T01:25:38.313481Z)

# My active log
$ cat ~/.cache/spotify-player/spotify-player-25-05-08-17-43.log \
    | grep "expires_in" \
    | sed -e 's/\([^Z]*\)[^,]*, [^}]*}, \([^,]*\).*/\1Z \2/g'
2025-05-09T00:43:11.589670Z expires_at: Some(2025-05-09T01:43:11.589659Z)
2025-05-09T00:58:10.884204Z expires_at: Some(2025-05-09T01:58:10.884194Z)

_{^{I think you should probably redact the access tokens from the log}}
Is something going on with the request token logic? All of these make requests for expires_in: TimeDelta { secs: 3600, nanos: 0 }.
I think the crash happened before the last token request, so it might be that that log was late to requesting tokens? It could be that the new session is playing because the tokens are refreshed earlier, which is happening because there's some errors like librespot_core::session: Connection to server closed and Socket is not connected prior to the retokenization?

I have also noticed that sometimes there is a problem when outputting audio with my airpods.
I'm not exactly sure the sequence that leads to the event but it can happen if I take my headphones out of my ears.
This doesn't pause spotify_player but I believe Apple sends an event and this seems to sometimes be interpreted by Apple Music (something I do not use and do not want...).
When that happens I cannot select the correct audio device and I have to shutdown spotify_player, return my headphones to their case, pull them back out, and then start spotify_player.

Parse log for `ERROR` and `WARN`

2025-05-09T00:25:07.453939Z ERROR librespot_core::session: Connection to server closed.
2025-05-09T00:25:07.454108Z ERROR librespot_connect::spirc: remote update selected, but none received
2025-05-09T00:25:08.909227Z ERROR librespot_core::audio_key: Audio key response timeout
2025-05-09T00:25:08.909383Z  WARN librespot_playback::player: Unable to load key, continuing without decryption: Operation aborted { audio key response timeout }
2025-05-09T00:25:08.936643Z  WARN librespot_playback::player: Unable to read cached audio file: Symphonia Decoder Error: end of stream. Trying to download it.
2025-05-09T00:25:09.267824Z ERROR librespot_core::session: Broken pipe (os error 32)
2025-05-09T00:25:10.768869Z ERROR librespot_core::audio_key: Audio key response timeout
2025-05-09T00:25:10.768994Z  WARN librespot_playback::player: Unable to load key, continuing without decryption: Operation aborted { audio key response timeout }
2025-05-09T00:25:15.031163Z ERROR librespot_playback::player: Unable to read audio file: Symphonia Decoder Error: end of stream
2025-05-09T00:25:38.154489Z ERROR spotify_player::client: Failed to shutdown old streaming connection: Internal error { channel closed }
2025-05-09T00:25:39.874060Z ERROR librespot_connect::spirc: ContextError: Error { kind: NotFound, error: StatusCode(404) }

(There only other error/warn messages in my log are a few more instances as the last line shown above)

System

OSX Sequoia 15.4.1
spotify_player 0.20.4

@stevenwalton commented on GitHub (May 9, 2025): This has been happening to me a lot lately. I was follow the log waiting for it to crash. [Here's the tail](https://0x0.st/8JU-.log). Note that this has a max lifetime of a week and I redacted a few things like the `access_token` ### Comments It appears what is happening is that the server connection gets closed and after re-establishing the audio doesn't continue. ***Sometimes*** I can continue by pressing play, but this doesn't always seem to be the case. The log will say that it got a Paused pay event. But most times when I press play the progress bar resumes but there is no audio (@earhax do you see this behavior?). Because of this, I think the issue isn't just due to resolving the connection. I think there's something a bit more complicated and may involve the connection to the audio device. I notice some weird behavior in the logs when it is re-establishing connections. ```python # This log has the crash $ cat ~/.cache/spotify-player/spotify-player-25-05-08-14-38.log \ | grep "expires_in" \ | sed -e 's/$[^Z]*$[^,]*, [^}]*}, $[^,]*$.*/\1Z \2/g' 2025-05-08T21:38:31.306186Z expires_at: Some(2025-05-08T22:38:31.306172Z) 2025-05-08T22:41:43.967958Z expires_at: Some(2025-05-08T23:41:43.967954Z) 2025-05-08T23:42:04.108905Z expires_at: Some(2025-05-09T00:42:04.108904Z) 2025-05-09T00:25:38.313487Z expires_at: Some(2025-05-09T01:25:38.313481Z) # My active log $ cat ~/.cache/spotify-player/spotify-player-25-05-08-17-43.log \ | grep "expires_in" \ | sed -e 's/$[^Z]*$[^,]*, [^}]*}, $[^,]*$.*/\1Z \2/g' 2025-05-09T00:43:11.589670Z expires_at: Some(2025-05-09T01:43:11.589659Z) 2025-05-09T00:58:10.884204Z expires_at: Some(2025-05-09T01:58:10.884194Z) ``` I think you should probably redact the access tokens from the log Is something going on with the request token logic? All of these make requests for `expires_in: TimeDelta { secs: 3600, nanos: 0 }`. I think the crash happened before the last token request, so it might be that that log was late to requesting tokens? It could be that the new session is playing because the tokens are refreshed earlier, which is happening because there's some errors like `librespot_core::session: Connection to server closed` and `Socket is not connected` prior to the retokenization? #### Extra maybe related I have also noticed that sometimes there is a problem when outputting audio with my airpods. I'm not exactly sure the sequence that leads to the event but it can happen if I take my headphones out of my ears. This doesn't pause `spotify_player` but I believe Apple sends an event and this seems to sometimes be interpreted by Apple Music (something I do not use and do not want...). When that happens I cannot select the correct audio device and I have to shutdown `spotify_player`, return my headphones to their case, pull them back out, and then start `spotify_player`. ### Parse log for `ERROR` and `WARN` ```ruby 2025-05-09T00:25:07.453939Z ERROR librespot_core::session: Connection to server closed. 2025-05-09T00:25:07.454108Z ERROR librespot_connect::spirc: remote update selected, but none received 2025-05-09T00:25:08.909227Z ERROR librespot_core::audio_key: Audio key response timeout 2025-05-09T00:25:08.909383Z WARN librespot_playback::player: Unable to load key, continuing without decryption: Operation aborted { audio key response timeout } 2025-05-09T00:25:08.936643Z WARN librespot_playback::player: Unable to read cached audio file: Symphonia Decoder Error: end of stream. Trying to download it. 2025-05-09T00:25:09.267824Z ERROR librespot_core::session: Broken pipe (os error 32) 2025-05-09T00:25:10.768869Z ERROR librespot_core::audio_key: Audio key response timeout 2025-05-09T00:25:10.768994Z WARN librespot_playback::player: Unable to load key, continuing without decryption: Operation aborted { audio key response timeout } 2025-05-09T00:25:15.031163Z ERROR librespot_playback::player: Unable to read audio file: Symphonia Decoder Error: end of stream 2025-05-09T00:25:38.154489Z ERROR spotify_player::client: Failed to shutdown old streaming connection: Internal error { channel closed } 2025-05-09T00:25:39.874060Z ERROR librespot_connect::spirc: ContextError: Error { kind: NotFound, error: StatusCode(404) } ``` (There only other error/warn messages in my log are a few more instances as the last line shown above) ### System - OSX Sequoia 15.4.1 - `spotify_player 0.20.4`

kerem commented

2026-03-02 23:47:23 +03:00

Author

Owner

@aome510 commented on GitHub (May 10, 2025):

Thanks @stevenwalton for the detailed explanation of what might happen. I can confirm I also occasionally encounter the same thing on my end when using the app at work. Often, I will restart the app or the integrated client with RestartIntegratedClient.

That said, recently I couldn't find time to do deep dive into this problem or any related problems reported in https://github.com/aome510/spotify-player/issues. This kind of problem tends to be time-consuming to investigate cause it's less of spotify_player issue but more of how third-party library like librespot handles Spotify APIs.

@aome510 commented on GitHub (May 10, 2025): Thanks @stevenwalton for the detailed explanation of what might happen. I can confirm I also occasionally encounter the same thing on my end when using the app at work. Often, I will restart the app or the integrated client with `RestartIntegratedClient`. That said, recently I couldn't find time to do deep dive into this problem or any related problems reported in https://github.com/aome510/spotify-player/issues. This kind of problem tends to be time-consuming to investigate cause it's less of `spotify_player` issue but more of how third-party library like `librespot` handles Spotify APIs.

kerem commented

2026-03-02 23:47:23 +03:00

Author

Owner

@aome510 commented on GitHub (May 10, 2025):

@aome510 commented on GitHub (May 10, 2025): Maybe related to https://github.com/librespot-org/librespot/issues/1492

kerem commented

2026-03-02 23:47:23 +03:00

Author

Owner

@georgev93 commented on GitHub (Oct 4, 2025):

In case this adds any context, I'm also having the same issue (except it stops after roughly every other song). I use a VPN with a ~350ms ping, so I've found weird issues in other software because of that. Perhaps it's related?

Logs:

2025-10-04T04:30:21.482729Z  WARN librespot_core::session: Connection to server closed.
2025-10-04T04:31:06.790250Z  WARN librespot_connect::spirc: unexpected shutdown 
2025-10-04T04:31:08.392209Z  INFO librespot_playback::player: Loading <put it in the boogie - Version 2> with Spotify URI <spotify:track:2k20fXoOuYwO0dd29WsX6i>
2025-10-04T04:31:09.210552Z  WARN librespot_connect::state::context: couldn't load context info because: context is not available. type: Default
2025-10-04T04:31:11.054516Z ERROR librespot_core::session: Broken pipe (os error 32)
2025-10-04T04:31:12.555787Z ERROR librespot_core::audio_key: Audio key response timeout
2025-10-04T04:31:12.555841Z  WARN librespot_playback::player: Unable to load key, continuing without decryption: Operation aborted { audio key response timeout }

EDIT: It's 350ms, but it's a stable 350ms. No, you never get used to it.

@georgev93 commented on GitHub (Oct 4, 2025): In case this adds any context, I'm also having the same issue (except it stops after roughly every other song). I use a VPN with a ~350ms ping, so I've found weird issues in other software because of that. Perhaps it's related? Logs: ``` 2025-10-04T04:30:21.482729Z WARN librespot_core::session: Connection to server closed. 2025-10-04T04:31:06.790250Z WARN librespot_connect::spirc: unexpected shutdown 2025-10-04T04:31:08.392209Z INFO librespot_playback::player: Loading <put it in the boogie - Version 2> with Spotify URI <spotify:track:2k20fXoOuYwO0dd29WsX6i> 2025-10-04T04:31:09.210552Z WARN librespot_connect::state::context: couldn't load context info because: context is not available. type: Default 2025-10-04T04:31:11.054516Z ERROR librespot_core::session: Broken pipe (os error 32) 2025-10-04T04:31:12.555787Z ERROR librespot_core::audio_key: Audio key response timeout 2025-10-04T04:31:12.555841Z WARN librespot_playback::player: Unable to load key, continuing without decryption: Operation aborted { audio key response timeout } ``` EDIT: It's 350ms, but it's a **stable** 350ms. No, you never get used to it.

kerem referenced this issue

2026-03-02 23:49:41 +03:00

[PR #419] [MERGED] Refactor ui and event modules #755

kerem referenced this issue

2026-03-14 15:28:01 +03:00

[PR #419] [MERGED] Refactor ui and event modules #1696