Librespot stops working when switching networks #1627
Description
Description
Switching networks does not fully reconnect, leaves librespot unusable.
Version
Tested with latest dev (84a3302 at the time of writing).
How to reproduce
Steps to reproduce the behavior in librespot e.g.
- Launch
librespotwith any flags you like - Make librespot the active device
- Start playback
- Switch networks, e.g. enable VPN, connect to a different WiFi, etc.
- Playback stops at latest after the current song, the librespot client disappears from the list of known devices after a while.
Log
full log
[2025-11-08T16:46:15Z INFO librespot] librespot 0.7.1 84a33021 (Built on 2025-11-08, Build ID: WAQRubnw, Profile: debug)
[2025-11-08T16:46:15Z TRACE librespot] Command line argument(s):
[2025-11-08T16:46:15Z TRACE librespot] verbose
[2025-11-08T16:46:15Z DEBUG librespot_core::session] new Session
[2025-11-08T16:46:15Z DEBUG librespot_discovery::server] Zeroconf server listening on 0.0.0.0:43669
[2025-11-08T16:46:15Z INFO librespot_playback::mixer::softmixer] Mixing with softvol and volume control: Log(60.0)
[2025-11-08T16:46:15Z DEBUG librespot_playback::player] new Player [0]
[2025-11-08T16:46:15Z INFO librespot_playback::convert] Converting with ditherer: tpdf
[2025-11-08T16:46:15Z INFO librespot_playback::audio_backend::rodio] Using Rodio sink with format S16 and cpal host: ALSA
[2025-11-08T16:46:15Z INFO librespot_playback::audio_backend::rodio] Using audio device: default
[2025-11-08T16:46:15Z DEBUG librespot_playback::audio_backend::rodio] Rodio sink was created
[2025-11-08T16:46:31Z DEBUG librespot_discovery::server] POST "/" {}
[2025-11-08T16:46:31Z DEBUG librespot_core::session] Shutdown: Invalidating session
[2025-11-08T16:46:31Z DEBUG librespot::component] new MercuryManager
[2025-11-08T16:46:31Z DEBUG librespot::component] new ChannelManager
[2025-11-08T16:46:31Z DEBUG librespot_core::session] new Session
[2025-11-08T16:46:31Z DEBUG librespot_playback::player] command=SetSession
[2025-11-08T16:46:31Z DEBUG librespot_core::session] drop Session
[2025-11-08T16:46:31Z DEBUG librespot_connect::spirc] new Spirc[0]
[2025-11-08T16:46:31Z DEBUG librespot::component] drop ChannelManager
[2025-11-08T16:46:31Z DEBUG librespot::component] drop MercuryManager
[2025-11-08T16:46:31Z DEBUG librespot::component] new DealerManager
[2025-11-08T16:46:31Z DEBUG librespot::component] new SpClient
[2025-11-08T16:46:31Z DEBUG librespot_core::spclient] Client token unavailable or expired, requesting new token.
[2025-11-08T16:46:31Z DEBUG librespot_core::http_client] Requesting https://clienttoken.spotify.com/v1/clienttoken
[2025-11-08T16:46:31Z DEBUG librespot_core::spclient] Received a granted token
[2025-11-08T16:46:31Z TRACE librespot_core::spclient] Got client token: GrantedTokenResponse { token: "token", expires_after_seconds: 1216800, refresh_after_seconds: 1209600, domains: [TokenDomain { domain: "spotify.com", special_fields: SpecialFields { unknown_fields: UnknownFields { fields: None }, cached_size: CachedSize { size: 0 } } }, TokenDomain { domain: "spotify.net", special_fields: SpecialFields { unknown_fields: UnknownFields { fields: None }, cached_size: CachedSize { size: 0 } } }], special_fields: SpecialFields { unknown_fields: UnknownFields { fields: None }, cached_size: CachedSize { size: 0 } } }
[2025-11-08T16:46:31Z DEBUG librespot::component] new ApResolver
[2025-11-08T16:46:31Z DEBUG librespot_core::http_client] Requesting https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient
[2025-11-08T16:46:31Z INFO librespot_core::session] Connecting to AP "ap-gew4.spotify.com:4070"
[2025-11-08T16:46:31Z DEBUG librespot_core::connection] Connection to AP established.
[2025-11-08T16:46:31Z DEBUG librespot_core::connection] Authenticating with AP using AUTHENTICATION_STORED_SPOTIFY_CREDENTIALS
[2025-11-08T16:46:32Z INFO librespot_core::session] Authenticated as 'user' !
[2025-11-08T16:46:32Z DEBUG librespot::component] new Login5Manager
[2025-11-08T16:46:32Z DEBUG librespot_core::http_client] Requesting https://login5.spotify.com/v3/login
[2025-11-08T16:46:32Z TRACE librespot_core::session] Received Ping
[2025-11-08T16:46:32Z TRACE librespot_core::session] keep-alive state: PendingPong, timeout in 60.0
[2025-11-08T16:46:32Z DEBUG librespot_core::session] Session strong=5 weak=6
[2025-11-08T16:46:32Z INFO librespot_core::session] Country: "DE"
[2025-11-08T16:46:32Z TRACE librespot_core::session] Received product info: { removed 102 lines of product information }
[2025-11-08T16:46:32Z DEBUG librespot::component] new MercuryManager
[2025-11-08T16:46:32Z TRACE librespot_core::mercury] mercury response <hm://pusher/v1/connections/N2MyOGFiOGE1Yzk1MTJlNDI2NmFjN2NiNzU2MzEyYzgyZWU0M2Q3ZStBUCt0Y3A6Ly8wYWIxNTBmMC5pcC5nZXc0LnNwb3RpZnkubmV0OjUwMzArQ0E2QzExN0VFOTVGRTgzMzNCM0IxMTc0OTQwMEI5OEFCRTQ4OEY3RTAyRTYwMjdERkYxQjY5MDQ4MTQ1QzExRQ%3D%3D> is handled by dealer
[2025-11-08T16:46:32Z TRACE librespot_core::login5] Got auth token: Token { access_token: "BQCtfMiag93erqUtWF_8bAwp7rMzMthKV7p7YtG8hfvzQdnnMZUwI_MapxxPEeCRjE6QWFKlr5AyC3rivZ8EKHBHnIp5EMc8AC7dv0EBOelvlTFbC3N77gXzjcclMTUjQs0gAQGo4ZfjGxeYG-BWVJn_vd0ca60KXnWkImE8K-wmwS3M8eAIaVfaeC1q8s-OD85U3ZiBk9J5R463ju9gooVXyfFnXgAPNL2aJtUKwxNLoQ3IxWLRHNGkEIHA0ODK_nKGvgOJrBoZctHaDHhQuYVjDDP3tO28hkxqjbsnGCtfNVft7QPO6_8mrxbnTg76cuQpzpsJMMINW8Lg0oxjvSe3oon7znAkdI32A0pox5EgkEzMwJRgq4gL2lPpfORxBDilMfxvacdOoNzuiaVvXwKZXwYKNQaK2edOJD5JXoFFOvzX", expires_in: 3600s, token_type: "Bearer", scopes: [], timestamp: SystemTime { tv_sec: 1762620392, tv_nsec: 137459906 } }
[2025-11-08T16:46:32Z DEBUG librespot_connect::spirc] SpircTask::set_volume(32767)
[2025-11-08T16:46:32Z DEBUG librespot_playback::mixer::mappings] Input volume 32767 mapped to: 3.16%
[2025-11-08T16:46:32Z DEBUG librespot_playback::player] command=AddEventSender
[2025-11-08T16:46:32Z DEBUG librespot_core::dealer::manager] Launching dealer
[2025-11-08T16:46:32Z TRACE librespot_core::dealer] Sent ping
[2025-11-08T16:46:32Z TRACE librespot_connect::spirc] Received connection ID update: "NTI0NjU0YTUtZGE0OS00MjVjLTg1YWYtY2FmZjJiZWI3ZmU5K2RlYWxlcit0Y3A6Ly8wYWIxNTA2MS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArOUExQkQzRTM2RUIwMkI4QURFQkQ5RTRFN0RCMjQyNDk3MEY5Q0VDQTk4QkVEODU3QTQ5OURERDUxQ0UzQkZGOA=="
[2025-11-08T16:46:32Z INFO librespot_core::spclient] Resolved "gew4-spclient.spotify.com:443" as spclient access point
[2025-11-08T16:46:32Z DEBUG librespot_core::http_client] Requesting https://gew4-spclient.spotify.com:443/connect-state/v1/devices/7c28ab8a5c9512e4266ac7cb756312c82ee43d7e?product=0&country=DE&salt=1644674121
[2025-11-08T16:46:32Z TRACE librespot_core::dealer] Received pong
[2025-11-08T16:46:32Z TRACE librespot_core::dealer] dealer request hm://connect-state/v1/player/command
[2025-11-08T16:46:32Z TRACE librespot_core::dealer::protocol] message was sent with gzip encoding
[2025-11-08T16:46:32Z TRACE librespot_core::dealer::protocol] websocket request: Object {
"command": Object {
"data": String("Cm4IABAAGAAqCgoDamFtEgNvZmYqCQoFbWVkaWESACobChNjb250ZXh0X2VuaGFuY2VtZW50EgROT05FKhsKE2NvbnRleHRfZW5oYW5jZW1lbnQSBE5PTkUqCgoDamFtEgNvZmYqCQoFbWVkaWESABLWBwjS0fKipjMQ4rgRGQAAAAAAAPA/IAAqvQcKABIgMzMzOTMxMzEzMDMzMzU2MjYxMzA2MjM5MzA2NTM1NjQaEDPRx6w+A0RDtOWmo9R0jDwiNwoTYXNzb2NpYXRlZF92aWRlb19pZBIgZTRkYTRiOTllNWNhNDhjZmE4MDAzNTA5NTQyODk5NzkiEQoFdGl0bGUSCEdsZW53b29kIhkKCGFkZGVkX2F0Eg0xNzYyNTE2NTE4MTUwIioKIGFjdGlvbnMuc2tpcHBpbmdfcHJldl9wYXN0X3RyYWNrEgZyZXN1bWUiMwoKYXJ0aXN0X3VyaRIlc3BvdGlmeTphcnRpc3Q6NnZYWW95OG91UlZpYjMwMnp4YXhGRiI1CgplbnRpdHlfdXJpEidzcG90aWZ5OnBsYXlsaXN0OjM3aTlkUVpGMURaMDZldk8zUUFaS0ciDgoJaXRlcmF0aW9uEgEwIkkKD2ltYWdlX2xhcmdlX3VybBI2c3BvdGlmeTppbWFnZTphYjY3NjE2ZDAwMDBiMjczNTQ2NTFjMzUxYmYzMDlkNjgwOTBlNzFmIjEKCWFsYnVtX3VyaRIkc3BvdGlmeTphbGJ1bTowN3k4eTNDU0ZUcTQ4SHdlanJUZEd3Ih4KFG1lZGlhLnN0YXJ0X3Bvc2l0aW9uEgYyODMwNzQiSQoPaW1hZ2Vfc21hbGxfdXJsEjZzcG90aWZ5OmltYWdlOmFiNjc2MTZkMDAwMDQ4NTE1NDY1MWMzNTFiZjMwOWQ2ODA5MGU3MWYiNgoLY29udGV4dF91cmkSJ3Nwb3RpZnk6cGxheWxpc3Q6MzdpOWRRWkYxRFowNmV2TzNRQVpLRyJKChBpbWFnZV94bGFyZ2VfdXJsEjZzcG90aWZ5OmltYWdlOmFiNjc2MTZkMDAwMGIyNzM1NDY1MWMzNTFiZjMwOWQ2ODA5MGU3MWYiKgogYWN0aW9ucy5za2lwcGluZ19uZXh0X3Bhc3RfdHJhY2sSBnJlc3VtZSIPCgp2aWV3X2luZGV4EgEwIjcKC2RlY2lzaW9uX2lkEihzc3B+MDY0MzE3ZTQxZDgxZDM4YzA4YzcwYzA5MjJjZTI4YWVlYmRhIjcKC2FsYnVtX3RpdGxlEihJIEZlZWwgVGhlIEV2ZXJibGFjayBGZXN0ZXJpbmcgV2l0aGluIE1lIhUKDHRyYWNrX3BsYXllchIFYXVkaW8iQwoJaW1hZ2VfdXJsEjZzcG90aWZ5OmltYWdlOmFiNjc2MTZkMDAwMDFlMDI1NDY1MWMzNTFiZjMwOWQ2ODA5MGU3MWYa1wUKUwoIcGxheWxpc3QSLnhwdWktc25hcHNob3RfMjAyNS0xMC0wNl8xNzU5NzU1MTE2ODA5XzNiZTUzYWYaACIAKgZzZWFyY2gyADoHY29ubmVjdEIAEr8ECidzcG90aWZ5OnBsYXlsaXN0OjM3aTlkUVpGMURaMDZldk8zUUFaS0cSMWNvbnRleHQ6Ly9zcG90aWZ5OnBsYXlsaXN0OjM3aTlkUVpGMURaMDZldk8zUUFaS0caOgoOY29ycmVsYXRpb24taWQSKHNzcH4wNjQzMTdlNDFkY2ZmODk0ZTcxNmQyYWI1YWI2ZjkxYjA1OWYaLwoYY29udGV4dF9sb25nX2Rlc2NyaXB0aW9uEhNUaGlzIElzIExvcm5hIFNob3JlGh4KEGZvcm1hdF9saXN0X3R5cGUSCmFydGlzdHNldHMaKgoTY29udGV4dF9kZXNjcmlwdGlvbhITVGhpcyBJcyBMb3JuYSBTaG9yZRo2ChxwbGF5bGlzdF92b2xhdGlsZV9jb250ZXh0X2lkEhYycVdDMU1idW1TU3RuVGFsM0p2UGlYGjYKCnJlcXVlc3RfaWQSKHNzcH4wNjQzMTdlNDFkY2ZmODk0ZTcxNmQyYWI1YWI2ZjkxYjA1OWYaGQoQZW5oYW5jZWRfY29udGV4dBIFZmFsc2UaDQoJaW1hZ2VfdXJsEgAaHwoZcGxheWxpc3RfbnVtYmVyX29mX3RyYWNrcxICNDUaIAobcGxheWxpc3RfbnVtYmVyX29mX2VwaXNvZGVzEgEwGi0KCWFydGlzdEdpZBIgZDYxNTBhYjZkYTBjNDQ1NjhkMDA2OTlmZmI0MGU2N2IaGAoNY29udGV4dF9vd25lchIHc3BvdGlmeSIAMAEaIDMzMzkzMTMxMzAzMzM1NjI2MTMwNjIzOTMwNjUzNTY0IgAqADIAShYxSWRHZm80alBVemxsZVRJaFBnTVltIgIQADoCCgA="),
"endpoint": String("transfer"),
"from_device_identifier": String("53c06aa4ae7136661dc941a551e6ca3c8f4374d8"),
"logging_params": Object {
"command_id": String("b3e6b17e45302ec1292ccaf884581163"),
},
"options": Object {
"license": String("premium"),
"restore_paused": String("restore"),
"restore_position": String("extrapolate"),
"restore_track": String("always_play_something"),
"retain_session": String("do_not_retain"),
},
},
"message_id": Number(1683801894),
"play_on_secondary_stream": Null,
"sent_by_device_id": String("53c06aa4ae7136661dc941a551e6ca3c8f4374d8"),
"target_alias_id": Null,
}
[2025-11-08T16:46:32Z DEBUG librespot_connect::spirc] successfully put connect state for 7c28ab8a5c9512e4266ac7cb756312c82ee43d7e with connection-id NTI0NjU0YTUtZGE0OS00MjVjLTg1YWYtY2FmZjJiZWI3ZmU5K2RlYWxlcit0Y3A6Ly8wYWIxNTA2MS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArOUExQkQzRTM2RUIwMkI4QURFQkQ5RTRFN0RCMjQyNDk3MEY5Q0VDQTk4QkVEODU3QTQ5OURERDUxQ0UzQkZGOA==
[2025-11-08T16:46:32Z INFO librespot_connect::spirc] active device is <53c06aa4ae7136661dc941a551e6ca3c8f4374d8> with session <1IdGfo4jPUzlleTIhPgMYm>
[2025-11-08T16:46:32Z DEBUG librespot_connect::spirc] handling: 'endpoint: transfer' from 53c06aa4ae7136661dc941a551e6ca3c8f4374d8
[2025-11-08T16:46:32Z WARN librespot_connect::state::context] couldn't load context info because: context is not available. type: Default
[2025-11-08T16:46:32Z DEBUG librespot_connect::state::transfer] transfer track was the current track
[2025-11-08T16:46:32Z DEBUG librespot_connect::spirc] found initial track <spotify:track:1zMtEW4SE5s3VqrmTicJaY>
[2025-11-08T16:46:32Z TRACE librespot_connect::context_resolver] added spotify:playlist:37i9dQZF1DZ06evO3QAZKG to resolver queue
[2025-11-08T16:46:32Z TRACE librespot_connect::state::transfer] shuffle_seed: <None> (spotify), <None> (own)
[2025-11-08T16:46:32Z DEBUG librespot_playback::player] command=EmitSessionConnectedEvent("NTI0NjU0YTUtZGE0OS00MjVjLTg1YWYtY2FmZjJiZWI3ZmU5K2RlYWxlcit0Y3A6Ly8wYWIxNTA2MS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArOUExQkQzRTM2RUIwMkI4QURFQkQ5RTRFN0RCMjQyNDk3MEY5Q0VDQTk4QkVEODU3QTQ5OURERDUxQ0UzQkZGOA==", "user")
[2025-11-08T16:46:32Z DEBUG librespot_connect::state] updated connect play status playing: true, paused: false, buffering: true
[2025-11-08T16:46:32Z DEBUG librespot_playback::player] command=EmitSessionClientChangedEvent("65b708073fc0480ea92a077233ca87bd", "", "", "")
[2025-11-08T16:46:32Z DEBUG librespot_connect::state] updated connect play status playing: true, paused: false, buffering: true
[2025-11-08T16:46:32Z DEBUG librespot_playback::player] command=EmitVolumeChangedEvent(32767)
[2025-11-08T16:46:32Z DEBUG librespot_playback::player] command=EmitAutoPlayChangedEvent(false)
[2025-11-08T16:46:32Z DEBUG librespot_playback::player] command=EmitFilterExplicitContentChangedEvent(false)
[2025-11-08T16:46:32Z DEBUG librespot_connect::state] update position to 4:52 at 16:46:32.511
[2025-11-08T16:46:32Z DEBUG librespot_playback::player] command=EmitShuffleChangedEvent(false)
[2025-11-08T16:46:32Z DEBUG librespot_playback::player] command=EmitRepeatChangedEvent(false, false)
[2025-11-08T16:46:32Z DEBUG librespot_playback::player] command=Load(SpotifyUri("spotify:track:1zMtEW4SE5s3VqrmTicJaY"), true, 292815)
[2025-11-08T16:46:32Z DEBUG librespot_core::http_client] Requesting https://gew4-spclient.spotify.com:443/connect-state/v1/devices/7c28ab8a5c9512e4266ac7cb756312c82ee43d7e?product=0&country=DE&salt=2452660299
[2025-11-08T16:46:32Z DEBUG librespot_core::http_client] Requesting https://gew4-spclient.spotify.com:443/extended-metadata/v0/extended-metadata?product=0&country=DE&salt=529895047
[2025-11-08T16:46:32Z TRACE librespot_metadata] Received metadata: Track { remove 824 lines of track metadata }
[2025-11-08T16:46:32Z INFO librespot_playback::player] Loading <Glenwood> with Spotify URI <spotify:track:1zMtEW4SE5s3VqrmTicJaY>
[2025-11-08T16:46:32Z DEBUG librespot_audio::fetch] Downloading file f84ab518aa89ffbf06f18d8f4bf100bc50470cc7
[2025-11-08T16:46:32Z DEBUG librespot_core::http_client] Requesting https://gew4-spclient.spotify.com:443/storage-resolve/files/audio/interactive/f84ab518aa89ffbf06f18d8f4bf100bc50470cc7?product=0&country=DE&salt=2449211065
[2025-11-08T16:46:32Z TRACE librespot_core::cdn_url] Resolved CDN storage: CdnUrl { removed 34 lines of CDN url data }
[2025-11-08T16:46:32Z TRACE librespot_audio::fetch] Streaming from https://audio-fa.scdn.co/audio/f84ab518aa89ffbf06f18d8f4bf100bc50470cc7?1762706792_Fi5JpweqKXyRVna4dpAzn2oV2foHhe677Fdj-I04BS4=
[2025-11-08T16:46:32Z DEBUG librespot::component] new AudioKeyManager
[2025-11-08T16:46:32Z TRACE librespot_connect::spirc] ==> LoadingPlay
[2025-11-08T16:46:32Z DEBUG librespot_core::dealer::manager] replying to ws request: Success
[2025-11-08T16:46:32Z TRACE librespot_audio::fetch::receive] Time to first byte now estimated as: 18 ms
[2025-11-08T16:46:32Z DEBUG librespot_core::dealer] No subscriber for msg.uri: social-connect/v2/broadcast_status_update
[2025-11-08T16:46:32Z DEBUG librespot_core::mercury] unknown subscription uri=social-connect/v2/broadcast_status_update
[2025-11-08T16:46:32Z TRACE librespot_core::mercury] response pushed over Mercury: MercuryResponse { uri: "social-connect/v2/broadcast_status_update", status_code: 200, payload: [[123, 34, 100, 101, 118, 105, 99, 101, 66, 114, 111, 97, 100, 99, 97, 115, 116, 83, 116, 97, 116, 117, 115, 34, 58, 123, 34, 116, 105, 109, 101, 115, 116, 97, 109, 112, 34, 58, 34, 49, 55, 54, 50, 54, 50, 48, 51, 57, 50, 55, 48, 55, 34, 44, 34, 98, 114, 111, 97, 100, 99, 97, 115, 116, 95, 115, 116, 97, 116, 117, 115, 34, 58, 34, 66, 82, 79, 65, 68, 67, 65, 83, 84, 95, 79, 78, 34, 44, 34, 100, 101, 118, 105, 99, 101, 95, 105, 100, 34, 58, 34, 55, 99, 50, 56, 97, 98, 56, 97, 53, 99, 57, 53, 49, 50, 101, 52, 50, 54, 54, 97, 99, 55, 99, 98, 55, 53, 54, 51, 49, 50, 99, 56, 50, 101, 101, 52, 51, 100, 55, 101, 34, 44, 34, 109, 100, 110, 115, 95, 116, 111, 107, 101, 110, 34, 58, 123, 34, 116, 111, 107, 101, 110, 34, 58, 34, 52, 79, 112, 56, 101, 117, 98, 71, 48, 67, 86, 105, 117, 107, 57, 69, 49, 85, 105, 99, 109, 76, 34, 125, 44, 34, 115, 111, 99, 105, 97, 108, 95, 114, 97, 100, 97, 114, 95, 116, 111, 107, 101, 110, 34, 58, 123, 34, 116, 111, 107, 101, 110, 34, 58, 34, 79, 65, 74, 87, 66, 79, 80, 49, 76, 69, 52, 65, 75, 88, 89, 80, 89, 51, 67, 83, 34, 125, 44, 34, 108, 105, 110, 107, 95, 116, 111, 107, 101, 110, 34, 58, 123, 34, 116, 111, 107, 101, 110, 34, 58, 34, 53, 76, 98, 108, 89, 76, 81, 103, 113, 81, 54, 51, 77, 119, 57, 76, 109, 75, 76, 102, 119, 79, 34, 125, 125, 125]] }
[2025-11-08T16:46:32Z DEBUG librespot_core::session] could not dispatch command: Service unavailable { error handling Mercury response: MercuryResponse { uri: "social-connect/v2/broadcast_status_update", status_code: 200, payload: [[123, 34, 100, 101, 118, 105, 99, 101, 66, 114, 111, 97, 100, 99, 97, 115, 116, 83, 116, 97, 116, 117, 115, 34, 58, 123, 34, 116, 105, 109, 101, 115, 116, 97, 109, 112, 34, 58, 34, 49, 55, 54, 50, 54, 50, 48, 51, 57, 50, 55, 48, 55, 34, 44, 34, 98, 114, 111, 97, 100, 99, 97, 115, 116, 95, 115, 116, 97, 116, 117, 115, 34, 58, 34, 66, 82, 79, 65, 68, 67, 65, 83, 84, 95, 79, 78, 34, 44, 34, 100, 101, 118, 105, 99, 101, 95, 105, 100, 34, 58, 34, 55, 99, 50, 56, 97, 98, 56, 97, 53, 99, 57, 53, 49, 50, 101, 52, 50, 54, 54, 97, 99, 55, 99, 98, 55, 53, 54, 51, 49, 50, 99, 56, 50, 101, 101, 52, 51, 100, 55, 101, 34, 44, 34, 109, 100, 110, 115, 95, 116, 111, 107, 101, 110, 34, 58, 123, 34, 116, 111, 107, 101, 110, 34, 58, 34, 52, 79, 112, 56, 101, 117, 98, 71, 48, 67, 86, 105, 117, 107, 57, 69, 49, 85, 105, 99, 109, 76, 34, 125, 44, 34, 115, 111, 99, 105, 97, 108, 95, 114, 97, 100, 97, 114, 95, 116, 111, 107, 101, 110, 34, 58, 123, 34, 116, 111, 107, 101, 110, 34, 58, 34, 79, 65, 74, 87, 66, 79, 80, 49, 76, 69, 52, 65, 75, 88, 89, 80, 89, 51, 67, 83, 34, 125, 44, 34, 108, 105, 110, 107, 95, 116, 111, 107, 101, 110, 34, 58, 123, 34, 116, 111, 107, 101, 110, 34, 58, 34, 53, 76, 98, 108, 89, 76, 81, 103, 113, 81, 54, 51, 77, 119, 57, 76, 109, 75, 76, 102, 119, 79, 34, 125, 125, 125]] } }
[2025-11-08T16:46:32Z TRACE librespot_audio::fetch::receive] Throughput now estimated as: 2246 kbps
[2025-11-08T16:46:32Z INFO librespot_connect::spirc] session update: <Ok(NEW_SESSION)> for self, current session_id f30835c4521e4e5689d172083e666a5d, new session_id 1e5c9509270b22bdb733fb9310513bdf
[2025-11-08T16:46:32Z TRACE librespot_core::mercury] mercury response <social-connect/v2/session_update> is handled by dealer
[2025-11-08T16:46:32Z TRACE librespot_audio::fetch::receive] Time to first byte now estimated as: 14 ms
[2025-11-08T16:46:32Z TRACE librespot_audio::fetch::receive] Throughput now estimated as: 3050 kbps
[2025-11-08T16:46:32Z TRACE librespot_audio::fetch::receive] Time to first byte now estimated as: 16 ms
[2025-11-08T16:46:32Z TRACE librespot_audio::fetch::receive] Time to first byte now estimated as: 10 ms
[2025-11-08T16:46:32Z TRACE librespot_audio::fetch::receive] Throughput now estimated as: 3766 kbps
[2025-11-08T16:46:32Z INFO librespot_playback::player] <Glenwood> (403875 ms) loaded
[2025-11-08T16:46:32Z TRACE librespot_playback::player] == Starting sink ==
[2025-11-08T16:46:32Z TRACE librespot_connect::spirc] ==> Playing
[2025-11-08T16:46:33Z TRACE librespot_core::mercury] mercury response <social-connect/v2/session_update> is handled by dealer
[2025-11-08T16:46:33Z DEBUG librespot_connect::spirc] Received SessionUpdate::WIFI_BROADCAST_CHANGED
[2025-11-08T16:46:33Z DEBUG librespot_connect::state] updated connect play status playing: true, paused: false, buffering: false
[2025-11-08T16:46:33Z DEBUG librespot_connect::state] update position to 4:53 at 16:46:33.288
[2025-11-08T16:46:33Z DEBUG librespot_core::http_client] Requesting https://gew4-spclient.spotify.com:443/connect-state/v1/devices/7c28ab8a5c9512e4266ac7cb756312c82ee43d7e?product=0&country=DE&salt=4175298869
[2025-11-08T16:46:33Z DEBUG librespot_core::http_client] Requesting https://gew4-spclient.spotify.com:443/context-resolve/v1/spotify:playlist:37i9dQZF1DZ06evO3QAZKG
[2025-11-08T16:46:33Z DEBUG librespot_connect::spirc] handling next context Some("spotify:playlist:37i9dQZF1DZ06evO3QAZKG")
[2025-11-08T16:46:33Z DEBUG librespot_connect::state::context] updated context Default to <Some("spotify:playlist:37i9dQZF1DZ06evO3QAZKG")> (45 tracks)
[2025-11-08T16:46:33Z DEBUG librespot_connect::context_resolver] last item of type <Default>, finishing state setup
[2025-11-08T16:46:33Z DEBUG librespot_connect::state::transfer] active track is <spotify:track:1zMtEW4SE5s3VqrmTicJaY> with index Ok(0) in Default context, has 45 tracks
[2025-11-08T16:46:33Z DEBUG librespot_connect::state::transfer] setting up next and prev: index is at Some(0) while shuffle false
[2025-11-08T16:46:33Z DEBUG librespot_connect::state] reset_playback with active ctx <Default> fill_up ctx <Default>
[2025-11-08T16:46:33Z DEBUG librespot_connect::state::tracks] set track to: spotify:track:1zMtEW4SE5s3VqrmTicJaY at 0 of 45 tracks
[2025-11-08T16:46:33Z DEBUG librespot_connect::state::tracks] finished filling up next_tracks (44)
[2025-11-08T16:46:33Z DEBUG librespot_connect::state] updated connect play status playing: true, paused: false, buffering: false
[2025-11-08T16:46:33Z DEBUG librespot_connect::state] update position to 4:53 at 16:46:33.528
[2025-11-08T16:46:33Z DEBUG librespot_core::http_client] Requesting https://gew4-spclient.spotify.com:443/connect-state/v1/devices/7c28ab8a5c9512e4266ac7cb756312c82ee43d7e?product=0&country=DE&salt=2752552323
[2025-11-08T16:46:33Z TRACE librespot_audio::fetch::receive] Time to first byte now estimated as: 12 ms
[2025-11-08T16:46:33Z TRACE librespot_audio::fetch::receive] Throughput now estimated as: 3474 kbps
[2025-11-08T16:46:33Z TRACE librespot_audio::fetch::receive] Throughput now estimated as: 9489 kbps
[2025-11-08T16:46:34Z TRACE librespot_audio::fetch::receive] Throughput now estimated as: 12746 kbps
[2025-11-08T16:46:34Z TRACE librespot_audio::fetch::receive] Throughput now estimated as: 14113 kbps
[2025-11-08T16:46:34Z TRACE librespot_audio::fetch::receive] Throughput now estimated as: 16132 kbps
[2025-11-08T16:46:34Z TRACE librespot_audio::fetch::receive] Throughput now estimated as: 14503 kbps
[2025-11-08T16:46:34Z DEBUG librespot_audio::fetch] Downloading file f84ab518aa89ffbf06f18d8f4bf100bc50470cc7 complete
[2025-11-08T16:46:41Z TRACE librespot_core::dealer::protocol] message was sent with gzip encoding
[2025-11-08T16:46:41Z DEBUG librespot_connect::spirc] cluster update: Ok(DEVICES_DISAPPEARED) from 53c06aa4ae7136661dc941a551e6ca3c8f4374d8, active device: 7c28ab8a5c9512e4266ac7cb756312c82ee43d7e
[2025-11-08T16:46:41Z DEBUG librespot_connect::state] updated connect play status playing: true, paused: false, buffering: false
[2025-11-08T16:46:41Z DEBUG librespot_connect::state] update position to 5:01 at 16:46:41.822
[2025-11-08T16:46:41Z DEBUG librespot_core::http_client] Requesting https://gew4-spclient.spotify.com:443/connect-state/v1/devices/7c28ab8a5c9512e4266ac7cb756312c82ee43d7e?product=0&country=DE&salt=3391763423
[2025-11-08T16:47:02Z TRACE librespot_core::dealer] Sent ping
[2025-11-08T16:47:02Z TRACE librespot_core::dealer] Received pong
Network was switched to VPN here
[2025-11-08T16:47:32Z TRACE librespot_core::session] Sending Pong
[2025-11-08T16:47:32Z TRACE librespot_core::session] keep-alive state: ExpectingPongAck, timeout in 20.0
[2025-11-08T16:47:32Z TRACE librespot_core::dealer] Sent ping
[2025-11-08T16:47:35Z WARN librespot_core::dealer] Websocket peer does not respond.
[2025-11-08T16:47:35Z DEBUG librespot_core::dealer] Dropping receive task
[2025-11-08T16:47:35Z DEBUG librespot_core::dealer] Dropping send task
[2025-11-08T16:47:35Z TRACE librespot_connect::spirc] Received connection ID update: "YmUzZmQ2NGItMWJmOS00MTZiLWEzYzQtNzJjZWNiMDJiZjRjK2RlYWxlcit0Y3A6Ly8wYWIxNDA4MS5pcC5ndWUxLnNwb3RpZnkubmV0OjU3MDArMzc0NkFENDAxNzg5N0I0MURCQjg0OTU1MjYwRkE5MkZBQkU0OEUwMEM4MEE2QjZGRUYwMjQzM0I4RjkyREZENQ=="
[2025-11-08T16:47:35Z DEBUG librespot_core::http_client] Requesting https://gew4-spclient.spotify.com:443/connect-state/v1/devices/7c28ab8a5c9512e4266ac7cb756312c82ee43d7e?product=0&country=DE&salt=2429974455
[2025-11-08T16:47:35Z TRACE librespot_core::dealer] Sent ping
[2025-11-08T16:47:35Z TRACE librespot_core::dealer] Received pong
First time hitting C-c
^C[2025-11-08T16:47:51Z INFO librespot] Gracefully shutting down
[2025-11-08T16:47:51Z DEBUG librespot_discovery::server] Shutting down discovery server
[2025-11-08T16:47:51Z DEBUG librespot_discovery] Shutting down zeroconf responder
[2025-11-08T16:47:51Z DEBUG librespot_discovery::server] Discovery server stopped
[2025-11-08T16:47:51Z DEBUG librespot_discovery] Zeroconf responder stopped
[2025-11-08T16:47:52Z DEBUG librespot_core::session] Shutdown: Invalidating session
[2025-11-08T16:47:52Z DEBUG librespot::component] new ChannelManager
[2025-11-08T16:47:52Z DEBUG librespot_core::session] drop Dispatch
[2025-11-08T16:48:05Z TRACE librespot_core::dealer] Sent ping
[2025-11-08T16:48:05Z TRACE librespot_core::dealer] Received pong
[2025-11-08T16:48:35Z TRACE librespot_core::dealer] Sent ping
[2025-11-08T16:48:35Z TRACE librespot_core::dealer] Received pong
Second time hitting C-c
^C[2025-11-08T16:48:38Z DEBUG librespot_connect::spirc] drop Spirc[0]
[2025-11-08T16:48:38Z DEBUG librespot_playback::player] Shutting down player thread ...
[2025-11-08T16:48:38Z DEBUG librespot_playback::player] drop PlayerInternal[0]
[2025-11-08T16:48:38Z DEBUG librespot_playback::player] PlayerInternal thread finished.
[2025-11-08T16:48:38Z DEBUG librespot_core::session] drop Session
[2025-11-08T16:48:38Z DEBUG librespot::component] drop ApResolver
[2025-11-08T16:48:38Z DEBUG librespot::component] drop AudioKeyManager
[2025-11-08T16:48:38Z DEBUG librespot::component] drop ChannelManager
[2025-11-08T16:48:38Z DEBUG librespot::component] drop MercuryManager
[2025-11-08T16:48:38Z DEBUG librespot::component] drop DealerManager
[2025-11-08T16:48:38Z DEBUG librespot::component] drop SpClient
[2025-11-08T16:48:38Z DEBUG librespot::component] drop Login5Manager
Host (what you are running librespot on):
- OS: Linux
- Platform: x86_64
Additional context
I additionally noticed, that it seems to corrupt the inner state somehow as graceful shutdown doesn't work as intended anymore. In the logs you can see, that I had to hit ^C twice to finally get it to shutdown. Even after the first one the app continued to send pings and also playback continues. Furthermore, the official client still considers librespot to be the active client until the song ends or e.g. next is triggered.
I think, it's related to
[2025-11-08T16:47:52Z DEBUG librespot_core::session] drop Dispatch
and the TODO at
Line 932 in 84a3302
This might be the same issue as reported in #1492.