Issues Reconnecting with Discovery Mode
Description Reconnecting in discovery mode does not always work. There are two main scenarios:
- Transferring to and from a different Spotify Connect device.
- Switching from spotifyd device to main speakers then back to spotifyd.
Side note: This is in a different code area, but there is also an issue with relaunching spotifyd when using discovery mode credentials. It uses the credentials to recapture the same session, but spotifyd does not show up as the output speaker on Spotify clients.
If you try to connect at this point, a similar output loop to the one described below occurs. Likely offering an option to disable credential caching (or even just discovery credential caching) would be a good idea to make usage of the discovery mode easier. Is there already something in the works for disabling credential caching or should I make a feature request for this?
To Reproduce Either scenario boils down to the following:
- With no credentials cached, connect to spotifyd.
- Transfer to ANY other device (includes the device you started the connection from such as a phone).
- Try to transfer back
In either case, the connection will eventually error out by disconnecting from spotifyd without user intervention. If you don't do anything from here, you can still see session state changes, but you cannot play music. Attempts to reconnect again from here result in looping log error messages.
Expected behavior A user should be able to swap between devices at will without worrying about potential disconnects or session errors.
Using raspotify, this behavior is seamless. I also have credential caching off there. However, I cannot use raspotify for my use-case, as I need to rely on MPRIS.
Logs
I've filtered out any libmdns lines as they were particularly useless and clogged up the logs. If so desired, I can regenerate logs with these lines, but after looking into this a bit, I do not believe they are relevant. These logs also do not contain the aforementioned log loop, as triggering this loop makes it hard to tell what parts of the logs are relevant and worth sending.
[[37mINFO[0m spotifyd::config] Loading config from "/etc/spotifyd.conf"
[[37mDEBUG[0m spotifyd::config] No proxy specified
[[37mINFO[0m spotifyd::setup] Using software volume controller.
[[37mINFO[0m librespot_playback::mixer::softmixer] Mixing with softvol and volume control: Log(60.0)
[[37mINFO[0m spotifyd::setup] Starting zeroconf server to advertise on local network.
[[37mDEBUG[0m spotifyd::setup] Using device id 'f75050e4ada1cfe882a7f463ef4a20c1a3fe0e4a'
[[37mDEBUG[0m librespot_discovery::server] Zeroconf server listening on 0.0.0.0:42031
[[37mDEBUG[0m librespot_discovery::server] POST "/" {}
[[37mDEBUG[0m librespot_core::session] new Session
[[37mDEBUG[0m librespot_connect::spirc] new Spirc[0]
[[37mDEBUG[0m librespot::component] new DealerManager
[[37mDEBUG[0m librespot_playback::player] new Player [0]
[[37mINFO[0m librespot_playback::convert] Converting with ditherer: tpdf
[[37mINFO[0m librespot_playback::audio_backend::alsa] Using AlsaSink with format: S16
[[37mDEBUG[0m librespot::component] new SpClient
[[37mDEBUG[0m librespot_core::spclient] Client token unavailable or expired, requesting new token.
[[37mDEBUG[0m librespot_core::http_client] Requesting https://clienttoken.spotify.com/v1/clienttoken
[[37mDEBUG[0m librespot_core::spclient] Received a granted token
[[37mDEBUG[0m librespot::component] new ApResolver
[[37mDEBUG[0m librespot_core::http_client] Requesting https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient
[[37mINFO[0m librespot_core::session] Connecting to AP "ap-guc3.spotify.com:443"
[[37mDEBUG[0m librespot_core::connection] Connection to AP established.
[[37mDEBUG[0m librespot_core::connection] Authenticating with AP using AUTHENTICATION_STORED_SPOTIFY_CREDENTIALS
[[37mINFO[0m librespot_core::session] Authenticated as 'sz5c75x30yy1lc0nvqgzeahpw' !
[[37mDEBUG[0m librespot::component] new Login5Manager
[[37mDEBUG[0m librespot_core::session] Session strong=4 weak=6
[[37mDEBUG[0m librespot_core::http_client] Requesting https://login5.spotify.com/v3/login
[[37mINFO[0m librespot_core::session] Country: "US"
[[37mDEBUG[0m librespot::component] new MercuryManager
[[37mDEBUG[0m librespot_connect::spirc] SpircTask::set_volume(58981)
[[37mDEBUG[0m librespot_playback::mixer::mappings] Input volume 58981 mapped to: 50.12%
[[37mDEBUG[0m librespot_playback::player] command=AddEventSender
[[37mDEBUG[0m librespot_core::dealer::manager] Launching dealer
[[37mDEBUG[0m librespot_playback::player] command=AddEventSender
[[37mDEBUG[0m tungstenite::handshake::client] Client handshake done.
[[37mINFO[0m librespot_core::spclient] Resolved "guc3-spclient.spotify.com:443" as spclient access point
[[37mDEBUG[0m librespot_core::http_client] Requesting https://guc3-spclient.spotify.com:443/connect-state/v1/devices/f75050e4ada1cfe882a7f463ef4a20c1a3fe0e4a?product=0&country=US&salt=2281426203
[[37mDEBUG[0m librespot_connect::spirc] successfully put connect state for f75050e4ada1cfe882a7f463ef4a20c1a3fe0e4a with connection-id ZmU5MjdjOTktMjMxYi00MjZjLTg1ZjUtY2I0NzMyNTkwM2IwK2RlYWxlcit0Y3A6Ly8wYWIxNDhhOS5pcC5ndWMzLnNwb3RpZnkubmV0OjU3MDArM0M4NjEzQzc5NkM2MUFGOTUyNTZERjJDM0NCOTgzMUE1OTAzQ0U0QzAxRUE5RkIwRjBBM0I2NjVGMjlENDUxMw==
[[37mINFO[0m librespot_connect::spirc] active device is <dabf2172feb9bc5d067c4d156e8c02a6a7eed0ba> with session <439731eb-c159-459a-aaeb-a6c4c1358fe9>
[[37mDEBUG[0m librespot_connect::spirc] handling: 'endpoint: transfer' from 6fbfa02db9fbc3241eab2f605830fb630aba8b0e
[[33mWARN[0m librespot_connect::state::context] couldn't load context info because: context is not available. type: Default
[[37mDEBUG[0m librespot_connect::state::transfer] transfer track was the current track
[[37mDEBUG[0m librespot_connect::spirc] found initial track <spotify:track:2pZkX6yyPuF8UdRqGXsDci>
[[37mDEBUG[0m librespot_playback::player] command=EmitSessionConnectedEvent("ZmU5MjdjOTktMjMxYi00MjZjLTg1ZjUtY2I0NzMyNTkwM2IwK2RlYWxlcit0Y3A6Ly8wYWIxNDhhOS5pcC5ndWMzLnNwb3RpZnkubmV0OjU3MDArM0M4NjEzQzc5NkM2MUFGOTUyNTZERjJDM0NCOTgzMUE1OTAzQ0U0QzAxRUE5RkIwRjBBM0I2NjVGMjlENDUxMw==", "sz5c75x30yy1lc0nvqgzeahpw")
[[37mDEBUG[0m librespot_connect::state] updated connect play status playing: true, paused: true, buffering: true
[[37mDEBUG[0m librespot_connect::state] updated connect play status playing: true, paused: true, buffering: true
[[37mDEBUG[0m librespot_playback::player] command=EmitSessionClientChangedEvent("65b708073fc0480ea92a077233ca87bd", "", "", "")
[[37mDEBUG[0m librespot_playback::player] command=EmitVolumeChangedEvent(58981)
[[37mDEBUG[0m librespot_playback::player] command=EmitAutoPlayChangedEvent(false)
[[37mDEBUG[0m librespot_core::http_client] Requesting https://guc3-spclient.spotify.com:443/connect-state/v1/devices/f75050e4ada1cfe882a7f463ef4a20c1a3fe0e4a?product=0&country=US&salt=1041073160
[[37mDEBUG[0m librespot_playback::player] command=EmitFilterExplicitContentChangedEvent(false)
[[37mDEBUG[0m librespot_playback::player] command=EmitShuffleChangedEvent(false)
[[37mDEBUG[0m librespot_playback::player] command=EmitRepeatChangedEvent(false, false)
[[37mDEBUG[0m librespot_playback::player] command=Load(SpotifyUri("spotify:track:2pZkX6yyPuF8UdRqGXsDci"), false, 67369)
[[37mDEBUG[0m librespot_core::http_client] Requesting https://guc3-spclient.spotify.com:443/extended-metadata/v0/extended-metadata?product=0&country=US&salt=2508493486
[[37mDEBUG[0m spotifyd::dbus_mpris] handling event SessionClientChanged { client_id: "65b708073fc0480ea92a077233ca87bd", client_name: "", client_brand_name: "", client_model_name: "" }
[[37mDEBUG[0m spotifyd::dbus_mpris] handling event VolumeChanged { volume: 58981 }
[[37mDEBUG[0m spotifyd::dbus_mpris] handling event AutoPlayChanged { auto_play: false }
[[37mDEBUG[0m spotifyd::dbus_mpris] handling event FilterExplicitContentChanged { filter: false }
[[37mDEBUG[0m spotifyd::dbus_mpris] handling event ShuffleChanged { shuffle: false }
[[37mDEBUG[0m spotifyd::dbus_mpris] handling event RepeatChanged { context: false, track: false }
[[37mDEBUG[0m spotifyd::dbus_mpris] handling event PlayRequestIdChanged { play_request_id: 0 }
[[37mDEBUG[0m spotifyd::dbus_mpris] handling event Loading { play_request_id: 0, track_id: SpotifyUri("spotify:track:2pZkX6yyPuF8UdRqGXsDci"), position_ms: 67369 }
[[37mINFO[0m librespot_playback::player] Loading <Ganja Tape> with Spotify URI <spotify:track:2pZkX6yyPuF8UdRqGXsDci>
[[37mDEBUG[0m librespot_audio::fetch] Downloading file 2a440d87c277316c01f02168302742e117a9c736
[[37mDEBUG[0m librespot_core::http_client] Requesting https://guc3-spclient.spotify.com:443/storage-resolve/files/audio/interactive/2a440d87c277316c01f02168302742e117a9c736?product=0&country=US&salt=4000116564
[[37mDEBUG[0m librespot_core::dealer] No subscriber for msg.uri: social-connect/v2/broadcast_status_update
[[37mDEBUG[0m librespot_core::mercury] unknown subscription uri=social-connect/v2/broadcast_status_update
[[37mDEBUG[0m 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, 55, 52, 55, 57, 55, 54, 54, 55, 53, 57, 53, 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, 102, 55, 53, 48, 53, 48, 101, 52, 97, 100, 97, 49, 99, 102, 101, 56, 56, 50, 97, 55, 102, 52, 54, 51, 101, 102, 52, 97, 50, 48, 99, 49, 97, 51, 102, 101, 48, 101, 52, 97, 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, 55, 111, 81, 77, 56, 70, 113, 82, 54, 48, 54, 75, 70, 115, 103, 82, 49, 122, 117, 122, 67, 65, 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, 74, 85, 49, 82, 76, 81, 68, 72, 72, 48, 90, 56, 71, 72, 69, 85, 71, 86, 69, 87, 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, 55, 97, 79, 102, 68, 74, 104, 112, 78, 55, 89, 104, 49, 102, 118, 115, 49, 103, 90, 57, 101, 103, 34, 125, 44, 34, 100, 101, 118, 105, 99, 101, 95, 116, 121, 112, 101, 34, 58, 34, 83, 80, 69, 65, 75, 69, 82, 34, 125, 125]] } }
[[37mDEBUG[0m librespot::component] new AudioKeyManager
[[37mDEBUG[0m librespot_core::dealer::manager] replying to ws request: Success
[[37mDEBUG[0m librespot_core::http_client] Requesting https://guc3-spclient.spotify.com:443/context-resolve/v1/spotify:playlist:3CsqNkt4RuyYKqHsecxNmO
[[37mDEBUG[0m librespot_connect::spirc] Received SessionUpdate::WIFI_BROADCAST_CHANGED
[[37mDEBUG[0m librespot_core::http_client] Requesting https://guc3-spclient.spotify.com:443/context-resolve/v1/spotify:playlist:3CsqNkt4RuyYKqHsecxNmO
[[37mDEBUG[0m symphonia_core::probe] found a possible format marker within [4f, 67, 67, 53, 0, 2, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] @ 0+2 bytes.
[[37mDEBUG[0m symphonia_core::probe] found the format marker [4f, 67, 67, 53] @ 0+2 bytes.
[[37mDEBUG[0m symphonia_format_ogg::page] grow page buffer to 8192 bytes
[[37mINFO[0m symphonia_format_ogg::demuxer] starting new physical stream
[[37mINFO[0m symphonia_format_ogg::demuxer] selected vorbis mapper for stream with serial=0x0
[[37mDEBUG[0m librespot_connect::spirc] cluster update: Ok(DEVICE_STATE_CHANGED) from dabf2172feb9bc5d067c4d156e8c02a6a7eed0ba, active device: f75050e4ada1cfe882a7f463ef4a20c1a3fe0e4a
[[37mDEBUG[0m symphonia_codec_vorbis] vorbis: leftover bits in setup head extra data
[[37mDEBUG[0m symphonia_format_ogg::demuxer] seeking track=0x0 to frame_ts=2970972
[[37mDEBUG[0m symphonia_format_ogg::demuxer] seek: bisect step: page={ start_ts=5636416, end_ts=5639552 } byte_range=[4026, 6087533, 12171040]
[[37mDEBUG[0m symphonia_format_ogg::demuxer] seek: bisect step: page={ start_ts=3209536, end_ts=3212800 } byte_range=[4026, 3045779, 6087533]
[[37mDEBUG[0m symphonia_format_ogg::demuxer] seek: bisect step: page={ start_ts=1668160, end_ts=1671232 } byte_range=[4026, 1524902, 3045779]
[[37mDEBUG[0m symphonia_format_ogg::demuxer] seek: bisect step: page={ start_ts=2536384, end_ts=2540480 } byte_range=[1524902, 2285340, 3045779]
[[37mDEBUG[0m symphonia_format_ogg::demuxer] seek: bisect step: page={ start_ts=2909568, end_ts=2912128 } byte_range=[2285340, 2665559, 3045779]
[[37mDEBUG[0m symphonia_format_ogg::demuxer] seek: bisect step: page={ start_ts=3061056, end_ts=3064640 } byte_range=[2665559, 2855669, 3045779]
[[37mDEBUG[0m symphonia_format_ogg::demuxer] seek: bisect step: page={ start_ts=2980032, end_ts=2983360 } byte_range=[2665559, 2760614, 2855669]
[[37mDEBUG[0m symphonia_format_ogg::demuxer] seeked track=0x0 to packet_ts=2970880 (delta=-92)
[[37mINFO[0m librespot_playback::player] <Ganja Tape> (254488 ms) loaded
[[37mDEBUG[0m spotifyd::dbus_mpris] handling event TrackChanged { audio_item: AudioItem { track_id: SpotifyUri("spotify:track:2pZkX6yyPuF8UdRqGXsDci"), uri: "spotify:track:2pZkX6yyPuF8UdRqGXsDci", files: AudioFiles({AAC_24: FileId(Ok("3b45b31ce3b3941347033e78b91c9eb869eb9ba7")), OGG_VORBIS_160: FileId(Ok("fbe757de3f73b359fe1aa0b4fd0a340565e12393")), OGG_VORBIS_320: FileId(Ok("2a440d87c277316c01f02168302742e117a9c736")), OGG_VORBIS_96: FileId(Ok("1d9b6b35b18bcdb37e37d32a62126979e378d841"))}), name: "Ganja Tape", covers: [CoverImage { url: "https://i.scdn.co/image/ab67616d0000b273340883dda987a2bbce4cdadd", size: LARGE, width: 640, height: 640 }, CoverImage { url: "https://i.scdn.co/image/ab67616d00001e02340883dda987a2bbce4cdadd", size: DEFAULT, width: 300, height: 300 }, CoverImage { url: "https://i.scdn.co/image/ab67616d00004851340883dda987a2bbce4cdadd", size: SMALL, width: 64, height: 64 }], language: ["en"], duration_ms: 254488, is_explicit: false, availability: Ok(()), alternatives: None, unique_fields: Track { artists: ArtistsWithRole([ArtistWithRole { id: SpotifyUri("spotify:artist:1a6oIpEh4DGgaqgWg5xwd3"), name: "Ganja White Night", role: ARTIST_ROLE_MAIN_ARTIST }, ArtistWithRole { id: SpotifyUri("spotify:artist:59tlsKpLWoLTxjNNS2wdPi"), name: "Tape B", role: ARTIST_ROLE_MAIN_ARTIST }]), album: "Ganja Tape", album_artists: ["Ganja White Night", "Tape B"], popularity: 45, number: 1, disc_number: 1 } } }
[[37mDEBUG[0m spotifyd::dbus_mpris] handling event Paused { play_request_id: 0, track_id: SpotifyUri("spotify:track:2pZkX6yyPuF8UdRqGXsDci"), position_ms: 67366 }
[[37mDEBUG[0m librespot_connect::state] updated connect play status playing: true, paused: true, buffering: true
[[37mDEBUG[0m librespot_core::http_client] Requesting https://guc3-spclient.spotify.com:443/connect-state/v1/devices/f75050e4ada1cfe882a7f463ef4a20c1a3fe0e4a?product=0&country=US&salt=4262659304
[[37mDEBUG[0m librespot_core::http_client] Requesting https://guc3-spclient.spotify.com:443/context-resolve/v1/spotify:playlist:3CsqNkt4RuyYKqHsecxNmO
[[37mDEBUG[0m librespot_connect::spirc] handling next context Some("spotify:playlist:3CsqNkt4RuyYKqHsecxNmO")
[[37mDEBUG[0m librespot_connect::state::context] updated context Default to <Some("spotify:playlist:3CsqNkt4RuyYKqHsecxNmO")> (1228 tracks)
[[37mDEBUG[0m librespot_connect::context_resolver] last item of type <Default>, finishing state setup
[[37mDEBUG[0m librespot_connect::state::transfer] active track is <spotify:track:2pZkX6yyPuF8UdRqGXsDci> with index Ok(725) in Default context, has 1228 tracks
[[37mDEBUG[0m librespot_connect::state::transfer] setting up next and prev: index is at Some(725) while shuffle true
[[37mDEBUG[0m librespot_connect::state::tracks] set track to: spotify:track:2pZkX6yyPuF8UdRqGXsDci at 725 of 1228 tracks
[[37mDEBUG[0m librespot_connect::state::tracks] skipped track spotify:track:2pZkX6yyPuF8UdRqGXsDci during fillup as it's unavailable or should be skipped
[[37mDEBUG[0m librespot_connect::state::tracks] finished filling up next_tracks (80)
[[37mDEBUG[0m librespot_connect::state] updated connect play status playing: true, paused: true, buffering: true
[[37mDEBUG[0m librespot_core::http_client] Requesting https://guc3-spclient.spotify.com:443/connect-state/v1/devices/f75050e4ada1cfe882a7f463ef4a20c1a3fe0e4a?product=0&country=US&salt=6210849
[[37mDEBUG[0m librespot_connect::spirc] cluster update: Ok(UNKNOWN_CLUSTER_UPDATE_REASON) from 6fbfa02db9fbc3241eab2f605830fb630aba8b0e, active device: f75050e4ada1cfe882a7f463ef4a20c1a3fe0e4a
[[37mDEBUG[0m librespot_connect::state] updated connect play status playing: true, paused: true, buffering: true
[[37mDEBUG[0m librespot_core::http_client] Requesting https://guc3-spclient.spotify.com:443/connect-state/v1/devices/f75050e4ada1cfe882a7f463ef4a20c1a3fe0e4a?product=0&country=US&salt=437616815
[[37mDEBUG[0m librespot_connect::spirc] cluster update: Ok(DEVICE_STATE_CHANGED) from dabf2172feb9bc5d067c4d156e8c02a6a7eed0ba, active device: dabf2172feb9bc5d067c4d156e8c02a6a7eed0ba
[[37mINFO[0m librespot_connect::spirc] device became inactive
[[37mDEBUG[0m librespot_connect::state] update position to 1:11 at 15:21:10.95
[[37mDEBUG[0m librespot_connect::state] updated connect play status playing: true, paused: true, buffering: true
[[37mDEBUG[0m librespot_core::http_client] Requesting https://guc3-spclient.spotify.com:443/connect-state/v1/devices/f75050e4ada1cfe882a7f463ef4a20c1a3fe0e4a?product=0&country=US&salt=1205786723
[[37mDEBUG[0m librespot_core::dealer] No subscriber for msg.uri: social-connect/v2/broadcast_status_update
[[37mDEBUG[0m librespot_core::mercury] unknown subscription uri=social-connect/v2/broadcast_status_update
[[37mDEBUG[0m 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, 55, 52, 55, 57, 55, 54, 55, 49, 57, 55, 50, 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, 100, 97, 98, 102, 50, 49, 55, 50, 102, 101, 98, 57, 98, 99, 53, 100, 48, 54, 55, 99, 52, 100, 49, 53, 54, 101, 56, 99, 48, 50, 97, 54, 97, 55, 101, 101, 100, 48, 98, 97, 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, 48, 113, 75, 110, 80, 76, 117, 107, 107, 55, 87, 49, 71, 113, 79, 89, 72, 51, 71, 77, 65, 107, 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, 75, 74, 66, 68, 67, 67, 76, 65, 81, 70, 68, 77, 84, 67, 70, 70, 90, 88, 56, 49, 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, 55, 97, 79, 102, 68, 74, 104, 112, 78, 55, 89, 104, 49, 102, 118, 115, 49, 103, 90, 57, 101, 103, 34, 125, 44, 34, 100, 101, 118, 105, 99, 101, 95, 116, 121, 112, 101, 34, 58, 34, 65, 86, 82, 34, 125, 125]] } }
[[33mWARN[0m librespot_connect::state::context] couldn't load context info because: context is not available. type: Default
[[37mDEBUG[0m librespot_core::http_client] Requesting https://guc3-spclient.spotify.com:443/connect-state/v1/devices/f75050e4ada1cfe882aSource: Spotifyd/spotifyd