Aug 31 13:28:01 spla-repro volumio[5528]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 31 13:28:01 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 31 13:28:01 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:01 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:01 spla-repro go-librespot[5857]: go-librespot daemon starting... Aug 31 13:28:01 spla-repro go-librespot[5858]: time="2026-08-31T13:28:01+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:28:01 spla-repro go-librespot[5858]: time="2026-08-31T13:28:01+02:00" level=debug msg="app state loaded" Aug 31 13:28:01 spla-repro go-librespot[5858]: time="2026-08-31T13:28:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:28:01 spla-repro go-librespot[5858]: time="2026-08-31T13:28:01+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 13:28:01 spla-repro go-librespot[5858]: time="2026-08-31T13:28:01+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 13:28:01 spla-repro go-librespot[5858]: time="2026-08-31T13:28:01+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 13:28:01 spla-repro go-librespot[5858]: time="2026-08-31T13:28:01+02:00" level=info msg="zeroconf server listening on port 38157" Aug 31 13:28:01 spla-repro go-librespot[5858]: time="2026-08-31T13:28:01+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 13:28:02 spla-repro go-librespot[5858]: time="2026-08-31T13:28:02+02:00" level=debug msg="obtained new client token: AAFQuJyI5clYEzPMiZZXXNx2hEx2TQ+3XjgCTWamo9miGS2aE47hHuoG5/FAzvKd9r39I72X5kDc//x3P/wi6bXNiV1VIgp6/pHid/v1YU9LcWrUtWVC91UzCJkp2YQ0FOeHq7GjdXt1gJSlZ1EcCx5g6ZLVQOAvWwmziDZ2UFGTY7lP60gUp0sf3uHXDRHL2uQxUQnwmwu+vrkWnoUlsduloRjC00SbqovmSH9bocwkJ8+apL4bgDQ=" Aug 31 13:28:02 spla-repro go-librespot[5858]: time="2026-08-31T13:28:02+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 31 13:28:02 spla-repro go-librespot[5858]: time="2026-08-31T13:28:02+02:00" level=debug msg="completed keyexchange" Aug 31 13:28:02 spla-repro go-librespot[5858]: time="2026-08-31T13:28:02+02:00" level=debug msg="completed challenge" Aug 31 13:28:02 spla-repro go-librespot[5858]: time="2026-08-31T13:28:02+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 31 13:28:02 spla-repro go-librespot[5858]: time="2026-08-31T13:28:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 13:28:02 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 13:28:02 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 13:28:02 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:02 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 31 13:28:04 spla-repro volumio[5528]: info: Adding plugin bluetooth to MyMusic Plugins Aug 31 13:28:04 spla-repro volumio[5528]: info: Adding plugin multiroom to MyMusic Plugins Aug 31 13:28:04 spla-repro volumio[5528]: info: Adding plugin metavolumio to MyMusic Plugins Aug 31 13:28:04 spla-repro volumio[5528]: info: Adding plugin cd_controller to MyMusic Plugins Aug 31 13:28:04 spla-repro volumio[5528]: info: Adding plugin qobuzconnect to MyMusic Plugins Aug 31 13:28:04 spla-repro volumio[5528]: info: Adding plugin smart_inputs to MyMusic Plugins Aug 31 13:28:04 spla-repro volumio[5528]: info: Adding plugin tidalconnect to MyMusic Plugins Aug 31 13:28:04 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 31 13:28:05 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Aug 31 13:28:05 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:05 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:05 spla-repro go-librespot[5881]: go-librespot daemon starting... Aug 31 13:28:05 spla-repro go-librespot[5882]: time="2026-08-31T13:28:05+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:28:05 spla-repro go-librespot[5882]: time="2026-08-31T13:28:05+02:00" level=debug msg="app state loaded" Aug 31 13:28:05 spla-repro go-librespot[5882]: time="2026-08-31T13:28:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:28:06 spla-repro go-librespot[5882]: time="2026-08-31T13:28:06+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 13:28:06 spla-repro go-librespot[5882]: time="2026-08-31T13:28:06+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 13:28:06 spla-repro go-librespot[5882]: time="2026-08-31T13:28:06+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 13:28:06 spla-repro go-librespot[5882]: time="2026-08-31T13:28:06+02:00" level=info msg="zeroconf server listening on port 33203" Aug 31 13:28:06 spla-repro go-librespot[5882]: time="2026-08-31T13:28:06+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 13:28:06 spla-repro volumio[5528]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 31 13:28:06 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 31 13:28:06 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 13:28:06 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 13:28:06 spla-repro volumio[5528]: info: Starting MyVolumio Remote Streaming Endpoints Aug 31 13:28:06 spla-repro volumio[5528]: info: MyVolumio login type: Token Aug 31 13:28:06 spla-repro go-librespot[5882]: time="2026-08-31T13:28:06+02:00" level=debug msg="obtained new client token: AAGm7pAz16gyMiVIFmKmttE4a2PE8m1A7n6BRV+MghrSKtnyC/Bd77EQutyTmXqEUiRy5wJ497VHF0uGqBVJByuBHKRZNFWKyb9zpZFgW0V0yzu5UBFakvY/6XCV+VVKYP3VBicwlkPdUq144LBFybUjN39IS9+4Y1eHLZ7LXjSXJwll9kDqXtl09KUWP/obd57804m2djHWveXneXz0zv4t6ZSvXhQXvHKctL+o4WgLBdSUrZjmR1U=" Aug 31 13:28:06 spla-repro volumio[5528]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 31 13:28:06 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Aug 31 13:28:06 spla-repro go-librespot[5882]: time="2026-08-31T13:28:06+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Aug 31 13:28:06 spla-repro go-librespot[5882]: time="2026-08-31T13:28:06+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 31 13:28:06 spla-repro go-librespot[5882]: time="2026-08-31T13:28:06+02:00" level=debug msg="completed keyexchange" Aug 31 13:28:06 spla-repro go-librespot[5882]: time="2026-08-31T13:28:06+02:00" level=debug msg="completed challenge" Aug 31 13:28:06 spla-repro go-librespot[5882]: time="2026-08-31T13:28:06+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 31 13:28:06 spla-repro go-librespot[5882]: time="2026-08-31T13:28:06+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 13:28:06 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 13:28:06 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 13:28:07 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Aug 31 13:28:07 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Aug 31 13:28:07 spla-repro volumio[5528]: info: Streaming services startup Aug 31 13:28:07 spla-repro volumio[5528]: info: Starting Streaming Daemon Aug 31 13:28:07 spla-repro sudo[5892]: volumio : unable to resolve host spla-repro: System error Aug 31 13:28:07 spla-repro volumio[5528]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Aug 31 13:28:07 spla-repro sudo[5892]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 13:28:07 spla-repro sudo[5892]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 13:28:07 spla-repro sudo[5892]: pam_unix(sudo:session): session closed for user root Aug 31 13:28:07 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:07 spla-repro volumio[5528]: error: Cannot start Volumio Streaming Daemon Aug 31 13:28:07 spla-repro volumio[5528]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 13:28:07 spla-repro volumio[5528]: sudo: unable to resolve host spla-repro: System error Aug 31 13:28:07 spla-repro volumio[5528]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 13:28:07 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:07 spla-repro volumio[5528]: info: CoreCommandRouter::volumioGetState Aug 31 13:28:07 spla-repro volumio[5528]: info: CorePlayQueue::getTrack 0 Aug 31 13:28:07 spla-repro volumio[5528]: info: Listing playlists Aug 31 13:28:07 spla-repro volumio[5528]: info: Listing playlists Aug 31 13:28:08 spla-repro volumio[5528]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 31 13:28:08 spla-repro volumio[5528]: info: MyVolumio token set successfully Aug 31 13:28:08 spla-repro volumio[5528]: info: MYVOLUMIO: Adding device Aug 31 13:28:08 spla-repro volumio[5528]: info: MYVOLUMIO: Evaluating Server Aug 31 13:28:09 spla-repro volumio[5528]: info: MyVolumio status changed Aug 31 13:28:09 spla-repro volumio[5528]: info: Streaming services startup Aug 31 13:28:09 spla-repro volumio[5528]: info: Starting Streaming Daemon Aug 31 13:28:09 spla-repro volumio[5528]: info: Removing browser output: myVolumio user plan is not superstar Aug 31 13:28:09 spla-repro volumio[5528]: info: Removing audio output: Aug 31 13:28:09 spla-repro volumio[5528]: info: Stoppping Tunnel 1 Aug 31 13:28:09 spla-repro sudo[5920]: volumio : unable to resolve host spla-repro: System error Aug 31 13:28:09 spla-repro sudo[5920]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 13:28:09 spla-repro sudo[5920]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 13:28:09 spla-repro sudo[5920]: pam_unix(sudo:session): session closed for user root Aug 31 13:28:09 spla-repro sudo[5923]: volumio : unable to resolve host spla-repro: System error Aug 31 13:28:09 spla-repro volumio[5528]: error: Cannot start Volumio Streaming Daemon Aug 31 13:28:09 spla-repro sudo[5923]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 31 13:28:09 spla-repro volumio[5528]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 13:28:09 spla-repro volumio[5528]: sudo: unable to resolve host spla-repro: System error Aug 31 13:28:09 spla-repro volumio[5528]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 13:28:09 spla-repro sudo[5923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 31 13:28:09 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 13:28:09 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 13:28:09 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 13:28:09 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 13:28:09 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 13:28:09 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 13:28:09 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 13:28:09 spla-repro systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Aug 31 13:28:09 spla-repro sudo[5923]: pam_unix(sudo:session): session closed for user root Aug 31 13:28:09 spla-repro volumio[5528]: info: Remote SSH Stopped Aug 31 13:28:09 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Aug 31 13:28:09 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:09 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:09 spla-repro go-librespot[5925]: go-librespot daemon starting... Aug 31 13:28:09 spla-repro go-librespot[5926]: time="2026-08-31T13:28:09+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:28:09 spla-repro go-librespot[5926]: time="2026-08-31T13:28:09+02:00" level=debug msg="app state loaded" Aug 31 13:28:09 spla-repro go-librespot[5926]: time="2026-08-31T13:28:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:28:10 spla-repro go-librespot[5926]: time="2026-08-31T13:28:10+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 13:28:10 spla-repro go-librespot[5926]: time="2026-08-31T13:28:10+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 13:28:10 spla-repro go-librespot[5926]: time="2026-08-31T13:28:10+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 13:28:10 spla-repro go-librespot[5926]: time="2026-08-31T13:28:10+02:00" level=info msg="zeroconf server listening on port 39613" Aug 31 13:28:10 spla-repro go-librespot[5926]: time="2026-08-31T13:28:10+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 13:28:10 spla-repro go-librespot[5926]: time="2026-08-31T13:28:10+02:00" level=debug msg="obtained new client token: AAH1dJXmZipcTwttKRNkANXyRAjp5ayCxcXsd+F3yRnp+oITI3VBZRc9ph+7Q8ePg/HNGBcW35mfHh0vX4XD0D0S+2WsJX3/B0kCV+UYp7Hke012xntC8qVGk4MevLI9NMLcZBzBEBQqxxY6gagHf2+snevL4Tb1dAxr7TcL5T1mLnVNgKKgNv3HITrv2QggzHDF0BUoQB4Rywdg5Gn6fCPvGbDLJy9YPSN1wmYGUWZngxph4dhEAUZFEA==" Aug 31 13:28:10 spla-repro go-librespot[5926]: time="2026-08-31T13:28:10+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 31 13:28:10 spla-repro go-librespot[5926]: time="2026-08-31T13:28:10+02:00" level=debug msg="completed keyexchange" Aug 31 13:28:10 spla-repro go-librespot[5926]: time="2026-08-31T13:28:10+02:00" level=debug msg="completed challenge" Aug 31 13:28:10 spla-repro go-librespot[5926]: time="2026-08-31T13:28:10+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 31 13:28:10 spla-repro go-librespot[5926]: time="2026-08-31T13:28:10+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 13:28:10 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 13:28:10 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 13:28:10 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:10 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:11 spla-repro volumio[5528]: info: Setting Geolocation for MyVolumio to eu7 Aug 31 13:28:11 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 13:28:11 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 13:28:11 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 13:28:11 spla-repro volumio[5528]: info: Successfully Added MyVolumio device Aug 31 13:28:12 spla-repro volumio[5528]: info: Updating MyVolumio device info Aug 31 13:28:12 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 13:28:12 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 13:28:12 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 13:28:12 spla-repro volumio[5528]: info: Successfully Updated MyVolumio device Aug 31 13:28:13 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:13 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:13 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Aug 31 13:28:13 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:13 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:13 spla-repro go-librespot[5949]: go-librespot daemon starting... Aug 31 13:28:13 spla-repro go-librespot[5950]: time="2026-08-31T13:28:13+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:28:13 spla-repro go-librespot[5950]: time="2026-08-31T13:28:13+02:00" level=debug msg="app state loaded" Aug 31 13:28:13 spla-repro go-librespot[5950]: time="2026-08-31T13:28:13+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:28:14 spla-repro go-librespot[5950]: time="2026-08-31T13:28:14+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 31 13:28:14 spla-repro go-librespot[5950]: time="2026-08-31T13:28:14+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 31 13:28:14 spla-repro go-librespot[5950]: time="2026-08-31T13:28:14+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 31 13:28:14 spla-repro go-librespot[5950]: time="2026-08-31T13:28:14+02:00" level=info msg="zeroconf server listening on port 34083" Aug 31 13:28:14 spla-repro go-librespot[5950]: time="2026-08-31T13:28:14+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 13:28:14 spla-repro go-librespot[5950]: time="2026-08-31T13:28:14+02:00" level=debug msg="obtained new client token: AAF62+kKN5WDZQ3JgVZyvhWLHd4ylmGjn+Ik6ihJ/iO4tvqSUjKhQo3GD+677xyA98F6HSRbYZxCznZDpfAhLtbe1sg58iI+QBdYkrCvUXfd54NMIDJ1hMXX+8aS3MVPHhNxHkMI1YZ/Qvn+Uom8GfUTCjQcmYNQ6KlYxT6rJrr/33/2MXtT1f/BPXefOWG+R4NRoNt/SNM9K6p3iZPEZ2vqe0ky7p66D4uKFYNMCm4zdu6ug57iQ8E=" Aug 31 13:28:14 spla-repro go-librespot[5950]: time="2026-08-31T13:28:14+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 31 13:28:14 spla-repro go-librespot[5950]: time="2026-08-31T13:28:14+02:00" level=debug msg="completed keyexchange" Aug 31 13:28:14 spla-repro go-librespot[5950]: time="2026-08-31T13:28:14+02:00" level=debug msg="completed challenge" Aug 31 13:28:14 spla-repro go-librespot[5950]: time="2026-08-31T13:28:14+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 31 13:28:14 spla-repro go-librespot[5950]: time="2026-08-31T13:28:14+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 13:28:14 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 13:28:14 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 13:28:16 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:16 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:17 spla-repro volumio[5528]: info: CoreCommandRouter::volumioGetState Aug 31 13:28:17 spla-repro volumio[5528]: info: CorePlayQueue::getTrack 0 Aug 31 13:28:17 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Aug 31 13:28:17 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:17 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:17 spla-repro go-librespot[5959]: go-librespot daemon starting... Aug 31 13:28:17 spla-repro go-librespot[5960]: time="2026-08-31T13:28:17+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:28:17 spla-repro go-librespot[5960]: time="2026-08-31T13:28:17+02:00" level=debug msg="app state loaded" Aug 31 13:28:17 spla-repro go-librespot[5960]: time="2026-08-31T13:28:17+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:28:18 spla-repro go-librespot[5960]: time="2026-08-31T13:28:18+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 13:28:18 spla-repro go-librespot[5960]: time="2026-08-31T13:28:18+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 13:28:18 spla-repro go-librespot[5960]: time="2026-08-31T13:28:18+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 13:28:18 spla-repro go-librespot[5960]: time="2026-08-31T13:28:18+02:00" level=info msg="zeroconf server listening on port 46149" Aug 31 13:28:18 spla-repro go-librespot[5960]: time="2026-08-31T13:28:18+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 13:28:18 spla-repro go-librespot[5960]: time="2026-08-31T13:28:18+02:00" level=debug msg="obtained new client token: AAHN+qYfEqRGMJSzyNyzX7GTYCsDtBC3AhYBnD6eap6V/ntxSkCxd0Yf4HwWg/Kyv+PBm626pmcpDs5ov3HzzYYfoGNItGjuTYTIyktfQ9xz8jADtUsx5wLVbbwZJlxR0R8ZtMQToWJs6fJklHJ+jkkpVQgGo1g8Fx0HW1wijCCFlP0+WgeUtRFpqe1KTpn4gibiI+MU6eFe9aRTpy/37vcd8TIU8ZHGeQ6rLRFNqMgaw3M494wOC9dz4Q==" Aug 31 13:28:18 spla-repro go-librespot[5960]: time="2026-08-31T13:28:18+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 31 13:28:18 spla-repro go-librespot[5960]: time="2026-08-31T13:28:18+02:00" level=debug msg="completed keyexchange" Aug 31 13:28:18 spla-repro go-librespot[5960]: time="2026-08-31T13:28:18+02:00" level=debug msg="completed challenge" Aug 31 13:28:18 spla-repro go-librespot[5960]: time="2026-08-31T13:28:18+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 31 13:28:18 spla-repro go-librespot[5960]: time="2026-08-31T13:28:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 13:28:18 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 13:28:18 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 13:28:19 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:19 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:20 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 13:28:20 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 13:28:20 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 31 13:28:20 spla-repro volumio-remote-updater[725]: Test mode disabled Aug 31 13:28:20 spla-repro volumio-remote-updater[725]: Alpha mode disabled Aug 31 13:28:20 spla-repro volumio-remote-updater[725]: Alpha legacy test mode disabled Aug 31 13:28:20 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 31 13:28:20 spla-repro volumio[5528]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 31 13:28:20 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 31 13:28:21 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 13:28:21 spla-repro volumio[5528]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Aug 31 13:28:21 spla-repro volumio[5528]: info: CoreCommandRouter::volumioGetState Aug 31 13:28:21 spla-repro volumio[5528]: info: CorePlayQueue::getTrack 0 Aug 31 13:28:21 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Aug 31 13:28:21 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:21 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:21 spla-repro go-librespot[5974]: go-librespot daemon starting... Aug 31 13:28:21 spla-repro go-librespot[5975]: time="2026-08-31T13:28:21+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:28:21 spla-repro go-librespot[5975]: time="2026-08-31T13:28:21+02:00" level=debug msg="app state loaded" Aug 31 13:28:21 spla-repro go-librespot[5975]: time="2026-08-31T13:28:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:28:22 spla-repro go-librespot[5975]: time="2026-08-31T13:28:22+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 31 13:28:22 spla-repro go-librespot[5975]: time="2026-08-31T13:28:22+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 31 13:28:22 spla-repro go-librespot[5975]: time="2026-08-31T13:28:22+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 31 13:28:22 spla-repro go-librespot[5975]: time="2026-08-31T13:28:22+02:00" level=info msg="zeroconf server listening on port 41309" Aug 31 13:28:22 spla-repro go-librespot[5975]: time="2026-08-31T13:28:22+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 13:28:22 spla-repro go-librespot[5975]: time="2026-08-31T13:28:22+02:00" level=debug msg="obtained new client token: AAGhRri3/HrtIm/BJn6vwBeSWXmdomEYOVjWeNCzDpZxvz5RX0b3ri3pt9gwm4mHO7X/vaGY3ftc8SUdlINZyJAzCC3VCBQFKwF/xGlYwlxG5WFQl2+OzHee109YNk+a5ZoDXT/UOcchPn/7MPZPBywTOG7jk8y2YUex8aAK3a0rJhqreUnjuQcXobOb3ooypDLIyQw2gu0z/pHuuwmduJw4sr4eKVZBqMaNTLeAmFEnc7A6wmd2AC8=" Aug 31 13:28:22 spla-repro go-librespot[5975]: time="2026-08-31T13:28:22+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 31 13:28:22 spla-repro go-librespot[5975]: time="2026-08-31T13:28:22+02:00" level=debug msg="completed keyexchange" Aug 31 13:28:22 spla-repro go-librespot[5975]: time="2026-08-31T13:28:22+02:00" level=debug msg="completed challenge" Aug 31 13:28:22 spla-repro go-librespot[5975]: time="2026-08-31T13:28:22+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 31 13:28:22 spla-repro go-librespot[5975]: time="2026-08-31T13:28:22+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 13:28:22 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 13:28:22 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 13:28:22 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:22 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:25 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:25 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:25 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Aug 31 13:28:25 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:25 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:25 spla-repro go-librespot[5999]: go-librespot daemon starting... Aug 31 13:28:25 spla-repro go-librespot[6000]: time="2026-08-31T13:28:25+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:28:25 spla-repro go-librespot[6000]: time="2026-08-31T13:28:25+02:00" level=debug msg="app state loaded" Aug 31 13:28:25 spla-repro go-librespot[6000]: time="2026-08-31T13:28:25+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:28:26 spla-repro go-librespot[6000]: time="2026-08-31T13:28:26+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 13:28:26 spla-repro go-librespot[6000]: time="2026-08-31T13:28:26+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 13:28:26 spla-repro go-librespot[6000]: time="2026-08-31T13:28:26+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 13:28:26 spla-repro go-librespot[6000]: time="2026-08-31T13:28:26+02:00" level=info msg="zeroconf server listening on port 32809" Aug 31 13:28:26 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 13:28:26 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 13:28:26 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 31 13:28:26 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Aug 31 13:28:26 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 31 13:28:26 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 31 13:28:26 spla-repro volumio[5528]: info: CoreCommandRouter::volumioGetBrowseSources Aug 31 13:28:26 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 13:28:26 spla-repro go-librespot[6000]: time="2026-08-31T13:28:26+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 13:28:26 spla-repro go-librespot[6000]: time="2026-08-31T13:28:26+02:00" level=debug msg="obtained new client token: AAGMxmZe1MoegobeMx09h6+8HXXExFBzNDU3TeryFLnOimSCqJltlLnIqhwKWlR20JLtxn4kZJvd1WU9oZNNxHTx4bZnKHYpeLs7dwdvbKE4prWvVwdStpWHZ/lXZdYU788UyoC4y6Ft1c2gppPYYd7Aoj3I8Ytj2GhG2S2ziqkJvOkp7tGATaQPQbhi31r2JpGGIAIhoPtY3p3Pp/F+bdsb6x/LuV81zv10I2MXaBiH1VTnbPYoDaM=" Aug 31 13:28:26 spla-repro go-librespot[6000]: time="2026-08-31T13:28:26+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 31 13:28:26 spla-repro go-librespot[6000]: time="2026-08-31T13:28:26+02:00" level=debug msg="completed keyexchange" Aug 31 13:28:26 spla-repro go-librespot[6000]: time="2026-08-31T13:28:26+02:00" level=debug msg="completed challenge" Aug 31 13:28:26 spla-repro go-librespot[6000]: time="2026-08-31T13:28:26+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 31 13:28:26 spla-repro go-librespot[6000]: time="2026-08-31T13:28:26+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 13:28:26 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 13:28:26 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 13:28:27 spla-repro volumio[5528]: info: CoreCommandRouter::volumioGetState Aug 31 13:28:27 spla-repro volumio[5528]: info: CorePlayQueue::getTrack 0 Aug 31 13:28:27 spla-repro volumio[5528]: info: Listing playlists Aug 31 13:28:27 spla-repro volumio[5528]: info: Listing playlists Aug 31 13:28:27 spla-repro volumio[5528]: error: MyVolumio Plugin failed to authenticate in a timely fashion Aug 31 13:28:27 spla-repro volumio[5528]: info: Completed starting MyVolumio Plugin Aug 31 13:28:27 spla-repro volumio[5528]: [Metrics] CommandRouter: 48s 606.33ms Aug 31 13:28:27 spla-repro volumio[5528]: info: CoreCommandRouter::volumiosetStartupVolume Aug 31 13:28:27 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 13:28:27 spla-repro volumio[5528]: info: VolumeController:: Setting startup Volume 45 Aug 31 13:28:27 spla-repro volumio[5528]: info: VolumeController::SetAlsaVolume45 Aug 31 13:28:27 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 13:28:27 spla-repro volumio[5528]: info: CoreCommandRouter::Close All Modals sent Aug 31 13:28:27 spla-repro volumio[5528]: info: CoreCommandRouter::Close All Modals sent Aug 31 13:28:27 spla-repro volumio[5528]: info: CoreStateMachine::pushState Aug 31 13:28:27 spla-repro volumio[5528]: info: CorePlayQueue::getTrack 0 Aug 31 13:28:27 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 13:28:27 spla-repro volumio[5528]: info: CoreCommandRouter::volumioPushState Aug 31 13:28:28 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 31 13:28:28 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 31 13:28:28 spla-repro volumio[5528]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 31 13:28:28 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:28 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:29 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Aug 31 13:28:29 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:29 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:29 spla-repro go-librespot[6010]: go-librespot daemon starting... Aug 31 13:28:29 spla-repro go-librespot[6011]: time="2026-08-31T13:28:29+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:28:29 spla-repro go-librespot[6011]: time="2026-08-31T13:28:29+02:00" level=debug msg="app state loaded" Aug 31 13:28:29 spla-repro go-librespot[6011]: time="2026-08-31T13:28:29+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:28:30 spla-repro go-librespot[6011]: time="2026-08-31T13:28:30+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 31 13:28:30 spla-repro go-librespot[6011]: time="2026-08-31T13:28:30+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 31 13:28:30 spla-repro go-librespot[6011]: time="2026-08-31T13:28:30+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 31 13:28:30 spla-repro go-librespot[6011]: time="2026-08-31T13:28:30+02:00" level=info msg="zeroconf server listening on port 39035" Aug 31 13:28:30 spla-repro go-librespot[6011]: time="2026-08-31T13:28:30+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 13:28:30 spla-repro go-librespot[6011]: time="2026-08-31T13:28:30+02:00" level=debug msg="obtained new client token: AAHKkE+VKVH7iGkBJ2rFBbDC5/y/I6NWPHPw0FACWOz8ad43o14oZGPMRe2EHqLh1MQtvroNJsFQREabARrWcy92sGpwCdD1suR0nRn8RZuswDJVt68f4EvQNZqwZGFfnMoJ2lNzXxWFhCztlBkha0lcmxApD7rfQPWMmMlkKMvcfB4vccCelbTdyZVJn8LOsghe/UOJOqLnl8sX5lghrRHiCb2By3fn9EraEBRkBUYmZM21UhlJFwc=" Aug 31 13:28:30 spla-repro go-librespot[6011]: time="2026-08-31T13:28:30+02:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Aug 31 13:28:30 spla-repro go-librespot[6011]: time="2026-08-31T13:28:30+02:00" level=debug msg="connected to ap-gew1.spotify.com:443" Aug 31 13:28:30 spla-repro go-librespot[6011]: time="2026-08-31T13:28:30+02:00" level=debug msg="completed keyexchange" Aug 31 13:28:30 spla-repro go-librespot[6011]: time="2026-08-31T13:28:30+02:00" level=debug msg="completed challenge" Aug 31 13:28:30 spla-repro go-librespot[6011]: time="2026-08-31T13:28:30+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 31 13:28:30 spla-repro go-librespot[6011]: time="2026-08-31T13:28:30+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 13:28:30 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 13:28:30 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 13:28:31 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:31 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:33 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Aug 31 13:28:33 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:33 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:33 spla-repro go-librespot[6034]: go-librespot daemon starting... Aug 31 13:28:33 spla-repro go-librespot[6035]: time="2026-08-31T13:28:33+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:28:33 spla-repro go-librespot[6035]: time="2026-08-31T13:28:33+02:00" level=debug msg="app state loaded" Aug 31 13:28:33 spla-repro go-librespot[6035]: time="2026-08-31T13:28:33+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:28:34 spla-repro go-librespot[6035]: time="2026-08-31T13:28:34+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 31 13:28:34 spla-repro go-librespot[6035]: time="2026-08-31T13:28:34+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 31 13:28:34 spla-repro go-librespot[6035]: time="2026-08-31T13:28:34+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 31 13:28:34 spla-repro go-librespot[6035]: time="2026-08-31T13:28:34+02:00" level=info msg="zeroconf server listening on port 42065" Aug 31 13:28:34 spla-repro go-librespot[6035]: time="2026-08-31T13:28:34+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 13:28:34 spla-repro go-librespot[6035]: time="2026-08-31T13:28:34+02:00" level=debug msg="obtained new client token: AAEkyPfpi2GwJFSgPa5TN2eyS3My063PyM0AacjTY7iaiZ1FTF3ulPoF2Eih2aRa16QICQqiAoAbs+KmeKqMsO3SWhwrUIa8JVL+aQ2eyKZQpKyY60NMht9pzA2diXLZ8wpYJFnqvqiHHZzSXV9Sq4clp3x6j+i6VZkodpVLrZ+4OUUjpDkibD3zY1zKgQLWpRTyACMVZ1SLStqAsl6JCkVvb1LSFjvmnJnOHlPxpnxu9GyHehPKLws=" Aug 31 13:28:34 spla-repro go-librespot[6035]: time="2026-08-31T13:28:34+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 31 13:28:34 spla-repro go-librespot[6035]: time="2026-08-31T13:28:34+02:00" level=debug msg="completed keyexchange" Aug 31 13:28:34 spla-repro go-librespot[6035]: time="2026-08-31T13:28:34+02:00" level=debug msg="completed challenge" Aug 31 13:28:34 spla-repro go-librespot[6035]: time="2026-08-31T13:28:34+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 31 13:28:34 spla-repro go-librespot[6035]: time="2026-08-31T13:28:34+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 13:28:34 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 13:28:34 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 13:28:34 spla-repro volumio[5528]: info: BOOT COMPLETED Aug 31 13:28:34 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:34 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:37 spla-repro volumio[5528]: info: CoreCommandRouter::volumioGetState Aug 31 13:28:37 spla-repro volumio[5528]: info: CorePlayQueue::getTrack 0 Aug 31 13:28:37 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:37 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:37 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Aug 31 13:28:37 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:37 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:37 spla-repro go-librespot[6045]: go-librespot daemon starting... Aug 31 13:28:37 spla-repro go-librespot[6046]: time="2026-08-31T13:28:37+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:28:37 spla-repro go-librespot[6046]: time="2026-08-31T13:28:37+02:00" level=debug msg="app state loaded" Aug 31 13:28:37 spla-repro go-librespot[6046]: time="2026-08-31T13:28:37+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:28:38 spla-repro go-librespot[6046]: time="2026-08-31T13:28:38+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 13:28:38 spla-repro go-librespot[6046]: time="2026-08-31T13:28:38+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 13:28:38 spla-repro go-librespot[6046]: time="2026-08-31T13:28:38+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 13:28:38 spla-repro go-librespot[6046]: time="2026-08-31T13:28:38+02:00" level=info msg="zeroconf server listening on port 41171" Aug 31 13:28:38 spla-repro go-librespot[6046]: time="2026-08-31T13:28:38+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 13:28:38 spla-repro go-librespot[6046]: time="2026-08-31T13:28:38+02:00" level=debug msg="obtained new client token: AAEwLMa9gmIHRkBEOyp2Lr7BqEFHoMrRyKXzBs4b/mSyoXS12Lf4o/OxttEd8nh/Tc2dD8Xyrln+oBIZHcEKgMabfHR7rbRLO1hYZwLl2zgLkFppcRXp31r0UuMlkFmlUV7vsZRHlqsPkJMHECB/tUFyPV6ablHiVZOms5ijYuDyIANsIFPwUwmnQAG0x4HZZdam4ExDG1EozKJwWF6G40sk6xoamnOOf9jpM5uc6UMh1fYyVt8GpRI=" Aug 31 13:28:38 spla-repro go-librespot[6046]: time="2026-08-31T13:28:38+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 31 13:28:38 spla-repro go-librespot[6046]: time="2026-08-31T13:28:38+02:00" level=debug msg="completed keyexchange" Aug 31 13:28:38 spla-repro go-librespot[6046]: time="2026-08-31T13:28:38+02:00" level=debug msg="completed challenge" Aug 31 13:28:38 spla-repro go-librespot[6046]: time="2026-08-31T13:28:38+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 31 13:28:38 spla-repro go-librespot[6046]: time="2026-08-31T13:28:38+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 13:28:38 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 13:28:38 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 13:28:40 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:40 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:41 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Aug 31 13:28:41 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:41 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:41 spla-repro go-librespot[6056]: go-librespot daemon starting... Aug 31 13:28:41 spla-repro go-librespot[6057]: time="2026-08-31T13:28:41+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:28:41 spla-repro go-librespot[6057]: time="2026-08-31T13:28:41+02:00" level=debug msg="app state loaded" Aug 31 13:28:41 spla-repro go-librespot[6057]: time="2026-08-31T13:28:41+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:28:42 spla-repro go-librespot[6057]: time="2026-08-31T13:28:42+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 13:28:42 spla-repro go-librespot[6057]: time="2026-08-31T13:28:42+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 13:28:42 spla-repro go-librespot[6057]: time="2026-08-31T13:28:42+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 13:28:42 spla-repro go-librespot[6057]: time="2026-08-31T13:28:42+02:00" level=info msg="zeroconf server listening on port 39227" Aug 31 13:28:42 spla-repro go-librespot[6057]: time="2026-08-31T13:28:42+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 13:28:42 spla-repro go-librespot[6057]: time="2026-08-31T13:28:42+02:00" level=debug msg="obtained new client token: AAFLkIIDg5L2vZXNylbZiN7fjquUsc078mCY9WCGG2ld6QJFnibQ8VB2864hAR932HAaANVfc+SQjvBkCDrjPJBjQZYhWyna77a8LD4H2H/qbWtaKEy0byRA9yZ1uM68D+nrt9F6rKei7zsiw7lupqRzuLGT0NKa5C9azjAbsDJ/kHdexaIqx1YZz3awHNicak6h+dE1W67w8b5OzyYdPOX5MIV7oY9Z0rJrV3S5hiLrQtc+nSUgy28=" Aug 31 13:28:42 spla-repro go-librespot[6057]: time="2026-08-31T13:28:42+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 31 13:28:42 spla-repro go-librespot[6057]: time="2026-08-31T13:28:42+02:00" level=debug msg="completed keyexchange" Aug 31 13:28:42 spla-repro go-librespot[6057]: time="2026-08-31T13:28:42+02:00" level=debug msg="completed challenge" Aug 31 13:28:42 spla-repro go-librespot[6057]: time="2026-08-31T13:28:42+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 31 13:28:42 spla-repro go-librespot[6057]: time="2026-08-31T13:28:42+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 13:28:42 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 13:28:42 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 13:28:43 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:43 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:45 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Aug 31 13:28:45 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:45 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:45 spla-repro go-librespot[6080]: go-librespot daemon starting... Aug 31 13:28:45 spla-repro go-librespot[6081]: time="2026-08-31T13:28:45+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:28:45 spla-repro go-librespot[6081]: time="2026-08-31T13:28:45+02:00" level=debug msg="app state loaded" Aug 31 13:28:45 spla-repro go-librespot[6081]: time="2026-08-31T13:28:45+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:28:46 spla-repro go-librespot[6081]: time="2026-08-31T13:28:46+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 13:28:46 spla-repro go-librespot[6081]: time="2026-08-31T13:28:46+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 13:28:46 spla-repro go-librespot[6081]: time="2026-08-31T13:28:46+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 13:28:46 spla-repro go-librespot[6081]: time="2026-08-31T13:28:46+02:00" level=info msg="zeroconf server listening on port 38759" Aug 31 13:28:46 spla-repro go-librespot[6081]: time="2026-08-31T13:28:46+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 13:28:46 spla-repro go-librespot[6081]: time="2026-08-31T13:28:46+02:00" level=debug msg="obtained new client token: AAH0LprpaJtpkTSJ1UOLK28k6P7RGX0st+fgGqivv+wPSfAv07keTXSOXvbl7G3aiAcWNQz51gNn8ZlZ9mOLr8YtqgTtgBZfw6jVf1Yy/E2OgZOFeIUKt04uvrH6ysaLcqXFJxnkHG9tN4kZB6cKQFezqvby29RQNr6egMBv9bI0qJEt+D59P2THLhOBZKmOzJPufUxl2ii5aGUownWYrOliUBVIq57Bgf1aCSs3wAmompl/svp6RkE=" Aug 31 13:28:46 spla-repro go-librespot[6081]: time="2026-08-31T13:28:46+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 31 13:28:46 spla-repro go-librespot[6081]: time="2026-08-31T13:28:46+02:00" level=debug msg="completed keyexchange" Aug 31 13:28:46 spla-repro go-librespot[6081]: time="2026-08-31T13:28:46+02:00" level=debug msg="completed challenge" Aug 31 13:28:46 spla-repro go-librespot[6081]: time="2026-08-31T13:28:46+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 31 13:28:46 spla-repro go-librespot[6081]: time="2026-08-31T13:28:46+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 13:28:46 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 13:28:46 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 13:28:46 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:46 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:47 spla-repro volumio[5528]: info: CoreCommandRouter::volumioGetState Aug 31 13:28:47 spla-repro volumio[5528]: info: CorePlayQueue::getTrack 0 Aug 31 13:28:47 spla-repro volumio[5528]: info: Listing playlists Aug 31 13:28:47 spla-repro volumio[5528]: info: Listing playlists Aug 31 13:28:49 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:49 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:49 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Aug 31 13:28:49 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:49 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:49 spla-repro go-librespot[6090]: go-librespot daemon starting... Aug 31 13:28:49 spla-repro go-librespot[6091]: time="2026-08-31T13:28:49+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:28:49 spla-repro go-librespot[6091]: time="2026-08-31T13:28:49+02:00" level=debug msg="app state loaded" Aug 31 13:28:49 spla-repro go-librespot[6091]: time="2026-08-31T13:28:49+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:28:50 spla-repro go-librespot[6091]: time="2026-08-31T13:28:50+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 13:28:50 spla-repro go-librespot[6091]: time="2026-08-31T13:28:50+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 13:28:50 spla-repro go-librespot[6091]: time="2026-08-31T13:28:50+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 13:28:50 spla-repro go-librespot[6091]: time="2026-08-31T13:28:50+02:00" level=info msg="zeroconf server listening on port 37545" Aug 31 13:28:50 spla-repro go-librespot[6091]: time="2026-08-31T13:28:50+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 13:28:50 spla-repro go-librespot[6091]: time="2026-08-31T13:28:50+02:00" level=debug msg="obtained new client token: AAHAosZTAR5rJyEZWayHzB8mBD0jG1htZabhzsVmncxKWdJcqoNcKYaqr4h0ktLGW6Tgr+TljUH4y5QDHWNdqpe6jfJYJXs80+3grSLkKG8ZJ1tFVr9GILEQTVE4+9jpvnXD4wry70eEv+zonXNFlsVerJ+dOmJ5ZANAVDLdxPqq+moumrU0dtN6gXCEG9mifLTEPiUvhTq8ooeACMtb5a+wJtPuSjgqW+H6DDAIAg3Q/yY8FND1Fus=" Aug 31 13:28:50 spla-repro go-librespot[6091]: time="2026-08-31T13:28:50+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 31 13:28:50 spla-repro go-librespot[6091]: time="2026-08-31T13:28:50+02:00" level=debug msg="completed keyexchange" Aug 31 13:28:50 spla-repro go-librespot[6091]: time="2026-08-31T13:28:50+02:00" level=debug msg="completed challenge" Aug 31 13:28:50 spla-repro go-librespot[6091]: time="2026-08-31T13:28:50+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 31 13:28:50 spla-repro go-librespot[6091]: time="2026-08-31T13:28:50+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 13:28:50 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 13:28:50 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 13:28:52 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:52 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:53 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Aug 31 13:28:53 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:53 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:53 spla-repro go-librespot[6114]: go-librespot daemon starting... Aug 31 13:28:53 spla-repro go-librespot[6115]: time="2026-08-31T13:28:53+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:28:53 spla-repro go-librespot[6115]: time="2026-08-31T13:28:53+02:00" level=debug msg="app state loaded" Aug 31 13:28:53 spla-repro go-librespot[6115]: time="2026-08-31T13:28:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:28:54 spla-repro go-librespot[6115]: time="2026-08-31T13:28:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 13:28:54 spla-repro go-librespot[6115]: time="2026-08-31T13:28:54+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 13:28:54 spla-repro go-librespot[6115]: time="2026-08-31T13:28:54+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 13:28:54 spla-repro go-librespot[6115]: time="2026-08-31T13:28:54+02:00" level=info msg="zeroconf server listening on port 43493" Aug 31 13:28:54 spla-repro go-librespot[6115]: time="2026-08-31T13:28:54+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 13:28:54 spla-repro go-librespot[6115]: time="2026-08-31T13:28:54+02:00" level=debug msg="obtained new client token: AAHZyxA61W+PsQgNwWnXyyaHQuymlXhoiflRojCm89n9LgvJeEgcEYEXilBzE7Tq5zyfHVQojIhcdy0IaHK9lLTl537s8+ew14ouEjyq3QcCx2BmJ7Ixcwq1FISAozS1760xxl1lbGE1jHke+hd3KXoPY0ioqDfRoZ6Iim6TPzHO/zuVfcVSWETa/vEeU3Zwz4UxB5euMHNdGRHeD2z9ay+WZ1EPFH9qUOS+2fehTMvn1YXsLid4nmY=" Aug 31 13:28:54 spla-repro go-librespot[6115]: time="2026-08-31T13:28:54+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 31 13:28:54 spla-repro go-librespot[6115]: time="2026-08-31T13:28:54+02:00" level=debug msg="completed keyexchange" Aug 31 13:28:54 spla-repro go-librespot[6115]: time="2026-08-31T13:28:54+02:00" level=debug msg="completed challenge" Aug 31 13:28:54 spla-repro go-librespot[6115]: time="2026-08-31T13:28:54+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 31 13:28:54 spla-repro go-librespot[6115]: time="2026-08-31T13:28:54+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 13:28:54 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 13:28:54 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 13:28:55 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:55 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:28:57 spla-repro volumio[5528]: info: CoreCommandRouter::volumioGetState Aug 31 13:28:57 spla-repro volumio[5528]: info: CorePlayQueue::getTrack 0 Aug 31 13:28:57 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Aug 31 13:28:57 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:57 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:28:57 spla-repro go-librespot[6124]: go-librespot daemon starting... Aug 31 13:28:57 spla-repro go-librespot[6125]: time="2026-08-31T13:28:57+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:28:57 spla-repro go-librespot[6125]: time="2026-08-31T13:28:57+02:00" level=debug msg="app state loaded" Aug 31 13:28:57 spla-repro go-librespot[6125]: time="2026-08-31T13:28:57+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:28:57 spla-repro go-librespot[6125]: time="2026-08-31T13:28:57+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 13:28:57 spla-repro go-librespot[6125]: time="2026-08-31T13:28:57+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 13:28:57 spla-repro go-librespot[6125]: time="2026-08-31T13:28:57+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 13:28:57 spla-repro go-librespot[6125]: time="2026-08-31T13:28:57+02:00" level=info msg="zeroconf server listening on port 36761" Aug 31 13:28:57 spla-repro go-librespot[6125]: time="2026-08-31T13:28:57+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 13:28:57 spla-repro go-librespot[6125]: time="2026-08-31T13:28:57+02:00" level=debug msg="obtained new client token: AAHAp5psHn3O57K5yooEw54j7Q7ift2tgN9YZ8iWL6goXVVNf0Gm+Wej7IGa4+EtU3pYuTLnax1X7BHGY/lBBJt+P/zIXOV3f1+8nc/9pQQv3Tt9y8Fu30QTVaKttU+474WaD/yb++pkMNXJXHMPZftYfrCqjAuK0YQpqlvAaeeSZvRTXLrc/Vf/B8iOsni7Yhiv84towM6h49ZLQ5b/7mTcLUQk1TtRk0in3okln5e8Nkdx/FZ0pJ4g7g==" Aug 31 13:28:58 spla-repro go-librespot[6125]: time="2026-08-31T13:28:58+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 31 13:28:58 spla-repro go-librespot[6125]: time="2026-08-31T13:28:58+02:00" level=debug msg="completed keyexchange" Aug 31 13:28:58 spla-repro go-librespot[6125]: time="2026-08-31T13:28:58+02:00" level=debug msg="completed challenge" Aug 31 13:28:58 spla-repro go-librespot[6125]: time="2026-08-31T13:28:58+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 31 13:28:58 spla-repro go-librespot[6125]: time="2026-08-31T13:28:58+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 13:28:58 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 13:28:58 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 13:28:58 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:28:58 spla-repro volumio[5528]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:29:01 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Aug 31 13:29:01 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:29:01 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:29:01 spla-repro go-librespot[6135]: go-librespot daemon starting... Aug 31 13:29:01 spla-repro go-librespot[6136]: time="2026-08-31T13:29:01+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:29:01 spla-repro go-librespot[6136]: time="2026-08-31T13:29:01+02:00" level=debug msg="app state loaded" Aug 31 13:29:01 spla-repro go-librespot[6136]: time="2026-08-31T13:29:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:29:01 spla-repro volumio[5528]: info: Initializing connection to go-librespot Websocket Aug 31 13:29:01 spla-repro go-librespot[6136]: time="2026-08-31T13:29:01+02:00" level=debug msg="new websocket client" Aug 31 13:29:01 spla-repro volumio[5528]: info: Connection to go-librespot Websocket established Aug 31 13:29:01 spla-repro go-librespot[6136]: time="2026-08-31T13:29:01+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Aug 31 13:29:01 spla-repro go-librespot[6136]: time="2026-08-31T13:29:01+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Aug 31 13:29:01 spla-repro go-librespot[6136]: time="2026-08-31T13:29:01+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Aug 31 13:29:01 spla-repro go-librespot[6136]: time="2026-08-31T13:29:01+02:00" level=info msg="zeroconf server listening on port 33337" Aug 31 13:29:01 spla-repro go-librespot[6136]: time="2026-08-31T13:29:01+02:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Aug 31 13:29:01 spla-repro go-librespot[6136]: time="2026-08-31T13:29:01+02:00" level=debug msg="obtained new client token: AAF19iQXRJUjLkbJyKmrGJHlOcfzV9qfGKspScvKKxvCz9Yjzg4+hhCL7PlXYgEr7tN1qd3V2thOggCXD/3B+LEMzV3etdc/WsmiPAMahB9IxmETXWJ8gqbuhU+0wJDZjywaBOxxBna4YFPJnGdoIQ4ZDysocdI73b3LYcbg5mwk/2T55THY8XuhoU+oO4XVThR/qg+yXyPpiGDISHVt6wS3h3Iqiv7FJylshHhJcK5PPsPx9eB96UFZ3A==" Aug 31 13:29:02 spla-repro go-librespot[6136]: time="2026-08-31T13:29:02+02:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Aug 31 13:29:02 spla-repro go-librespot[6136]: time="2026-08-31T13:29:02+02:00" level=debug msg="completed keyexchange" Aug 31 13:29:02 spla-repro go-librespot[6136]: time="2026-08-31T13:29:02+02:00" level=debug msg="completed challenge" Aug 31 13:29:02 spla-repro go-librespot[6136]: time="2026-08-31T13:29:02+02:00" level=info msg="authenticated AP" username="4b*********************lb" Aug 31 13:29:02 spla-repro go-librespot[6136]: time="2026-08-31T13:29:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: INVALID_CREDENTIALS" Aug 31 13:29:02 spla-repro volumio[5528]: info: Connection to go-librespot Websocket closed Aug 31 13:29:02 spla-repro systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 13:29:02 spla-repro systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 13:29:04 spla-repro volumio[5528]: info: Getting Spotify volume Aug 31 13:29:04 spla-repro volumio[5528]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 13:29:04 spla-repro volumio[5528]: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 31 13:29:04 spla-repro volumio[5528]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 31 13:29:04 spla-repro volumio[5528]: errno: -111, Aug 31 13:29:04 spla-repro volumio[5528]: code: 'ECONNREFUSED', Aug 31 13:29:04 spla-repro volumio[5528]: syscall: 'connect', Aug 31 13:29:04 spla-repro volumio[5528]: address: '127.0.0.1', Aug 31 13:29:04 spla-repro volumio[5528]: port: 9879, Aug 31 13:29:04 spla-repro volumio[5528]: response: undefined Aug 31 13:29:04 spla-repro volumio[5528]: } Aug 31 13:29:04 spla-repro volumio[5528]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 13:29:05 spla-repro systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Aug 31 13:29:05 spla-repro systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:29:05 spla-repro systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 31 13:29:05 spla-repro go-librespot[6172]: go-librespot daemon starting... Aug 31 13:29:05 spla-repro go-librespot[6173]: time="2026-08-31T13:29:05+02:00" level=info msg="running go-librespot 0.7.1" Aug 31 13:29:05 spla-repro go-librespot[6173]: time="2026-08-31T13:29:05+02:00" level=debug msg="app state loaded" Aug 31 13:29:05 spla-repro go-librespot[6173]: time="2026-08-31T13:29:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 31 13:29:05 spla-repro sudo[6183]: volumio : unable to resolve host spla-repro: System error Aug 31 13:29:05 spla-repro sudo[6183]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 13:28' Aug 31 13:29:05 spla-repro sudo[6183]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"