[GH-ISSUE #1151] Librespot playback stops - Connection reset by peer (os error 104) #533

Closed
opened 2026-02-27 19:31:09 +03:00 by kerem · 27 comments
Owner

Originally created by @dwedia on GitHub (Apr 12, 2023).
Original GitHub issue: https://github.com/librespot-org/librespot/issues/1151

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

Playback stops randomly. Sometimes after a few seconds, sometimes after a few hours
Librespot seems to crash and I have to reconnect from spotify. Sometimes I can reconnect at once, at other times a complete OS reboot is necessary

Gives these two errors in the log:
ERROR librespot_core::session] Connection reset by peer (os error 104)
WARN librespot] Spirc shut down unexpectedly

To reproduce
Steps to reproduce the behavior:

  1. Launch librespot with '...' running Librespot through Raspotify, had the same issue (though much worse), when I used Volumio. both use Librespot for the actually spotify connection.
  2. Connect with '...'
  3. In the client click on '...'
  4. See error

Log
A full log so we may trace your problem (launch librespot with --verbose). Format the log as code.

´
Apr 12 19:58:06 barry librespot[1552]: [2023-04-12T17:58:06Z ERROR librespot_core::session] Connection reset by peer (os error 104)
Apr 12 19:58:06 barry librespot[1552]: [2023-04-12T17:58:06Z ERROR librespot_connect::spirc] subscription terminated
Apr 12 19:58:06 barry librespot[1552]: [2023-04-12T17:58:06Z WARN librespot] Spirc shut down unexpectedly
Apr 12 19:58:06 barry librespot[1552]: [2023-04-12T17:58:06Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:4070
Apr 12 19:58:06 barry librespot[1552]: [2023-04-12T17:58:06Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:443
Apr 12 19:58:06 barry librespot[1552]: [2023-04-12T17:58:06Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:80
Apr 12 19:58:06 barry librespot[1552]: [2023-04-12T17:58:06Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gue1.spotify.com:4070
´

Host (what you are running librespot on):

  • OS: Linux barry 6.1.21-v8+ - Raspberry Pi OS ( PRETTY_NAME="Debian GNU/Linux 11 (bullseye)" )
  • Platform: Raspberry Pi Zero 2

Additional context
Add any other context about the problem here. If your issue is related to sound playback, at a minimum specify the type and make of your output device.

Originally created by @dwedia on GitHub (Apr 12, 2023). Original GitHub issue: https://github.com/librespot-org/librespot/issues/1151 **Describe the bug** A clear and concise description of what the bug is. Playback stops randomly. Sometimes after a few seconds, sometimes after a few hours Librespot seems to crash and I have to reconnect from spotify. Sometimes I can reconnect at once, at other times a complete OS reboot is necessary Gives these two errors in the log: ERROR librespot_core::session] Connection reset by peer (os error 104) WARN librespot] Spirc shut down unexpectedly **To reproduce** Steps to reproduce the behavior: 1. Launch `librespot` with '...' running Librespot through Raspotify, had the same issue (though much worse), when I used Volumio. both use Librespot for the actually spotify connection. 2. Connect with '...' 3. In the client click on '...' 4. See error **Log** A full log so we may trace your problem (launch `librespot` with `--verbose`). Format the log as code. ´ Apr 12 19:58:06 barry librespot[1552]: [2023-04-12T17:58:06Z ERROR librespot_core::session] Connection reset by peer (os error 104) Apr 12 19:58:06 barry librespot[1552]: [2023-04-12T17:58:06Z ERROR librespot_connect::spirc] subscription terminated Apr 12 19:58:06 barry librespot[1552]: [2023-04-12T17:58:06Z WARN librespot] Spirc shut down unexpectedly Apr 12 19:58:06 barry librespot[1552]: [2023-04-12T17:58:06Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:4070 Apr 12 19:58:06 barry librespot[1552]: [2023-04-12T17:58:06Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:443 Apr 12 19:58:06 barry librespot[1552]: [2023-04-12T17:58:06Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:80 Apr 12 19:58:06 barry librespot[1552]: [2023-04-12T17:58:06Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gue1.spotify.com:4070 ´ **Host (what you are running `librespot` on):** - OS: Linux barry 6.1.21-v8+ - Raspberry Pi OS ( PRETTY_NAME="Debian GNU/Linux 11 (bullseye)" ) - Platform: Raspberry Pi Zero 2 **Additional context** Add any other context about the problem here. If your issue is related to sound playback, at a minimum specify the type and make of your output device.
kerem 2026-02-27 19:31:09 +03:00
  • closed this issue
  • added the
    bug
    label
Author
Owner

@JasonLG1979 commented on GitHub (Apr 13, 2023):

Connection reset by peer (os error 104) means that Spotify has dropped the connection for any number of potential reasons. In a perfect world librespot would try to seamlessly reconnect without the user noticing if that's possible. Currently I think it may just restart Spirc which isn't seamless. In Raspotify if librespot crashes or exits the service restarts.

In short on librespot's side there's nothing that can be done to prevent a 104, but it could be handled a little better maybe?

<!-- gh-comment-id:1506274399 --> @JasonLG1979 commented on GitHub (Apr 13, 2023): `Connection reset by peer (os error 104)` means that Spotify has dropped the connection for any number of potential reasons. In a perfect world librespot would try to seamlessly reconnect without the user noticing if that's possible. Currently I think it may just restart Spirc which isn't seamless. In Raspotify if librespot crashes or exits the service restarts. In short on librespot's side there's nothing that can be done to prevent a 104, but it could be handled a little better maybe?
Author
Owner

@dwedia commented on GitHub (Apr 18, 2023):

Connection reset by peer (os error 104) means that Spotify has dropped the connection for any number of potential reasons. In a perfect world librespot would try to seamlessly reconnect without the user noticing if that's possible. Currently I think it may just restart Spirc which isn't seamless. In Raspotify if librespot crashes or exits the service restarts.

In short on librespot's side there's nothing that can be done to prevent a 104, but it could be handled a little better maybe?

Thank you for the reply. Not the answer I was hoping for, but if the issue is on Spotify's end, there doesnt seem like there would be much to do about it =\

<!-- gh-comment-id:1512807187 --> @dwedia commented on GitHub (Apr 18, 2023): > `Connection reset by peer (os error 104)` means that Spotify has dropped the connection for any number of potential reasons. In a perfect world librespot would try to seamlessly reconnect without the user noticing if that's possible. Currently I think it may just restart Spirc which isn't seamless. In Raspotify if librespot crashes or exits the service restarts. > > In short on librespot's side there's nothing that can be done to prevent a 104, but it could be handled a little better maybe? Thank you for the reply. Not the answer I was hoping for, but if the issue is on Spotify's end, there doesnt seem like there would be much to do about it =\
Author
Owner

@tofublock commented on GitHub (May 11, 2023):

I experience this issue, but with an added wrinkle: My RPi3+HifiberryDAC+ running OSMC and raspotify had been working perfectly until I decided to upgrade raspotify a few months ago (if I'm not mistaken I upgraded from 0.31.3 to 0.31.6, since I had to redo my raspotify configuration and set up an asound.conf.)
Since then, I see frequent crashes and service reboots as described in the issue here, but haven't changed anything else.
Is there any way this could also be related to asound configuration or anything other than "bad network"?

<!-- gh-comment-id:1543849772 --> @tofublock commented on GitHub (May 11, 2023): I experience this issue, but with an added wrinkle: My RPi3+HifiberryDAC+ running OSMC and raspotify had been working perfectly until I decided to upgrade raspotify a few months ago (if I'm not mistaken I upgraded from 0.31.3 to 0.31.6, since I had to redo my raspotify configuration and set up an asound.conf.) Since then, I see frequent crashes and service reboots as described in the issue here, but haven't changed anything else. Is there any way this could also be related to asound configuration or anything other than "bad network"?
Author
Owner

@JasonLG1979 commented on GitHub (May 11, 2023):

If you're having a Raspotify issue this is the wrong place. File a bug report at the Raspotify repo and if it is a librespot issue we can file a bug here.

<!-- gh-comment-id:1543869492 --> @JasonLG1979 commented on GitHub (May 11, 2023): If you're having a Raspotify issue this is the wrong place. File a bug report at the Raspotify repo and if it is a librespot issue we can file a bug here.
Author
Owner

@tofublock commented on GitHub (May 11, 2023):

Sorry, all 104-related topics in the raspotify repo get referred back to librespot, so I thought I'd jump on this issue report directly. Will file it over there.

<!-- gh-comment-id:1543926717 --> @tofublock commented on GitHub (May 11, 2023): Sorry, all 104-related topics in the raspotify repo get referred back to librespot, so I thought I'd jump on this issue report directly. Will file it over there.
Author
Owner

@HinzundKunz commented on GitHub (May 30, 2023):

I experience the same issue with Spot under Linux. I then have to end Spot manually via the task manager and restart.
Spot doesn't even see the problem and goes on playing stuff, but no sound is heard, and the pulseaudio applet says that no app plays any media.
Anyway, this is not a raspberry-only issue.

<!-- gh-comment-id:1567866989 --> @HinzundKunz commented on GitHub (May 30, 2023): I experience the same issue with Spot under Linux. I then have to end Spot manually via the task manager and restart. Spot doesn't even see the problem and goes on playing stuff, but no sound is heard, and the pulseaudio applet says that no app plays any media. Anyway, this is not a raspberry-only issue.
Author
Owner

@roderickvd commented on GitHub (Jun 1, 2023):

Peers shutting librespot down is hardly a librespot problem. We could discuss how librespot handles such disconnections, which indeed is a problem, and is logged in separate issues.

<!-- gh-comment-id:1572612747 --> @roderickvd commented on GitHub (Jun 1, 2023): Peers shutting librespot down is hardly a librespot problem. We could discuss how librespot handles such disconnections, which indeed is a problem, and is logged in separate issues.
Author
Owner

@jkp commented on GitHub (Apr 10, 2024):

Seeing this very same issue and as others have reported, the lowest layer where there is control of this seems to be in librespot. I understand that it feels like the client is doing the Right Thing™ but I'm pretty sure this isn't how things are supposed to work :) @roderickvd you mentioned other tickets which propose solutions...would you mind adding a link so folks can contribute to that line of enquiry?

(also speaking here as an ex-Spotify developer I may be able to poke some old friends at the mothership to help debug the issue and ask for advice on what the client should really be doing?)

<!-- gh-comment-id:2047972517 --> @jkp commented on GitHub (Apr 10, 2024): Seeing this very same issue and as others have reported, the lowest layer where there is control of this seems to be in `librespot`. I understand that it feels like the client is doing the Right Thing™ but I'm pretty sure this isn't how things are supposed to work :) @roderickvd you mentioned other tickets which propose solutions...would you mind adding a link so folks can contribute to that line of enquiry? (also speaking here as an ex-Spotify developer I may be able to poke some old friends at the mothership to help debug the issue and ask for advice on what the client should really be doing?)
Author
Owner

@roderickvd commented on GitHub (Apr 10, 2024):

See #609.

Help from the mothership would be awesome! If they'd be willing to help, then I'd like them to focus on other stuff first. Because reconnection handling is just a problem with librespot, that wasn't architected to that and is hard to fix now. It's not a problem on the server side or the understanding of the API.

Do let us know if there are Spotify devs willing to help us with a thing or two. For example with the reporting of tracks that were played and the obfuscated keys in the new HTTP API are two parts that are really not understood by us yet. And you know this project has always tried to do the right thing to combat piracy -- we're here for the music.

<!-- gh-comment-id:2048307387 --> @roderickvd commented on GitHub (Apr 10, 2024): See #609. Help from the mothership would be awesome! If they'd be willing to help, then I'd like them to focus on other stuff first. Because reconnection handling is just a problem with `librespot`, that wasn't architected to that and is hard to fix now. It's not a problem on the server side or the understanding of the API. Do let us know if there are Spotify devs willing to help us with a thing or two. For example with the reporting of tracks that were played and the obfuscated keys in the new HTTP API are two parts that are really not understood by us yet. And you know this project has always tried to do the right thing to combat piracy -- we're here for the music.
Author
Owner

@jkp commented on GitHub (Apr 11, 2024):

Nice! I'll have to reach out to a few folks and see if I can drum up any interest (there's one particular person I know who was pretty much the architect behind a full rewrite of the player stack who recently finished up at Spotify - assuming PTSD isn't too strong he might be willing to help out :))

The player/playback stack (including Connect and the Web APIs) was a thing I worked on directly for about five years (I moved on to something new in 2017) so I do have a fair bit of familiarity myself...but likely the details are hazy now. But if there are specifics I might be able to take a look (if I can find some time).

<!-- gh-comment-id:2049189047 --> @jkp commented on GitHub (Apr 11, 2024): Nice! I'll have to reach out to a few folks and see if I can drum up any interest (there's one particular person I know who was pretty much the architect behind a full rewrite of the player stack who recently finished up at Spotify - assuming PTSD isn't too strong he might be willing to help out :)) The player/playback stack (including Connect and the Web APIs) was a thing I worked on directly for about five years (I moved on to something new in 2017) so I do have a fair bit of familiarity myself...but likely the details are hazy now. But if there are specifics I might be able to take a look (if I can find some time).
Author
Owner

@kingosticks commented on GitHub (Apr 11, 2024):

If possible, I'd specifically like to know about shuffle/repeat modes which I think at least of which isn't working properly, and echo @roderickvd's request for reporting (we're keen for the correct artists to get paid), and also clarify which keymaster client IDs we should be using (we seemed to have a bunch), and if playback using just an access_token is possible (I would really like to get #1098 working).

Sorry, that snowballed. Very keen for any details you have.

<!-- gh-comment-id:2049302063 --> @kingosticks commented on GitHub (Apr 11, 2024): If possible, I'd specifically like to know about shuffle/repeat modes which I think at least of which isn't working properly, and echo @roderickvd's request for reporting (we're keen for the correct artists to get paid), and also clarify which keymaster client IDs we should be using (we seemed to have a bunch), and if playback using just an access_token is possible (I would really like to get #1098 working). Sorry, that snowballed. Very keen for any details you have.
Author
Owner

@jkp commented on GitHub (Apr 12, 2024):

When it comes to reporting of tracks: I don’t think I’m breaking any NDAs to say that (in my day….) anything past 30 seconds has to be counted and the way to register something as played is with log messages (so you’ll need to reverse engineer the logs of a genuine client to figure out the format).

The caveat here is that I have read there have been some tweaks to counteract stream fraud however I’d imagine that any correction happens downstream.

One thing I think plays in favour of building third-party clients is that even very old Spotify devices still work - having worked on the platform team building SDKs I can say that they are extremely generous about backward compatibility which I can tell you can prove extremely challenging at times!

Sent from Proton Mail for iOS

On Wed, Apr 10, 2024 at 20:41, Roderick van Domburg @.***(mailto:On Wed, Apr 10, 2024 at 20:41, Roderick van Domburg < wrote:

See #609.

Help from the mothership would be awesome! If they'd be willing to help, then I'd like them to focus on other stuff first. Because reconnection handling is just a problem with librespot, that wasn't architected to that and is hard to fix now. It's not a problem on the server side or the understanding of the API.

Do let us know if there are Spotify devs willing to help us with a thing or two. For example with the reporting of tracks that were played and the obfuscated keys in the new HTTP API are two parts that are really not understood by us yet. And you know this project has always tried to do the right thing to combat piracy -- we're here for the music.


Reply to this email directly, view it on GitHub, or unsubscribe.
You are receiving this because you commented.Message ID: @.***>

<!-- gh-comment-id:2051089716 --> @jkp commented on GitHub (Apr 12, 2024): When it comes to reporting of tracks: I don’t think I’m breaking any NDAs to say that (in my day….) anything past 30 seconds has to be counted and the way to register something as played is with log messages (so you’ll need to reverse engineer the logs of a genuine client to figure out the format). The caveat here is that I have read there have been some tweaks to counteract stream fraud however I’d imagine that any correction happens downstream. One thing I think plays in favour of building third-party clients is that even very old Spotify devices still work - having worked on the platform team building SDKs I can say that they are extremely generous about backward compatibility which I can tell you can prove extremely challenging at times! Sent from [Proton Mail](https://proton.me/mail/home) for iOS On Wed, Apr 10, 2024 at 20:41, Roderick van Domburg ***@***.***(mailto:On Wed, Apr 10, 2024 at 20:41, Roderick van Domburg <<a href=)> wrote: > See [#609](https://github.com/librespot-org/librespot/discussions/609). > > Help from the mothership would be awesome! If they'd be willing to help, then I'd like them to focus on other stuff first. Because reconnection handling is just a problem with librespot, that wasn't architected to that and is hard to fix now. It's not a problem on the server side or the understanding of the API. > > Do let us know if there are Spotify devs willing to help us with a thing or two. For example with the reporting of tracks that were played and the obfuscated keys in the new HTTP API are two parts that are really not understood by us yet. And you know this project has always tried to do the right thing to combat piracy -- we're here for the music. > > — > Reply to this email directly, [view it on GitHub](https://github.com/librespot-org/librespot/issues/1151#issuecomment-2048307387), or [unsubscribe](https://github.com/notifications/unsubscribe-auth/AAAAIINQB5M3RNWJ6O2IN7DY4WIWBAVCNFSM6AAAAAAW4BAMZWVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDANBYGMYDOMZYG4). > You are receiving this because you commented.Message ID: ***@***.***>
Author
Owner

@JCBird1012 commented on GitHub (Jun 24, 2024):

So, I encountered this issue myself using the fork vollibrespot in HiFiBerryOS (see https://github.com/hifiberry/hifiberry-os/issues/519 and https://github.com/ashthespy/Vollibrespot/issues/17) - and I was curious to see if this was still happening on 0.5.0-dev - I'm still seeing disconnects.

librespot establishes a new connection, but the Spotify Connect session does not get resumed, and playback (sometimes) stops within a few seconds of the disconnect, but always after the current song is finished.

Here's some log output (for brevity, I haven't attached logs running with --verbose, but that output isn't much more helpful) -

[2024-06-24T00:18:54Z INFO  librespot] librespot 0.5.0-dev cdff6da (Built on 2024-06-24, Build ID: cGn8N5Z2, Profile: release)
[2024-06-24T00:18:54Z INFO  librespot_playback::mixer::softmixer] Mixing with softvol and volume control: Log(60.0)
[2024-06-24T00:18:54Z INFO  librespot_playback::convert] Converting with ditherer: tpdf
[2024-06-24T00:18:54Z INFO  librespot_playback::audio_backend::rodio] Using Rodio sink with format S16 and cpal host: CoreAudio
[2024-06-24T00:18:55Z INFO  librespot_playback::audio_backend::rodio] Using audio device: MacBook Pro Speakers
[2024-06-24T00:18:58Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:18:59Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:00Z INFO  librespot_core::session] Connecting to AP "ap-gue1.spotify.com:4070"
[2024-06-24T00:19:00Z INFO  librespot_core::session] Authenticated as "1225120197" !
[2024-06-24T00:19:00Z INFO  librespot_core::session] Country: "US"
[2024-06-24T00:19:00Z INFO  librespot_core::spclient] Resolved "gue1-spclient.spotify.com:443" as spclient access point
[2024-06-24T00:19:00Z WARN  librespot_core::spclient] Unable to get client token: Client specified an invalid argument { Response status code: 400 Bad Request } Trying to continue without...
[2024-06-24T00:19:00Z WARN  librespot_core::spclient] Unable to get client token: Client specified an invalid argument { Response status code: 400 Bad Request } Trying to continue without...
[2024-06-24T00:19:01Z ERROR librespot_connect::spirc] ContextError: Error { kind: Unknown, error: StatusCode(502) }
[2024-06-24T00:19:01Z WARN  librespot_core::spclient] Unable to get client token: Client specified an invalid argument { Response status code: 400 Bad Request } Trying to continue without...
[2024-06-24T00:19:01Z INFO  librespot_playback::player] Loading <Lilac, I Think> with Spotify URI <spotify:track:0IJV2dILcU0M0dPwQzZh2T>
[2024-06-24T00:19:01Z WARN  librespot_core::spclient] Unable to get client token: Client specified an invalid argument { Response status code: 400 Bad Request } Trying to continue without...
[2024-06-24T00:19:01Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:01Z INFO  librespot_playback::player] <Lilac, I Think> (243505 ms) loaded
[2024-06-24T00:19:02Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:03Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:05Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:07Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:09Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:11Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:13Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:15Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:17Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:19Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:21Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:23Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:25Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:27Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:29Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:31Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:33Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:35Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:37Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:39Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:41Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:43Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:45Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:47Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:49Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:51Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:53Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:55Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:19:57Z WARN  libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" }
[2024-06-24T00:21:05Z ERROR librespot_core::session] session lost connection to server
[2024-06-24T00:21:05Z ERROR librespot_connect::spirc] remote update selected, but none received
[2024-06-24T00:21:05Z WARN  librespot] Spirc shut down unexpectedly
[2024-06-24T00:21:05Z INFO  librespot_core::session] Connecting to AP "ap-gue1.spotify.com:4070"
[2024-06-24T00:21:06Z INFO  librespot_core::session] Authenticated as "1225120197" !
[2024-06-24T00:21:06Z INFO  librespot_core::session] Country: "US"
[2024-06-24T00:25:11Z ERROR librespot_core::session] session lost connection to server
[2024-06-24T00:25:11Z ERROR librespot_connect::spirc] connection ID update selected, but none received
[2024-06-24T00:25:11Z WARN  librespot] Spirc shut down unexpectedly
[2024-06-24T00:25:11Z INFO  librespot_core::session] Connecting to AP "ap-gue1.spotify.com:4070"
[2024-06-24T00:25:11Z INFO  librespot_core::session] Authenticated as "1225120197" !
[2024-06-24T00:25:11Z INFO  librespot_core::session] Country: "US"
[2024-06-24T00:29:16Z ERROR librespot_core::session] session lost connection to server
[2024-06-24T00:29:16Z ERROR librespot_connect::spirc] user attributes mutation selected, but none received
[2024-06-24T00:29:16Z WARN  librespot] Spirc shut down unexpectedly
[2024-06-24T00:29:17Z INFO  librespot_core::session] Connecting to AP "ap-gue1.spotify.com:4070"
[2024-06-24T00:29:17Z INFO  librespot_core::session] Authenticated as "1225120197" !
[2024-06-24T00:29:17Z INFO  librespot_core::session] Country: "US"

Something that's interesting to me - the session gets terminated consistently after a few minutes - even with no activity (i.e. no audio playing + no active Spotify Connect session). Not sure much can be done if Spotify's terminating the connection themselves.

I initially suspected this might be related to the work done in #1129, but that's probably a red herring since this still happens in v0.4.2 before that was merged.

<!-- gh-comment-id:2185386936 --> @JCBird1012 commented on GitHub (Jun 24, 2024): So, I encountered this issue myself using the fork `vollibrespot` in `HiFiBerryOS` (see https://github.com/hifiberry/hifiberry-os/issues/519 and https://github.com/ashthespy/Vollibrespot/issues/17) - and I was curious to see if this was still happening on `0.5.0-dev` - I'm still seeing disconnects. `librespot` establishes a new connection, but the Spotify Connect session does not get resumed, and playback (sometimes) stops within a few seconds of the disconnect, but always after the current song is finished. Here's some log output (for brevity, I haven't attached logs running with `--verbose`, but that output isn't much more helpful) - ``` [2024-06-24T00:18:54Z INFO librespot] librespot 0.5.0-dev cdff6da (Built on 2024-06-24, Build ID: cGn8N5Z2, Profile: release) [2024-06-24T00:18:54Z INFO librespot_playback::mixer::softmixer] Mixing with softvol and volume control: Log(60.0) [2024-06-24T00:18:54Z INFO librespot_playback::convert] Converting with ditherer: tpdf [2024-06-24T00:18:54Z INFO librespot_playback::audio_backend::rodio] Using Rodio sink with format S16 and cpal host: CoreAudio [2024-06-24T00:18:55Z INFO librespot_playback::audio_backend::rodio] Using audio device: MacBook Pro Speakers [2024-06-24T00:18:58Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:18:59Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:00Z INFO librespot_core::session] Connecting to AP "ap-gue1.spotify.com:4070" [2024-06-24T00:19:00Z INFO librespot_core::session] Authenticated as "1225120197" ! [2024-06-24T00:19:00Z INFO librespot_core::session] Country: "US" [2024-06-24T00:19:00Z INFO librespot_core::spclient] Resolved "gue1-spclient.spotify.com:443" as spclient access point [2024-06-24T00:19:00Z WARN librespot_core::spclient] Unable to get client token: Client specified an invalid argument { Response status code: 400 Bad Request } Trying to continue without... [2024-06-24T00:19:00Z WARN librespot_core::spclient] Unable to get client token: Client specified an invalid argument { Response status code: 400 Bad Request } Trying to continue without... [2024-06-24T00:19:01Z ERROR librespot_connect::spirc] ContextError: Error { kind: Unknown, error: StatusCode(502) } [2024-06-24T00:19:01Z WARN librespot_core::spclient] Unable to get client token: Client specified an invalid argument { Response status code: 400 Bad Request } Trying to continue without... [2024-06-24T00:19:01Z INFO librespot_playback::player] Loading <Lilac, I Think> with Spotify URI <spotify:track:0IJV2dILcU0M0dPwQzZh2T> [2024-06-24T00:19:01Z WARN librespot_core::spclient] Unable to get client token: Client specified an invalid argument { Response status code: 400 Bad Request } Trying to continue without... [2024-06-24T00:19:01Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:01Z INFO librespot_playback::player] <Lilac, I Think> (243505 ms) loaded [2024-06-24T00:19:02Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:03Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:05Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:07Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:09Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:11Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:13Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:15Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:17Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:19Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:21Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:23Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:25Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:27Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:29Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:31Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:33Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:35Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:37Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:39Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:41Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:43Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:45Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:47Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:49Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:51Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:53Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:55Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:19:57Z WARN libmdns::fsm] error sending packet Os { code: 65, kind: HostUnreachable, message: "No route to host" } [2024-06-24T00:21:05Z ERROR librespot_core::session] session lost connection to server [2024-06-24T00:21:05Z ERROR librespot_connect::spirc] remote update selected, but none received [2024-06-24T00:21:05Z WARN librespot] Spirc shut down unexpectedly [2024-06-24T00:21:05Z INFO librespot_core::session] Connecting to AP "ap-gue1.spotify.com:4070" [2024-06-24T00:21:06Z INFO librespot_core::session] Authenticated as "1225120197" ! [2024-06-24T00:21:06Z INFO librespot_core::session] Country: "US" [2024-06-24T00:25:11Z ERROR librespot_core::session] session lost connection to server [2024-06-24T00:25:11Z ERROR librespot_connect::spirc] connection ID update selected, but none received [2024-06-24T00:25:11Z WARN librespot] Spirc shut down unexpectedly [2024-06-24T00:25:11Z INFO librespot_core::session] Connecting to AP "ap-gue1.spotify.com:4070" [2024-06-24T00:25:11Z INFO librespot_core::session] Authenticated as "1225120197" ! [2024-06-24T00:25:11Z INFO librespot_core::session] Country: "US" [2024-06-24T00:29:16Z ERROR librespot_core::session] session lost connection to server [2024-06-24T00:29:16Z ERROR librespot_connect::spirc] user attributes mutation selected, but none received [2024-06-24T00:29:16Z WARN librespot] Spirc shut down unexpectedly [2024-06-24T00:29:17Z INFO librespot_core::session] Connecting to AP "ap-gue1.spotify.com:4070" [2024-06-24T00:29:17Z INFO librespot_core::session] Authenticated as "1225120197" ! [2024-06-24T00:29:17Z INFO librespot_core::session] Country: "US" ``` Something that's interesting to me - the session gets terminated consistently after a few minutes - even with no activity (i.e. no audio playing + no active Spotify Connect session). Not sure much can be done if Spotify's terminating the connection themselves. I initially suspected this might be related to the work done in #1129, but that's probably a red herring since this still happens in `v0.4.2` before that was merged.
Author
Owner

@roderickvd commented on GitHub (Jun 24, 2024):

Thanks for the debugging. It’s a known architecture flaw, and unfortunately a hard one at that.

Whether a song is playing or not does not matter, because a Spirc session is always connected and notices the hang up.

<!-- gh-comment-id:2185656096 --> @roderickvd commented on GitHub (Jun 24, 2024): Thanks for the debugging. It’s a known architecture flaw, and unfortunately a hard one at that. Whether a song is playing or not does not matter, because a Spirc session is always connected and notices the hang up.
Author
Owner

@JCBird1012 commented on GitHub (Jun 24, 2024):

I tested librespot-java for the heck of it to see if it's affected by this same issue - it looks like it is (on the surface), but it appears it gets handled much more gracefully. The Spotify Connect session on the controlling device never gets interrupted (+ it can continue controlling after the disconnection happens in the logs), and audio never stops playing. In the half-hour or so that I've played with it, I haven't seen it have the same behavior I see in librespot (except in a few rare circumstances such as the controlling device changing networks).

2024-06-24 09:55:21,750 TRACE CdnManager:277 - Chunk 4/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1}
2024-06-24 09:55:34,593 TRACE CdnManager:277 - Chunk 5/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1}
2024-06-24 09:55:47,488 TRACE CdnManager:277 - Chunk 6/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1}
2024-06-24 09:55:59,376 TRACE CdnManager:277 - Chunk 7/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1}
2024-06-24 09:56:11,762 TRACE CdnManager:277 - Chunk 8/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1}
2024-06-24 09:56:23,200 TRACE CdnManager:277 - Chunk 9/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1}
2024-06-24 09:56:34,962 TRACE CdnManager:277 - Chunk 10/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1}

2024-06-24 09:56:45,869 TRACE CdnManager:277 - Chunk 11/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1}
2024-06-24 09:56:57,041 TRACE CdnManager:277 - Chunk 12/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1}
2024-06-24 09:57:08,322 TRACE CdnManager:277 - Chunk 13/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1}
2024-06-24 09:57:16,413 WARN  Session:1440 - Socket timed out. Reconnecting...
2024-06-24 09:57:16,417 TRACE Session:1500 - Session.Receiver stopped
2024-06-24 09:57:16,455 INFO  ApResolver:99 - Loaded aps into pool: {accesspoint=[ap-gue1.spotify.com:4070, ap-gue1.spotify.com:443, ap-gue1.spotify.com:80, ap-gae2.spotify.com:4070, ap-gew1.spotify.com:443, ap-gew4.spotify.com:80], dealer=[gue1-dealer.spotify.com:443, gae2-dealer.spotify.com:443, gew1-dealer.spotify.com:443, gew4-dealer.spotify.com:443], spclient=[gue1-spclient.spotify.com:443, gae2-spclient.spotify.com:443, gew1-spclient.spotify.com:443, gew4-spclient.spotify.com:443]}
2024-06-24 09:57:17,346 INFO  Session:334 - Connected successfully!
2024-06-24 09:57:17,688 TRACE Session:1413 - Session.Receiver started
2024-06-24 09:57:17,689 INFO  Session:736 - Re-authenticated as 1225120197!
2024-06-24 09:57:17,690 INFO  Session:1495 - Skipping SecretBlock
2024-06-24 09:57:17,690 INFO  Session:1467 - Received LicenseVersion: 0
2024-06-24 09:57:17,690 INFO  Session:1457 - Received CountryCode: US
2024-06-24 09:57:17,701 TRACE Session:784 - Parsed product info: {audiobook-onboarding-completed=0, remote-control=6, publish-activity=1, audio-preview-url-template=https://p.scdn.co/mp3-preview/{id}, incognito_mode_timeout=21600, ad-formats-preroll-video=0, type=premium, ab_recently_played_feature_time_filter_threshold=com.spotify.gaia=30,driving-mode=120,spotify%3Ainternal%3Astartpage=30, license-agreements=, publish-playlist=0, buffering-strategy=0, expiry=1, ab-desktop-hide-follow=1, ab-collection-hide-unavailable-albums=0, capper-profile=, payments-initial-campaign=default, profile-image-upload=1, enable-annotations=2, ab-ad-player-targeting=1, subscription-enddate=, india-experience=0, video-wifi-initial-bitrate=800000, ab-mobile-running-onlymanualmode=only-manual, playlist-annotations-markup=0, prefetch-keys=1, allow-override-internal-prefs=0, prefetch-window-max=2, send-email=1, ad-formats-video-takeover=1, ab-collection-bookmark-model=1, pause-after=0, local-files-import=0, video-manifest-url=https://spclient.wg.spotify.com/manifests/v6/{type}/sources/{source_id}/options/supports_drm, playlist-folders=1, arsenal_country=1, track-cap=0, restrict-playlist-collaboration=0, audiobook-onboarding-dismissed=0, ab-mobile-running-tempo-detection=Control, is_email_verified=1, shows-collection=1, enable-annotations-read=0, addon-hifi=0, mobile-browse=0, payments-locked-state=0, employee-free-opt-in=0, shows-collection-jam=1, ab-browse-music-tuesday=1, offline=1, streaming=1, fb-info-confirmation=control, audio-quality=1, wanted-licenses=, lastfm-session=, ab-desktop-playlist-annotation-edit=1, ab-mobile-discover=0, widevine-license-url=https://spclient.wg.spotify.com/widevine-license/v1/video/license, key-caching-max-count=10000, hifi-eligible=0, ad-session-persistence=1, video-initial-bitrate=200000, ab-play-history=0, mobile-payment=0, payment-state=, key-caching-max-offline-seconds=1800, ugc-abuse-report-url=https://support.spotify.com/abuse/?uri={uri}, shuffle-algorithm=1, use-pl3=0, image-url=https://i.scdn.co/image/{file_id}, use-playlist-app=0, enable-autostart=1, metadata-link-lookup-modes=0, multiuserplan-current-size=4, shuffle=0, instant-search=0, instant-search-expand-sidebar=0, use-playlist-uris=0, user-profile-show-invitation-codes=0, multiuserplan-member-type=FAMILY_MANAGER, ab-ad-requester=1, nft-disabled=1, ab-collection-union=1, key-memory-cache-mode=1:15,300, libspotify=1, high-bitrate=1, head-file-caching=1, radio=1, key-caching-auto-offline=0, explicit-content=1, video-cdn-sampling=1, ab-android-push-notifications=1, unrestricted=1, use-fb-publish-backend=2, app-developer=0, buffering-strategy-parameters=0.8:0.2:0.0:0.0:0.0:0.0:1.0:10:10:2000:10000:10485760, enable-gapless=1, ab-playlist-extender=5, enable-crossfade=1, ad-persist-reward-time=0, public-toplist=1, network-operator-premium-activation=1, video-device-blacklisted=0, collection=1, fb-grant-permission-local-render=0, backend-advised-bitrate=1, autoplay=1, catalogue=premium, storage-size-config=10240,90,500,3, ads=0, head-files-url=https://heads-fa-tls13.spotifycdn.com/head/{file_id}, ab-collection-followed-artists-only=0, browse-overview-enabled=1, on-demand=1, ap-resolve-pods=1, name=Spotify Premium, sidebar-navigation-enabled=0, loudness-levels=1:-5.0,0.0,3.0:-2.0, mobile-login=1, product-expiry=, hifi-optin-intent=0, preferred-locale=en, license-acceptance-grace-days=30, prefetch-strategy=18, ugc-abuse-report=1, ab-watch-now=0, financial-product=pr:premium,tc:0,rt:v2_US_default_new-family-master-1m_16.99_USD_default, ab-collection-offline-mode=0, streaming-rules=, head-files=1, capping-bar-threshold=3601, ab-new-share-flow=0, video-keyframe-url=http://keyframes-fa.cdn.spotify.com/keyframes/v1/sources/{source_id}/keyframe/heights/{height}/timestamps/{timestamp_ms}.jpg, mobile=1, is_maybe_in_social_session=0, ab-mobile-startpage=0, ab-moments-experience=0, ab-mobile-social-feed=1, ab-test-group=168, player-license=premium}
2024-06-24 09:57:17,702 INFO  Session:1495 - Skipping UnknownData_AllZeros
2024-06-24 09:57:17,702 INFO  Session:1495 - Skipping LegacyWelcome
2024-06-24 09:57:17,875 TRACE MercuryClient:191 - Handling packet, cmd: MercuryEvent, seq: -126318492868673536, flags: 1, parts: 1
2024-06-24 09:57:17,875 DEBUG MercuryClient:226 - Couldn't dispatch Mercury event {seq: -126318492868673536, uri: hm://pusher/v1/connections/YTU1ZTE2YzViMzBmM2U3YWQ2ODdiMWY4NTkzYWFjODQ3OWU1ZDE3MStBUCt0Y3A6Ly9nYWUyLWFjY2Vzc3BvaW50LWMtenRqZi5nYWUyLnNwb3RpZnkubmV0OjUwMTIrNUI4REU4QzhBRTVBNDJEMkY3ODMzMjZFMjhERjBFNEYzNDYxRDJDOURDQUIwN0JGNjYxQTg3MjNEM0QyNTQ3Rg%3D%3D, code: 200, payload: []}
2024-06-24 09:57:18,062 DEBUG Session:1471 - Received 0x10: 43B6DFFAA2A7D71CE576B6BEC40CF1A5736983E9
2024-06-24 09:57:18,251 INFO  Session:1422 - Skipping unknown command {cmd: 0x75, payload: 000000}
2024-06-24 09:57:20,099 TRACE CdnManager:277 - Chunk 14/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1}
2024-06-24 09:57:32,692 TRACE CdnManager:277 - Chunk 15/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1}
2024-06-24 09:57:45,419 TRACE CdnManager:277 - Chunk 16/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1}
2024-06-24 09:57:58,630 TRACE CdnManager:277 - Chunk 17/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1}
2024-06-24 09:58:11,448 TRACE CdnManager:277 - Chunk 18/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1}
2024-06-24 09:58:23,494 TRACE CdnManager:277 - Chunk 19/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1}
2024-06-24 09:58:25,474 TRACE DealerClient:113 - Received request. {mid: hm://connect-state/v1/player/command, key: 7323e193-24bc-4590-adc6-8727132a229b, pid: 1250587711, sender: 386d8ede68b726268a4f447b6e31cb8e071e6391, command: {"endpoint":"skip_next","options":{"override_restrictions":false,"only_for_local_device":false,"system_initiated":false},"logging_params":{"command_initiated_time":1719237505198,"command_received_time":1719237505201,"device_identifier":"386d8ede68b726268a4f447b6e31cb8e071e6391","command_id":"6564ce8bd340bdb6c1c67ffdb27aaffa"}}}
2024-06-24 09:58:25,474 DEBUG Player:107 - Received command: SkipNext
2024-06-24 09:58:25,486 TRACE MercuryClient:148 - Send Mercury request, seq: 5, uri: hm://event-service/v1/events, method: POST
2024-06-24 09:58:25,486 DEBUG Player:492 - Loading track, id: TrackId{spotify:track:1Ac5BDsGUMQ3tsW2vnc52x}, session: TsolA+3CEjrYAfHFsyB9cg, playback: 01ce76dd22c85ffa56fb91a6fcbb64ea, play: true
2024-06-24 09:58:25,488 TRACE PlayerQueueEntry:92 - Created new PlayerQueueEntry{0147b1fe4ea6756df72096f4572a3832}.
2024-06-24 09:58:25,489 TRACE PlayerQueue:82 - PlayerQueueEntry{0147b1fe4ea6756df72096f4572a3832} added to queue.
2024-06-24 09:58:25,489 DEBUG CrossfadeController:192 - Changed fade out. {curr: null, custom: false, why: TRACK_DONE, id: 01ce76dd22c85ffa56fb91a6fcbb64ea}
2024-06-24 09:58:25,489 TRACE PlayerSession:162 - PlayerQueueEntry{0147b1fe4ea6756df72096f4572a3832} started loading.
2024-06-24 09:58:25,489 DEBUG CrossfadeController:192 - Changed fade out. {curr: null, custom: false, why: FORWARD_BTN, id: 01ce76dd22c85ffa56fb91a6fcbb64ea}
2024-06-24 09:58:25,489 TRACE MixingLine:184 - Toggle first channel: false
2024-06-24 09:58:25,490 DEBUG PlayerQueueEntry:234 - PlayerQueueEntry{01ce76dd22c85ffa56fb91a6fcbb64ea} has been removed from output.
2024-06-24 09:58:25,490 TRACE PlayerQueueEntry:350 - PlayerQueueEntry{01ce76dd22c85ffa56fb91a6fcbb64ea} terminated.
2024-06-24 09:58:25,490 DEBUG PlayerSession:283 - PlayerQueueEntry{0147b1fe4ea6756df72096f4572a3832} has been added to the output. {sessionId: TsolA+3CEjrYAfHFsyB9cg, pos: 2, reason: FORWARD_BTN}
2024-06-24 09:58:25,492 DEBUG DealerClient:125 - Handled request. {key: 7323e193-24bc-4590-adc6-8727132a229b, result: SUCCESS}
2024-06-24 09:58:25,862 TRACE MercuryClient:191 - Handling packet, cmd: MercuryReq, seq: 5, flags: 1, parts: 1
2024-06-24 09:58:25,863 DEBUG EventService:51 - Event sent. {body: 12|38|0|a55e16c5b30f3e7ad687b1f8593aac8479e5d171|01ce76dd22c85ffa56fb91a6fcbb64ea|00000000000000000000000000000000|playlist/ondemand|clickrow|playlist/ondemand|fwdbtn|2510832|2510832|195139|195139|237958|1|0|0|0|1|8|0|-1|context|71|0|0|0|0|0|195139|195139|0|176400|spotify:playlist:71fQTNrM5KzjBQfuw181Pd|vorbis|714fa403d5a540b4b07712fcea59936e||0|1719237308472|0|context|find|8.9.48.455|com.spotify|crossfade|none|386d8ede68b726268a4f447b6e31cb8e071e6391|na|none, result: 200}
2024-06-24 09:58:25,863 TRACE MercuryClient:148 - Send Mercury request, seq: 6, uri: hm://event-service/v1/events, method: POST

I suspect they're re-using the existing session and just re-connecting (There's a TODO to do something similar in session.rs)

github.com/librespot-org/librespot@cdff6da1f8/core/src/session.rs (L264)

Here's what their logs look like on initial connect -

2024-06-24 10:08:55,061 INFO  ApResolver:99 - Loaded aps into pool: {accesspoint=[ap-gue1.spotify.com:4070, ap-gue1.spotify.com:443, ap-gue1.spotify.com:80, ap-gae2.spotify.com:4070, ap-gew1.spotify.com:443, ap-gew4.spotify.com:80], dealer=[gue1-dealer.spotify.com:443, gae2-dealer.spotify.com:443, gew1-dealer.spotify.com:443, gew4-dealer.spotify.com:443], spclient=[gue1-spclient.spotify.com:443, gae2-spclient.spotify.com:443, gew1-spclient.spotify.com:443, gew4-spclient.spotify.com:443]}
2024-06-24 10:08:55,099 INFO  Session:140 - Created new session! {deviceId: f98691d4969217ceac650b9595b694eee55bc45a, ap: ap-gue1.spotify.com:80, proxy: false}
2024-06-24 10:08:55,486 INFO  Session:334 - Connected successfully!
2024-06-24 10:08:55,613 TRACE Session:1413 - Session.Receiver started
2024-06-24 10:08:55,623 INFO  CacheManager:95 - There are 9 cached entries.
2024-06-24 10:08:55,624 TRACE AsyncProcessor:52 - AsyncProcessor{dealer-worker} has started
2024-06-24 10:08:55,625 TRACE AsyncProcessor:52 - AsyncProcessor{event-service-sender} has started
2024-06-24 10:08:55,626 INFO  Session:1495 - Skipping SecretBlock
2024-06-24 10:08:55,626 INFO  Session:1467 - Received LicenseVersion: 0
2024-06-24 10:08:55,626 DEBUG TokenProvider:68 - Token expired or not suitable, requesting again. {scopes: [playlist-read], oldToken: null}
2024-06-24 10:08:55,626 INFO  Session:1457 - Received CountryCode: US
2024-06-24 10:08:55,629 TRACE MercuryClient:148 - Send Mercury request, seq: 1, uri: hm://keymaster/token/authenticated?scope=playlist-read&client_id=65b708073fc0480ea92a077233ca87bd&device_id=f98691d4969217ceac650b9595b694eee55bc45a, method: GET


... <snip some non-helpful logs> ...


2024-06-24 10:08:55,631 INFO  Session:1495 - Skipping UnknownData_AllZeros
2024-06-24 10:08:55,631 INFO  Session:1495 - Skipping LegacyWelcome
2024-06-24 10:08:55,631 TRACE MercuryClient:191 - Handling packet, cmd: MercuryEvent, seq: 6511323252852260864, flags: 1, parts: 1
2024-06-24 10:08:55,632 DEBUG MercuryClient:226 - Couldn't dispatch Mercury event {seq: 6511323252852260864, uri: hm://pusher/v1/connections/Zjk4NjkxZDQ5NjkyMTdjZWFjNjUwYjk1OTViNjk0ZWVlNTViYzQ1YStBUCt0Y3A6Ly9ndWUxLWFjY2Vzc3BvaW50LWMtbjVoaC5ndWUxLnNwb3RpZnkubmV0OjUwMTQrQTk1QzI3NjIzRTlCRkIyRkZCNzVBMzlEN0EzMjBBRTA0QzI1NzZDN0IxNzYzMEIzMzNGREU5RkU0QkVENzUzRA%3D%3D, code: 200, payload: []}
2024-06-24 10:08:55,667 DEBUG Session:1471 - Received 0x10: 42FBF47638046984A8B4A094D3CD0D02EB3FF5F3
2024-06-24 10:08:55,709 TRACE MercuryClient:191 - Handling packet, cmd: MercuryReq, seq: 1, flags: 1, parts: 2
2024-06-24 10:08:55,710 DEBUG TokenProvider:72 - Updated token successfully! {scopes: [playlist-read], newToken: StoredToken{expiresIn=3600, accessToken='BQDw6L...l8SU5Q', scopes=[playlist-read], timestamp=1719238135754}}
2024-06-24 10:08:55,714 INFO  Session:364 - Authenticated as 1225120197!

and on re-connect -

2024-06-24 10:11:05,619 WARN  Session:1440 - Socket timed out. Reconnecting...
2024-06-24 10:11:05,624 TRACE Session:1500 - Session.Receiver stopped
2024-06-24 10:11:05,665 INFO  ApResolver:99 - Loaded aps into pool: {accesspoint=[ap-gue1.spotify.com:4070, ap-gue1.spotify.com:443, ap-gue1.spotify.com:80, ap-guc3.spotify.com:4070, ap-gew1.spotify.com:443, ap-gew4.spotify.com:80], dealer=[gue1-dealer.spotify.com:443, guc3-dealer.spotify.com:443, gew1-dealer.spotify.com:443, gew4-dealer.spotify.com:443], spclient=[gue1-spclient.spotify.com:443, guc3-spclient.spotify.com:443, gew1-spclient.spotify.com:443, gew4-spclient.spotify.com:443]}
2024-06-24 10:11:06,101 INFO  Session:334 - Connected successfully!
2024-06-24 10:11:06,216 TRACE Session:1413 - Session.Receiver started
2024-06-24 10:11:06,216 INFO  Session:736 - Re-authenticated as 1225120197!
2024-06-24 10:11:06,217 INFO  Session:1495 - Skipping SecretBlock
2024-06-24 10:11:06,218 INFO  Session:1467 - Received LicenseVersion: 0
2024-06-24 10:11:06,218 INFO  Session:1457 - Received CountryCode: US
<!-- gh-comment-id:2186680621 --> @JCBird1012 commented on GitHub (Jun 24, 2024): I tested `librespot-java` for the heck of it to see if it's affected by this same issue - it looks like it is (on the surface), but it appears it gets handled much more gracefully. The Spotify Connect session on the controlling device never gets interrupted (+ it can continue controlling after the disconnection happens in the logs), and audio never stops playing. In the half-hour or so that I've played with it, I haven't seen it have the same behavior I see in `librespot` (except in a few rare circumstances such as the controlling device changing networks). ``` 2024-06-24 09:55:21,750 TRACE CdnManager:277 - Chunk 4/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1} 2024-06-24 09:55:34,593 TRACE CdnManager:277 - Chunk 5/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1} 2024-06-24 09:55:47,488 TRACE CdnManager:277 - Chunk 6/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1} 2024-06-24 09:55:59,376 TRACE CdnManager:277 - Chunk 7/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1} 2024-06-24 09:56:11,762 TRACE CdnManager:277 - Chunk 8/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1} 2024-06-24 09:56:23,200 TRACE CdnManager:277 - Chunk 9/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1} 2024-06-24 09:56:34,962 TRACE CdnManager:277 - Chunk 10/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1} 2024-06-24 09:56:45,869 TRACE CdnManager:277 - Chunk 11/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1} 2024-06-24 09:56:57,041 TRACE CdnManager:277 - Chunk 12/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1} 2024-06-24 09:57:08,322 TRACE CdnManager:277 - Chunk 13/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1} 2024-06-24 09:57:16,413 WARN Session:1440 - Socket timed out. Reconnecting... 2024-06-24 09:57:16,417 TRACE Session:1500 - Session.Receiver stopped 2024-06-24 09:57:16,455 INFO ApResolver:99 - Loaded aps into pool: {accesspoint=[ap-gue1.spotify.com:4070, ap-gue1.spotify.com:443, ap-gue1.spotify.com:80, ap-gae2.spotify.com:4070, ap-gew1.spotify.com:443, ap-gew4.spotify.com:80], dealer=[gue1-dealer.spotify.com:443, gae2-dealer.spotify.com:443, gew1-dealer.spotify.com:443, gew4-dealer.spotify.com:443], spclient=[gue1-spclient.spotify.com:443, gae2-spclient.spotify.com:443, gew1-spclient.spotify.com:443, gew4-spclient.spotify.com:443]} 2024-06-24 09:57:17,346 INFO Session:334 - Connected successfully! 2024-06-24 09:57:17,688 TRACE Session:1413 - Session.Receiver started 2024-06-24 09:57:17,689 INFO Session:736 - Re-authenticated as 1225120197! 2024-06-24 09:57:17,690 INFO Session:1495 - Skipping SecretBlock 2024-06-24 09:57:17,690 INFO Session:1467 - Received LicenseVersion: 0 2024-06-24 09:57:17,690 INFO Session:1457 - Received CountryCode: US 2024-06-24 09:57:17,701 TRACE Session:784 - Parsed product info: {audiobook-onboarding-completed=0, remote-control=6, publish-activity=1, audio-preview-url-template=https://p.scdn.co/mp3-preview/{id}, incognito_mode_timeout=21600, ad-formats-preroll-video=0, type=premium, ab_recently_played_feature_time_filter_threshold=com.spotify.gaia=30,driving-mode=120,spotify%3Ainternal%3Astartpage=30, license-agreements=, publish-playlist=0, buffering-strategy=0, expiry=1, ab-desktop-hide-follow=1, ab-collection-hide-unavailable-albums=0, capper-profile=, payments-initial-campaign=default, profile-image-upload=1, enable-annotations=2, ab-ad-player-targeting=1, subscription-enddate=, india-experience=0, video-wifi-initial-bitrate=800000, ab-mobile-running-onlymanualmode=only-manual, playlist-annotations-markup=0, prefetch-keys=1, allow-override-internal-prefs=0, prefetch-window-max=2, send-email=1, ad-formats-video-takeover=1, ab-collection-bookmark-model=1, pause-after=0, local-files-import=0, video-manifest-url=https://spclient.wg.spotify.com/manifests/v6/{type}/sources/{source_id}/options/supports_drm, playlist-folders=1, arsenal_country=1, track-cap=0, restrict-playlist-collaboration=0, audiobook-onboarding-dismissed=0, ab-mobile-running-tempo-detection=Control, is_email_verified=1, shows-collection=1, enable-annotations-read=0, addon-hifi=0, mobile-browse=0, payments-locked-state=0, employee-free-opt-in=0, shows-collection-jam=1, ab-browse-music-tuesday=1, offline=1, streaming=1, fb-info-confirmation=control, audio-quality=1, wanted-licenses=, lastfm-session=, ab-desktop-playlist-annotation-edit=1, ab-mobile-discover=0, widevine-license-url=https://spclient.wg.spotify.com/widevine-license/v1/video/license, key-caching-max-count=10000, hifi-eligible=0, ad-session-persistence=1, video-initial-bitrate=200000, ab-play-history=0, mobile-payment=0, payment-state=, key-caching-max-offline-seconds=1800, ugc-abuse-report-url=https://support.spotify.com/abuse/?uri={uri}, shuffle-algorithm=1, use-pl3=0, image-url=https://i.scdn.co/image/{file_id}, use-playlist-app=0, enable-autostart=1, metadata-link-lookup-modes=0, multiuserplan-current-size=4, shuffle=0, instant-search=0, instant-search-expand-sidebar=0, use-playlist-uris=0, user-profile-show-invitation-codes=0, multiuserplan-member-type=FAMILY_MANAGER, ab-ad-requester=1, nft-disabled=1, ab-collection-union=1, key-memory-cache-mode=1:15,300, libspotify=1, high-bitrate=1, head-file-caching=1, radio=1, key-caching-auto-offline=0, explicit-content=1, video-cdn-sampling=1, ab-android-push-notifications=1, unrestricted=1, use-fb-publish-backend=2, app-developer=0, buffering-strategy-parameters=0.8:0.2:0.0:0.0:0.0:0.0:1.0:10:10:2000:10000:10485760, enable-gapless=1, ab-playlist-extender=5, enable-crossfade=1, ad-persist-reward-time=0, public-toplist=1, network-operator-premium-activation=1, video-device-blacklisted=0, collection=1, fb-grant-permission-local-render=0, backend-advised-bitrate=1, autoplay=1, catalogue=premium, storage-size-config=10240,90,500,3, ads=0, head-files-url=https://heads-fa-tls13.spotifycdn.com/head/{file_id}, ab-collection-followed-artists-only=0, browse-overview-enabled=1, on-demand=1, ap-resolve-pods=1, name=Spotify Premium, sidebar-navigation-enabled=0, loudness-levels=1:-5.0,0.0,3.0:-2.0, mobile-login=1, product-expiry=, hifi-optin-intent=0, preferred-locale=en, license-acceptance-grace-days=30, prefetch-strategy=18, ugc-abuse-report=1, ab-watch-now=0, financial-product=pr:premium,tc:0,rt:v2_US_default_new-family-master-1m_16.99_USD_default, ab-collection-offline-mode=0, streaming-rules=, head-files=1, capping-bar-threshold=3601, ab-new-share-flow=0, video-keyframe-url=http://keyframes-fa.cdn.spotify.com/keyframes/v1/sources/{source_id}/keyframe/heights/{height}/timestamps/{timestamp_ms}.jpg, mobile=1, is_maybe_in_social_session=0, ab-mobile-startpage=0, ab-moments-experience=0, ab-mobile-social-feed=1, ab-test-group=168, player-license=premium} 2024-06-24 09:57:17,702 INFO Session:1495 - Skipping UnknownData_AllZeros 2024-06-24 09:57:17,702 INFO Session:1495 - Skipping LegacyWelcome 2024-06-24 09:57:17,875 TRACE MercuryClient:191 - Handling packet, cmd: MercuryEvent, seq: -126318492868673536, flags: 1, parts: 1 2024-06-24 09:57:17,875 DEBUG MercuryClient:226 - Couldn't dispatch Mercury event {seq: -126318492868673536, uri: hm://pusher/v1/connections/YTU1ZTE2YzViMzBmM2U3YWQ2ODdiMWY4NTkzYWFjODQ3OWU1ZDE3MStBUCt0Y3A6Ly9nYWUyLWFjY2Vzc3BvaW50LWMtenRqZi5nYWUyLnNwb3RpZnkubmV0OjUwMTIrNUI4REU4QzhBRTVBNDJEMkY3ODMzMjZFMjhERjBFNEYzNDYxRDJDOURDQUIwN0JGNjYxQTg3MjNEM0QyNTQ3Rg%3D%3D, code: 200, payload: []} 2024-06-24 09:57:18,062 DEBUG Session:1471 - Received 0x10: 43B6DFFAA2A7D71CE576B6BEC40CF1A5736983E9 2024-06-24 09:57:18,251 INFO Session:1422 - Skipping unknown command {cmd: 0x75, payload: 000000} 2024-06-24 09:57:20,099 TRACE CdnManager:277 - Chunk 14/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1} 2024-06-24 09:57:32,692 TRACE CdnManager:277 - Chunk 15/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1} 2024-06-24 09:57:45,419 TRACE CdnManager:277 - Chunk 16/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1} 2024-06-24 09:57:58,630 TRACE CdnManager:277 - Chunk 17/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1} 2024-06-24 09:58:11,448 TRACE CdnManager:277 - Chunk 18/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1} 2024-06-24 09:58:23,494 TRACE CdnManager:277 - Chunk 19/20 completed, cached: false, stream: {fileId: 9EA919FC2D34817E61280E0AA700B45762E914E1} 2024-06-24 09:58:25,474 TRACE DealerClient:113 - Received request. {mid: hm://connect-state/v1/player/command, key: 7323e193-24bc-4590-adc6-8727132a229b, pid: 1250587711, sender: 386d8ede68b726268a4f447b6e31cb8e071e6391, command: {"endpoint":"skip_next","options":{"override_restrictions":false,"only_for_local_device":false,"system_initiated":false},"logging_params":{"command_initiated_time":1719237505198,"command_received_time":1719237505201,"device_identifier":"386d8ede68b726268a4f447b6e31cb8e071e6391","command_id":"6564ce8bd340bdb6c1c67ffdb27aaffa"}}} 2024-06-24 09:58:25,474 DEBUG Player:107 - Received command: SkipNext 2024-06-24 09:58:25,486 TRACE MercuryClient:148 - Send Mercury request, seq: 5, uri: hm://event-service/v1/events, method: POST 2024-06-24 09:58:25,486 DEBUG Player:492 - Loading track, id: TrackId{spotify:track:1Ac5BDsGUMQ3tsW2vnc52x}, session: TsolA+3CEjrYAfHFsyB9cg, playback: 01ce76dd22c85ffa56fb91a6fcbb64ea, play: true 2024-06-24 09:58:25,488 TRACE PlayerQueueEntry:92 - Created new PlayerQueueEntry{0147b1fe4ea6756df72096f4572a3832}. 2024-06-24 09:58:25,489 TRACE PlayerQueue:82 - PlayerQueueEntry{0147b1fe4ea6756df72096f4572a3832} added to queue. 2024-06-24 09:58:25,489 DEBUG CrossfadeController:192 - Changed fade out. {curr: null, custom: false, why: TRACK_DONE, id: 01ce76dd22c85ffa56fb91a6fcbb64ea} 2024-06-24 09:58:25,489 TRACE PlayerSession:162 - PlayerQueueEntry{0147b1fe4ea6756df72096f4572a3832} started loading. 2024-06-24 09:58:25,489 DEBUG CrossfadeController:192 - Changed fade out. {curr: null, custom: false, why: FORWARD_BTN, id: 01ce76dd22c85ffa56fb91a6fcbb64ea} 2024-06-24 09:58:25,489 TRACE MixingLine:184 - Toggle first channel: false 2024-06-24 09:58:25,490 DEBUG PlayerQueueEntry:234 - PlayerQueueEntry{01ce76dd22c85ffa56fb91a6fcbb64ea} has been removed from output. 2024-06-24 09:58:25,490 TRACE PlayerQueueEntry:350 - PlayerQueueEntry{01ce76dd22c85ffa56fb91a6fcbb64ea} terminated. 2024-06-24 09:58:25,490 DEBUG PlayerSession:283 - PlayerQueueEntry{0147b1fe4ea6756df72096f4572a3832} has been added to the output. {sessionId: TsolA+3CEjrYAfHFsyB9cg, pos: 2, reason: FORWARD_BTN} 2024-06-24 09:58:25,492 DEBUG DealerClient:125 - Handled request. {key: 7323e193-24bc-4590-adc6-8727132a229b, result: SUCCESS} 2024-06-24 09:58:25,862 TRACE MercuryClient:191 - Handling packet, cmd: MercuryReq, seq: 5, flags: 1, parts: 1 2024-06-24 09:58:25,863 DEBUG EventService:51 - Event sent. {body: 12|38|0|a55e16c5b30f3e7ad687b1f8593aac8479e5d171|01ce76dd22c85ffa56fb91a6fcbb64ea|00000000000000000000000000000000|playlist/ondemand|clickrow|playlist/ondemand|fwdbtn|2510832|2510832|195139|195139|237958|1|0|0|0|1|8|0|-1|context|71|0|0|0|0|0|195139|195139|0|176400|spotify:playlist:71fQTNrM5KzjBQfuw181Pd|vorbis|714fa403d5a540b4b07712fcea59936e||0|1719237308472|0|context|find|8.9.48.455|com.spotify|crossfade|none|386d8ede68b726268a4f447b6e31cb8e071e6391|na|none, result: 200} 2024-06-24 09:58:25,863 TRACE MercuryClient:148 - Send Mercury request, seq: 6, uri: hm://event-service/v1/events, method: POST ``` I suspect they're re-using the existing session and just re-connecting (There's a TODO to do something similar in `session.rs`) https://github.com/librespot-org/librespot/blob/cdff6da1f86c284897c0566fd92e332d925e5cd4/core/src/session.rs#L264 Here's what their logs look like on initial connect - ``` 2024-06-24 10:08:55,061 INFO ApResolver:99 - Loaded aps into pool: {accesspoint=[ap-gue1.spotify.com:4070, ap-gue1.spotify.com:443, ap-gue1.spotify.com:80, ap-gae2.spotify.com:4070, ap-gew1.spotify.com:443, ap-gew4.spotify.com:80], dealer=[gue1-dealer.spotify.com:443, gae2-dealer.spotify.com:443, gew1-dealer.spotify.com:443, gew4-dealer.spotify.com:443], spclient=[gue1-spclient.spotify.com:443, gae2-spclient.spotify.com:443, gew1-spclient.spotify.com:443, gew4-spclient.spotify.com:443]} 2024-06-24 10:08:55,099 INFO Session:140 - Created new session! {deviceId: f98691d4969217ceac650b9595b694eee55bc45a, ap: ap-gue1.spotify.com:80, proxy: false} 2024-06-24 10:08:55,486 INFO Session:334 - Connected successfully! 2024-06-24 10:08:55,613 TRACE Session:1413 - Session.Receiver started 2024-06-24 10:08:55,623 INFO CacheManager:95 - There are 9 cached entries. 2024-06-24 10:08:55,624 TRACE AsyncProcessor:52 - AsyncProcessor{dealer-worker} has started 2024-06-24 10:08:55,625 TRACE AsyncProcessor:52 - AsyncProcessor{event-service-sender} has started 2024-06-24 10:08:55,626 INFO Session:1495 - Skipping SecretBlock 2024-06-24 10:08:55,626 INFO Session:1467 - Received LicenseVersion: 0 2024-06-24 10:08:55,626 DEBUG TokenProvider:68 - Token expired or not suitable, requesting again. {scopes: [playlist-read], oldToken: null} 2024-06-24 10:08:55,626 INFO Session:1457 - Received CountryCode: US 2024-06-24 10:08:55,629 TRACE MercuryClient:148 - Send Mercury request, seq: 1, uri: hm://keymaster/token/authenticated?scope=playlist-read&client_id=65b708073fc0480ea92a077233ca87bd&device_id=f98691d4969217ceac650b9595b694eee55bc45a, method: GET ... <snip some non-helpful logs> ... 2024-06-24 10:08:55,631 INFO Session:1495 - Skipping UnknownData_AllZeros 2024-06-24 10:08:55,631 INFO Session:1495 - Skipping LegacyWelcome 2024-06-24 10:08:55,631 TRACE MercuryClient:191 - Handling packet, cmd: MercuryEvent, seq: 6511323252852260864, flags: 1, parts: 1 2024-06-24 10:08:55,632 DEBUG MercuryClient:226 - Couldn't dispatch Mercury event {seq: 6511323252852260864, uri: hm://pusher/v1/connections/Zjk4NjkxZDQ5NjkyMTdjZWFjNjUwYjk1OTViNjk0ZWVlNTViYzQ1YStBUCt0Y3A6Ly9ndWUxLWFjY2Vzc3BvaW50LWMtbjVoaC5ndWUxLnNwb3RpZnkubmV0OjUwMTQrQTk1QzI3NjIzRTlCRkIyRkZCNzVBMzlEN0EzMjBBRTA0QzI1NzZDN0IxNzYzMEIzMzNGREU5RkU0QkVENzUzRA%3D%3D, code: 200, payload: []} 2024-06-24 10:08:55,667 DEBUG Session:1471 - Received 0x10: 42FBF47638046984A8B4A094D3CD0D02EB3FF5F3 2024-06-24 10:08:55,709 TRACE MercuryClient:191 - Handling packet, cmd: MercuryReq, seq: 1, flags: 1, parts: 2 2024-06-24 10:08:55,710 DEBUG TokenProvider:72 - Updated token successfully! {scopes: [playlist-read], newToken: StoredToken{expiresIn=3600, accessToken='BQDw6L...l8SU5Q', scopes=[playlist-read], timestamp=1719238135754}} 2024-06-24 10:08:55,714 INFO Session:364 - Authenticated as 1225120197! ``` and on re-connect - ``` 2024-06-24 10:11:05,619 WARN Session:1440 - Socket timed out. Reconnecting... 2024-06-24 10:11:05,624 TRACE Session:1500 - Session.Receiver stopped 2024-06-24 10:11:05,665 INFO ApResolver:99 - Loaded aps into pool: {accesspoint=[ap-gue1.spotify.com:4070, ap-gue1.spotify.com:443, ap-gue1.spotify.com:80, ap-guc3.spotify.com:4070, ap-gew1.spotify.com:443, ap-gew4.spotify.com:80], dealer=[gue1-dealer.spotify.com:443, guc3-dealer.spotify.com:443, gew1-dealer.spotify.com:443, gew4-dealer.spotify.com:443], spclient=[gue1-spclient.spotify.com:443, guc3-spclient.spotify.com:443, gew1-spclient.spotify.com:443, gew4-spclient.spotify.com:443]} 2024-06-24 10:11:06,101 INFO Session:334 - Connected successfully! 2024-06-24 10:11:06,216 TRACE Session:1413 - Session.Receiver started 2024-06-24 10:11:06,216 INFO Session:736 - Re-authenticated as 1225120197! 2024-06-24 10:11:06,217 INFO Session:1495 - Skipping SecretBlock 2024-06-24 10:11:06,218 INFO Session:1467 - Received LicenseVersion: 0 2024-06-24 10:11:06,218 INFO Session:1457 - Received CountryCode: US ```
Author
Owner

@hamishfagg commented on GitHub (Aug 8, 2024):

FWIW I seem to have found a workaround which is to connect to spotify through a US VPN.

I'm not sure why connections from US IPs are treated differently, but it sure seems like they are.

<!-- gh-comment-id:2274667106 --> @hamishfagg commented on GitHub (Aug 8, 2024): FWIW I seem to have [found a workaround](https://github.com/librespot-org/librespot/issues/1292#issuecomment-2274657355) which is to connect to spotify through a US VPN. I'm not sure why connections from US IPs are treated differently, but it sure seems like they are.
Author
Owner

@JCBird1012 commented on GitHub (Aug 8, 2024):

Huh - that’s interesting. Good find!

I’ve got to get around to re-testing again to see if there’s change in behavior (since it’s been a while) + especially considering I’ve been in the US (and presumably connecting to US servers) this entire time.

This is a strange and elusive issue, it seems.

<!-- gh-comment-id:2274719681 --> @JCBird1012 commented on GitHub (Aug 8, 2024): Huh - that’s interesting. Good find! I’ve got to get around to re-testing again to see if there’s change in behavior (since it’s been a while) + especially considering I’ve been in the US (and presumably connecting to US servers) this entire time. This is a strange and elusive issue, it seems.
Author
Owner
<!-- gh-comment-id:2274951376 --> @jkp commented on GitHub (Aug 8, 2024): What is the algorithm used to choose an access point? Sent from [Proton Mail](https://proton.me/mail/home) for iOS On Thu, Aug 8, 2024 at 03:22, Jonathan Caicedo ***@***.***(mailto:On Thu, Aug 8, 2024 at 03:22, Jonathan Caicedo <<a href=)> wrote: > Huh - that’s interesting. Good find!I’ve got to get around to re-testing again to see if there’s change in behavior (since it’s been a while) + especially considering I’ve been in the US (and presumably connecting to US servers) this entire time.This is a strange and elusive issue, it seems.On Aug 7, 2024, at 21:00, Hamish Fagg ***@***.***> wrote: > FWIW I seem to have found a workaround which is to connect to spotify through a US VPN. > I'm not sure why connections from US IPs are treated differently, but it sure seems like they are. > > —Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you commented.Message ID: ***@***.***> > > — > Reply to this email directly, [view it on GitHub](https://github.com/librespot-org/librespot/issues/1151#issuecomment-2274719681), or [unsubscribe](https://github.com/notifications/unsubscribe-auth/AAAAIIJIJYNGJX2D5L6LFH3ZQLB5DAVCNFSM6AAAAAAW4BAMZWVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDENZUG4YTSNRYGE). > You are receiving this because you commented.Message ID: ***@***.***>
Author
Owner

@roderickvd commented on GitHub (Aug 8, 2024):

Spotify provides a couple based on geo DNS, in random order. We pick the first one that we can connect to.

<!-- gh-comment-id:2275048854 --> @roderickvd commented on GitHub (Aug 8, 2024): Spotify provides a couple based on geo DNS, in random order. We pick the first one that we can connect to.
Author
Owner

@jkp commented on GitHub (Aug 8, 2024):

Ok. It’s a hell of a long time since I had any exposure to this side of things at all but reading the previous comment it strikes me that the obvious thing to look for is whether the library connects to an AP in the wrong region. Years and years ago AP addresses were stored as a DHT in DNS - is it still the same way? (I imagine it must be supported to enable to older devices to run)

Sent from Proton Mail for iOS

On Thu, Aug 8, 2024 at 08:29, Roderick van Domburg @.***(mailto:On Thu, Aug 8, 2024 at 08:29, Roderick van Domburg < wrote:

Spotify provides a couple based on geo DNS, in random order. We pick the first one that we can connect to.


Reply to this email directly,
view it on GitHub, or unsubscribe.
You are receiving this because you commented.Message ID: @.***>

<!-- gh-comment-id:2275062102 --> @jkp commented on GitHub (Aug 8, 2024): Ok. It’s a hell of a long time since I had any exposure to this side of things at all but reading the previous comment it strikes me that the obvious thing to look for is whether the library connects to an AP in the wrong region. Years and years ago AP addresses were stored as a DHT in DNS - is it still the same way? (I imagine it must be supported to enable to older devices to run) Sent from [Proton Mail](https://proton.me/mail/home) for iOS On Thu, Aug 8, 2024 at 08:29, Roderick van Domburg ***@***.***(mailto:On Thu, Aug 8, 2024 at 08:29, Roderick van Domburg <<a href=)> wrote: > Spotify provides a couple based on geo DNS, in random order. We pick the first one that we can connect to. > > — > Reply to this email directly, [view it on GitHub](https://github.com/librespot-org/librespot/issues/1151#issuecomment-2275048854), or [unsubscribe](https://github.com/notifications/unsubscribe-auth/AAAAIIJCQL2WVD3ZL3YAETTZQMF3DAVCNFSM6AAAAAAW4BAMZWVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDENZVGA2DQOBVGQ). > You are receiving this because you commented.Message ID: ***@***.***>
Author
Owner

@roderickvd commented on GitHub (Aug 8, 2024):

DHT? I don’t know about that.

It just queries apresolve.spotify.com and relies on Spotify’s infrastructure to provide some hostnames, which it should based on geographic location. The library does not contain any intelligence beyond that.

I believe that even two equal host names will resolve to different IPs when resolved in different parts of the world.

See: https://github.com/librespot-org/librespot/blob/dev/core/src/apresolve.rs

<!-- gh-comment-id:2275104392 --> @roderickvd commented on GitHub (Aug 8, 2024): DHT? I don’t know about that. It just queries `apresolve.spotify.com` and relies on Spotify’s infrastructure to provide some hostnames, which it should based on geographic location. The library does not contain any intelligence beyond that. I believe that even two equal host names will resolve to different IPs when resolved in different parts of the world. See: https://github.com/librespot-org/librespot/blob/dev/core/src/apresolve.rs
Author
Owner

@roqueeee commented on GitHub (Sep 4, 2024):

I'm getting this error after switching to librespot 0.5.0-dev 2ea7436 yesterday because 0.4.2 stopped working. Never had any issues with 0.4.2 for almost two years.

This is an excerpt from my logs. It appears that librespot reconnects to the AP succesfully after Connection reset by peer (os error 104) but never resumes playback and the Spotify Connect connection to my PC or phone is also lost:

...
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] Session strong=4 weak=7
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] Invalidating session
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] new ChannelManager
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] drop Dispatch
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z ERROR librespot_core::session] Connection reset by peer (os error 104)
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z ERROR librespot_connect::spirc] remote update selected, but none received
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_connect::spirc] drop Spirc[0]
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z WARN  librespot] Spirc shut down unexpectedly
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] new Session
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_connect::spirc] new Spirc[1]
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] new MercuryManager
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] new ApResolver
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::http_client] Requesting https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_playback::player] command=SetSession
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] drop Session
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop ApResolver
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop AudioKeyManager
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop ChannelManager
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop MercuryManager
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop SpClient
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop TokenProvider
Sep 04 11:06:37 pi1 librespot[1721]: [2024-09-04T09:06:37Z INFO  librespot_core::session] Connecting to AP "ap2-gew4.spotify.com:4070"
Sep 04 11:06:37 pi1 librespot[1721]: [2024-09-04T09:06:37Z INFO  librespot_core::session] Authenticated as "xyz" !
...

I can manually reconnect and resume playback after this error without having to restart the service. So the AP reconnection at least seems to be successful.

<!-- gh-comment-id:2328375931 --> @roqueeee commented on GitHub (Sep 4, 2024): I'm getting this error after switching to `librespot 0.5.0-dev 2ea7436` yesterday because `0.4.2` [stopped working](https://github.com/librespot-org/librespot/issues/1322). Never had any issues with `0.4.2` for almost two years. This is an excerpt from my logs. It appears that `librespot` reconnects to the AP succesfully after `Connection reset by peer (os error 104)` but never resumes playback and the Spotify Connect connection to my PC or phone is also lost: ``` ... Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] Session strong=4 weak=7 Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] Invalidating session Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] new ChannelManager Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] drop Dispatch Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z ERROR librespot_core::session] Connection reset by peer (os error 104) Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z ERROR librespot_connect::spirc] remote update selected, but none received Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_connect::spirc] drop Spirc[0] Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z WARN librespot] Spirc shut down unexpectedly Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] new Session Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_connect::spirc] new Spirc[1] Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] new MercuryManager Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] new ApResolver Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::http_client] Requesting https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_playback::player] command=SetSession Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] drop Session Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop ApResolver Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop AudioKeyManager Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop ChannelManager Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop MercuryManager Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop SpClient Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop TokenProvider Sep 04 11:06:37 pi1 librespot[1721]: [2024-09-04T09:06:37Z INFO librespot_core::session] Connecting to AP "ap2-gew4.spotify.com:4070" Sep 04 11:06:37 pi1 librespot[1721]: [2024-09-04T09:06:37Z INFO librespot_core::session] Authenticated as "xyz" ! ... ``` I can manually reconnect and resume playback after this error without having to restart the service. So the AP reconnection at least seems to be successful.
Author
Owner

@RSKriegs commented on GitHub (Sep 4, 2024):

I'm getting this error after switching to librespot 0.5.0-dev 2ea7436 yesterday because 0.4.2 stopped working. Never had any issues with 0.4.2 for almost two years.

This is an excerpt from my logs. It appears that librespot reconnects to the AP succesfully after Connection reset by peer (os error 104) but never resumes playback and the Spotify Connect connection to my PC or phone is also lost:

...
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] Session strong=4 weak=7
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] Invalidating session
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] new ChannelManager
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] drop Dispatch
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z ERROR librespot_core::session] Connection reset by peer (os error 104)
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z ERROR librespot_connect::spirc] remote update selected, but none received
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_connect::spirc] drop Spirc[0]
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z WARN  librespot] Spirc shut down unexpectedly
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] new Session
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_connect::spirc] new Spirc[1]
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] new MercuryManager
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] new ApResolver
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::http_client] Requesting https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_playback::player] command=SetSession
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] drop Session
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop ApResolver
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop AudioKeyManager
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop ChannelManager
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop MercuryManager
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop SpClient
Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop TokenProvider
Sep 04 11:06:37 pi1 librespot[1721]: [2024-09-04T09:06:37Z INFO  librespot_core::session] Connecting to AP "ap2-gew4.spotify.com:4070"
Sep 04 11:06:37 pi1 librespot[1721]: [2024-09-04T09:06:37Z INFO  librespot_core::session] Authenticated as "xyz" !
...

I can manually reconnect and resume playback after this error without having to restart the service. So the AP reconnection at least seems to be successful.

I also began to receive these after switching to Librespot dev from Raspotify, basing on older comments it seems to be expected. Raspotify manages to handle it by design, but it uses other fork and I am not sure if settings tweaks on compiled Librespot could fix it with current version. Would be happy to hear any other solutions.

<!-- gh-comment-id:2329749968 --> @RSKriegs commented on GitHub (Sep 4, 2024): > I'm getting this error after switching to `librespot 0.5.0-dev 2ea7436` yesterday because `0.4.2` [stopped working](https://github.com/librespot-org/librespot/issues/1322). Never had any issues with `0.4.2` for almost two years. > > This is an excerpt from my logs. It appears that `librespot` reconnects to the AP succesfully after `Connection reset by peer (os error 104)` but never resumes playback and the Spotify Connect connection to my PC or phone is also lost: > > ``` > ... > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] Session strong=4 weak=7 > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] Invalidating session > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] new ChannelManager > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] drop Dispatch > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z ERROR librespot_core::session] Connection reset by peer (os error 104) > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z ERROR librespot_connect::spirc] remote update selected, but none received > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_connect::spirc] drop Spirc[0] > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z WARN librespot] Spirc shut down unexpectedly > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] new Session > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_connect::spirc] new Spirc[1] > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] new MercuryManager > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] new ApResolver > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::http_client] Requesting https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_playback::player] command=SetSession > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot_core::session] drop Session > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop ApResolver > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop AudioKeyManager > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop ChannelManager > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop MercuryManager > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop SpClient > Sep 04 11:06:36 pi1 librespot[1721]: [2024-09-04T09:06:36Z DEBUG librespot::component] drop TokenProvider > Sep 04 11:06:37 pi1 librespot[1721]: [2024-09-04T09:06:37Z INFO librespot_core::session] Connecting to AP "ap2-gew4.spotify.com:4070" > Sep 04 11:06:37 pi1 librespot[1721]: [2024-09-04T09:06:37Z INFO librespot_core::session] Authenticated as "xyz" ! > ... > ``` > > I can manually reconnect and resume playback after this error without having to restart the service. So the AP reconnection at least seems to be successful. I also began to receive these after switching to Librespot dev from Raspotify, basing on older comments it seems to be expected. Raspotify manages to handle it by design, but it uses other fork and I am not sure if settings tweaks on compiled Librespot could fix it with current version. Would be happy to hear any other solutions.
Author
Owner

@noahhaon commented on GitHub (Sep 19, 2024):

Seeing this very frequently now on 0.5.0 during playback using Spotify Connect. Would be great if librespot had the option for resuming the session and playback like raspotify does, as this behavior makes automated usage of librespot quite flaky.

The AP I get typically is ap-gew4.spotify.com:4070 if that is of any benefit.

<!-- gh-comment-id:2360091426 --> @noahhaon commented on GitHub (Sep 19, 2024): Seeing this very frequently now on 0.5.0 during playback using Spotify Connect. Would be great if librespot had the option for resuming the session and playback like raspotify does, as this behavior makes automated usage of librespot quite flaky. The AP I get typically is `ap-gew4.spotify.com:4070` if that is of any benefit.
Author
Owner

@Eirikr70 commented on GitHub (Sep 29, 2024):

Same problem here. Disconnections happen several times an hour, with ap-gew1.spotify.com:443

<!-- gh-comment-id:2381402266 --> @Eirikr70 commented on GitHub (Sep 29, 2024): Same problem here. Disconnections happen several times an hour, with `ap-gew1.spotify.com:443`
Author
Owner

@star-glider commented on GitHub (Oct 2, 2024):

I'm now seeing this problem as well, almost certainly related to Raspotify's switch to this librespot source. It's pretty inconsistent, and I haven't been able to figure out any pattern to the disconnections. I'm running it on two devices: a RPi4 that's connected via Ethernet and a Zero 2W that's wireless; they behave similarly.

<!-- gh-comment-id:2389669775 --> @star-glider commented on GitHub (Oct 2, 2024): I'm now seeing this problem as well, almost certainly related to Raspotify's switch to this librespot source. It's pretty inconsistent, and I haven't been able to figure out any pattern to the disconnections. I'm running it on two devices: a RPi4 that's connected via Ethernet and a Zero 2W that's wireless; they behave similarly.
Author
Owner

@kingosticks commented on GitHub (Oct 2, 2024):

@roderickvd shall we close this issue and concentrate everyone at https://github.com/librespot-org/librespot/issues/1340

Edit. Oh, wow, it already is closed and yet people still post here over the more updated one. Let's lock it??

<!-- gh-comment-id:2389708754 --> @kingosticks commented on GitHub (Oct 2, 2024): @roderickvd shall we close this issue and concentrate everyone at https://github.com/librespot-org/librespot/issues/1340 Edit. Oh, wow, it already is closed and yet people *still* post here over the more updated one. Let's lock it??
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
starred/librespot#533
No description provided.