Dec 05 14:05:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 05 14:05:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:00 volumio go-librespot[16067]: go-librespot daemon starting... Dec 05 14:05:00 volumio go-librespot[16068]: time="2025-12-05T14:05:00-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:05:00 volumio go-librespot[16068]: time="2025-12-05T14:05:00-06:00" level=debug msg="app state loaded" Dec 05 14:05:00 volumio go-librespot[16068]: time="2025-12-05T14:05:00-06:00" level=debug msg="stored credentials not found" Dec 05 14:05:00 volumio go-librespot[16068]: time="2025-12-05T14:05:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:05:00 volumio go-librespot[16068]: time="2025-12-05T14:05:00-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 05 14:05:00 volumio go-librespot[16068]: time="2025-12-05T14:05:00-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 05 14:05:00 volumio go-librespot[16068]: time="2025-12-05T14:05:00-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 05 14:05:00 volumio go-librespot[16068]: time="2025-12-05T14:05:00-06:00" level=info msg="zeroconf server listening on port 34387" Dec 05 14:05:01 volumio go-librespot[16068]: time="2025-12-05T14:05:01-06:00" level=debug msg="obtained new client token: AAAZct8U/ttbr9ToVzVMueUOE1Nyvw9uV0uCd6mOLOfEI4k/uGJXS9AhIKKCNhfxCSKbB6HWCA+zXbIcy8VAPgBr8Bro0juzwAMTD+mrMagRtgRlPKLvYI/rwBfDtD1xji4FOE9H/HCatrPJ6bGKyJE271hw9jImpK6561SLXzw74+hguhrcR0B0kxM9I3lRi0R25gO9gR+ydoCI9Nh8USzyxUpu2w9Qd14pAWcdcO1RDPYEr/N4raG48A==" Dec 05 14:05:01 volumio go-librespot[16068]: time="2025-12-05T14:05:01-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:05:01 volumio go-librespot[16068]: time="2025-12-05T14:05:01-06:00" level=debug msg="completed keyexchange" Dec 05 14:05:01 volumio go-librespot[16068]: time="2025-12-05T14:05:01-06:00" level=debug msg="completed challenge" Dec 05 14:05:01 volumio go-librespot[16068]: time="2025-12-05T14:05:01-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:05:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:05:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:05:02 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:02 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 05 14:05:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:04 volumio go-librespot[16077]: go-librespot daemon starting... Dec 05 14:05:04 volumio go-librespot[16078]: time="2025-12-05T14:05:04-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:05:04 volumio go-librespot[16078]: time="2025-12-05T14:05:04-06:00" level=debug msg="app state loaded" Dec 05 14:05:04 volumio go-librespot[16078]: time="2025-12-05T14:05:04-06:00" level=debug msg="stored credentials not found" Dec 05 14:05:04 volumio go-librespot[16078]: time="2025-12-05T14:05:04-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:05:04 volumio go-librespot[16078]: time="2025-12-05T14:05:04-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 05 14:05:04 volumio go-librespot[16078]: time="2025-12-05T14:05:04-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 05 14:05:04 volumio go-librespot[16078]: time="2025-12-05T14:05:04-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 05 14:05:04 volumio go-librespot[16078]: time="2025-12-05T14:05:04-06:00" level=info msg="zeroconf server listening on port 33837" Dec 05 14:05:04 volumio go-librespot[16078]: time="2025-12-05T14:05:04-06:00" level=debug msg="obtained new client token: AAAwUFdF1smwQP77EBbX0bf/NQ+FUBL9A/bpFO8RonrI+/lTMCajre46UWEc+i3pyZvJnopavdzMW2aWp/FxSVZxgnJqSw/xNk0OAGl4HuV54iaEVBQ9VxFJIb/ZgxwD6gNYMYp3CK6LxZ7gx4s17TG8eeZi7xIelYo2cWlgUadHO5KRUZg46QObxqP3NX+6mp2QYewmt55Tq0txsRbtK0pDdm7zorLx51nYTc1560L5I2IFMbrys4q2eQ==" Dec 05 14:05:04 volumio go-librespot[16078]: time="2025-12-05T14:05:04-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:05:04 volumio go-librespot[16078]: time="2025-12-05T14:05:04-06:00" level=debug msg="completed keyexchange" Dec 05 14:05:04 volumio go-librespot[16078]: time="2025-12-05T14:05:04-06:00" level=debug msg="completed challenge" Dec 05 14:05:05 volumio go-librespot[16078]: time="2025-12-05T14:05:05-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:05:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:05:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 05 14:05:05 volumio volumio[15600]: info: Adding plugin bluetooth to MyMusic Plugins Dec 05 14:05:05 volumio volumio[15600]: info: Adding plugin multiroom to MyMusic Plugins Dec 05 14:05:05 volumio volumio[15600]: info: Adding plugin metavolumio to MyMusic Plugins Dec 05 14:05:05 volumio volumio[15600]: info: Adding plugin cd_controller to MyMusic Plugins Dec 05 14:05:05 volumio volumio[15600]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 05 14:05:05 volumio volumio[15600]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 05 14:05:05 volumio volumio[15600]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 05 14:05:05 volumio volumio[15600]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 05 14:05:06 volumio volumio[15600]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 05 14:05:06 volumio volumio[15600]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 05 14:05:06 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 14:05:06 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 14:05:06 volumio volumio[15600]: info: Starting MyVolumio Remote Streaming Endpoints Dec 05 14:05:06 volumio volumio[15600]: info: MyVolumio login type: Token Dec 05 14:05:06 volumio volumio[15600]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 05 14:05:06 volumio volumio[15600]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 05 14:05:07 volumio volumio[15600]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 05 14:05:07 volumio volumio[15600]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 05 14:05:07 volumio volumio[15600]: info: Streaming services startup Dec 05 14:05:07 volumio volumio[15600]: info: Starting Streaming Daemon Dec 05 14:05:07 volumio sudo[16100]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 05 14:05:07 volumio sudo[16100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 14:05:07 volumio volumio[15600]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 05 14:05:07 volumio sudo[16100]: pam_unix(sudo:session): session closed for user root Dec 05 14:05:07 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:07 volumio volumio[15600]: error: Cannot start Volumio Streaming Daemon Dec 05 14:05:07 volumio volumio[15600]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 05 14:05:07 volumio volumio[15600]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 05 14:05:07 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:07 volumio volumio[15600]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 05 14:05:08 volumio volumio[15600]: info: MyVolumio token set successfully Dec 05 14:05:08 volumio volumio[15600]: info: MYVOLUMIO: Adding device Dec 05 14:05:08 volumio volumio[15600]: info: MYVOLUMIO: Evaluating Server Dec 05 14:05:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 05 14:05:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:08 volumio go-librespot[16110]: go-librespot daemon starting... Dec 05 14:05:08 volumio go-librespot[16120]: time="2025-12-05T14:05:08-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:05:08 volumio go-librespot[16120]: time="2025-12-05T14:05:08-06:00" level=debug msg="app state loaded" Dec 05 14:05:08 volumio go-librespot[16120]: time="2025-12-05T14:05:08-06:00" level=debug msg="stored credentials not found" Dec 05 14:05:08 volumio go-librespot[16120]: time="2025-12-05T14:05:08-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:05:08 volumio volumio[15600]: info: MyVolumio status changed Dec 05 14:05:08 volumio volumio[15600]: info: Streaming services startup Dec 05 14:05:08 volumio volumio[15600]: info: Starting Streaming Daemon Dec 05 14:05:08 volumio volumio[15600]: info: Removing browser output: myVolumio user plan is not superstar Dec 05 14:05:08 volumio volumio[15600]: info: Removing audio output: Dec 05 14:05:08 volumio volumio[15600]: info: Stoppping Tunnel 1 Dec 05 14:05:08 volumio sudo[16134]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 05 14:05:08 volumio sudo[16134]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 14:05:08 volumio sudo[16136]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 05 14:05:08 volumio sudo[16136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 05 14:05:08 volumio sudo[16134]: pam_unix(sudo:session): session closed for user root Dec 05 14:05:08 volumio 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. Dec 05 14:05:08 volumio 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. Dec 05 14:05:08 volumio volumio[15600]: error: Cannot start Volumio Streaming Daemon Dec 05 14:05:08 volumio volumio[15600]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 05 14:05:08 volumio volumio[15600]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 05 14:05:08 volumio 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. Dec 05 14:05:08 volumio 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. Dec 05 14:05:08 volumio 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. Dec 05 14:05:08 volumio 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. Dec 05 14:05:08 volumio 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. Dec 05 14:05:08 volumio 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. Dec 05 14:05:08 volumio sudo[16136]: pam_unix(sudo:session): session closed for user root Dec 05 14:05:08 volumio volumio[15600]: info: Remote SSH Stopped Dec 05 14:05:08 volumio go-librespot[16120]: time="2025-12-05T14:05:08-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 05 14:05:08 volumio go-librespot[16120]: time="2025-12-05T14:05:08-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 05 14:05:08 volumio go-librespot[16120]: time="2025-12-05T14:05:08-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 05 14:05:08 volumio go-librespot[16120]: time="2025-12-05T14:05:08-06:00" level=info msg="zeroconf server listening on port 41663" Dec 05 14:05:08 volumio volumio[15600]: info: Setting Geolocation for MyVolumio to us1 Dec 05 14:05:08 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 14:05:08 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 14:05:08 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 14:05:08 volumio go-librespot[16120]: time="2025-12-05T14:05:08-06:00" level=debug msg="obtained new client token: AAD/Vy3HIx3AnKuLiKqYzxvUoKSSjhyavh1CFU0ViJPPCB9nmr5tt+fPvd7TSxs8yIoTU+nQSB/5eBhYh7v8qNYk4frgg8vyW2eKFm3l9BNQyMUv4R9hEwfp+Sk8kMvEteqWt50hwVW0ogzg/kcj2OlXFZ69Nnye5BJGc2LJtgg6pYfjNyXqa1t68DC3sxgc2ziMkrfzP6nBCIKdNn2h5gvXhkvV4DzJkOeY2FOekFuUNSR8ZAcaMl6A9Q==" Dec 05 14:05:08 volumio go-librespot[16120]: time="2025-12-05T14:05:08-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:05:08 volumio volumio[15600]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 05 14:05:08 volumio go-librespot[16120]: time="2025-12-05T14:05:08-06:00" level=debug msg="completed keyexchange" Dec 05 14:05:08 volumio go-librespot[16120]: time="2025-12-05T14:05:08-06:00" level=debug msg="completed challenge" Dec 05 14:05:08 volumio go-librespot[16120]: time="2025-12-05T14:05:08-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:05:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:05:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:05:09 volumio volumio[15600]: info: Updating MyVolumio device info Dec 05 14:05:09 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 14:05:09 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 14:05:09 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 14:05:09 volumio volumio[15600]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 05 14:05:10 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:10 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 05 14:05:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:11 volumio go-librespot[16140]: go-librespot daemon starting... Dec 05 14:05:12 volumio go-librespot[16141]: time="2025-12-05T14:05:12-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:05:12 volumio go-librespot[16141]: time="2025-12-05T14:05:12-06:00" level=debug msg="app state loaded" Dec 05 14:05:12 volumio go-librespot[16141]: time="2025-12-05T14:05:12-06:00" level=debug msg="stored credentials not found" Dec 05 14:05:12 volumio go-librespot[16141]: time="2025-12-05T14:05:12-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:05:12 volumio go-librespot[16141]: time="2025-12-05T14:05:12-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 05 14:05:12 volumio go-librespot[16141]: time="2025-12-05T14:05:12-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 05 14:05:12 volumio go-librespot[16141]: time="2025-12-05T14:05:12-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 05 14:05:12 volumio go-librespot[16141]: time="2025-12-05T14:05:12-06:00" level=info msg="zeroconf server listening on port 37111" Dec 05 14:05:12 volumio go-librespot[16141]: time="2025-12-05T14:05:12-06:00" level=debug msg="obtained new client token: AABeAg0D9hPHsuP7vlDe9XaDAVXCA3TVcTmViykvBChN13ePTLEAH8Cmzurm0swxEuS/SDcYcnfzwmzWzMOiwkf+pfhetIdeZHtxkiKz2qALmtb8/LdHiB+CBO0EU2Ity3wmsgvHaOU786SCZW2lBd94FFSFKDjjuB35XQ3S6bu/0836lrGg8R99v9dlPX3MUV33WuChwJOOgck6+PO2S3gR7zcWRGNtpvuuiq6BRDHeL9Jkt6TUu6xQZg==" Dec 05 14:05:12 volumio go-librespot[16141]: time="2025-12-05T14:05:12-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:05:12 volumio go-librespot[16141]: time="2025-12-05T14:05:12-06:00" level=debug msg="completed keyexchange" Dec 05 14:05:12 volumio go-librespot[16141]: time="2025-12-05T14:05:12-06:00" level=debug msg="completed challenge" Dec 05 14:05:12 volumio go-librespot[16141]: time="2025-12-05T14:05:12-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:05:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:05:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:05:12 volumio volumio[15600]: info: MYVOLUMIO: Adding device Dec 05 14:05:12 volumio volumio[15600]: info: MYVOLUMIO: Evaluating Server Dec 05 14:05:13 volumio volumio[15600]: info: Setting Geolocation for MyVolumio to us4 Dec 05 14:05:13 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 14:05:13 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 14:05:13 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 14:05:13 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:13 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:13 volumio volumio[15600]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 05 14:05:14 volumio volumio[15600]: info: Updating MyVolumio device info Dec 05 14:05:14 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 14:05:14 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 14:05:14 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 14:05:14 volumio volumio[15600]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 05 14:05:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 05 14:05:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:15 volumio go-librespot[16180]: go-librespot daemon starting... Dec 05 14:05:15 volumio go-librespot[16181]: time="2025-12-05T14:05:15-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:05:15 volumio go-librespot[16181]: time="2025-12-05T14:05:15-06:00" level=debug msg="app state loaded" Dec 05 14:05:15 volumio go-librespot[16181]: time="2025-12-05T14:05:15-06:00" level=debug msg="stored credentials not found" Dec 05 14:05:15 volumio go-librespot[16181]: time="2025-12-05T14:05:15-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:05:15 volumio go-librespot[16181]: time="2025-12-05T14:05:15-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 05 14:05:15 volumio go-librespot[16181]: time="2025-12-05T14:05:15-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 05 14:05:15 volumio go-librespot[16181]: time="2025-12-05T14:05:15-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 05 14:05:16 volumio go-librespot[16181]: time="2025-12-05T14:05:16-06:00" level=info msg="zeroconf server listening on port 40537" Dec 05 14:05:16 volumio go-librespot[16181]: time="2025-12-05T14:05:16-06:00" level=debug msg="obtained new client token: AABJxSKQpzljualnFbdhDF0q0FBRmIbfzgXnhb1CL6dYUvzc52ifeuFOOxeuoFAKScRTYc++8Lb7ssgCxuxx//pGqhPocFDVVrM3m7krnao0UDhR5+9yScuQwSNLZzb00AWRDk8nAfHB4rpZD8s5sC9K7oBfcf8agP31JQq4KE8xH4//Uq5i8sUdeV/tQVApg5haZ9XjDhU2r4QUO+OMesmRCIVutlSB4qEMUglr3rk4cBJnix4Y9kQ=" Dec 05 14:05:16 volumio go-librespot[16181]: time="2025-12-05T14:05:16-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:05:16 volumio go-librespot[16181]: time="2025-12-05T14:05:16-06:00" level=debug msg="completed keyexchange" Dec 05 14:05:16 volumio go-librespot[16181]: time="2025-12-05T14:05:16-06:00" level=debug msg="completed challenge" Dec 05 14:05:16 volumio go-librespot[16181]: time="2025-12-05T14:05:16-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:05:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:05:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:05:16 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:16 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:18 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 05 14:05:18 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 14:05:18 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 05 14:05:18 volumio volumio-remote-updater[2353]: Test mode disabled Dec 05 14:05:18 volumio volumio-remote-updater[2353]: Alpha mode disabled Dec 05 14:05:18 volumio volumio-remote-updater[2353]: Alpha legacy test mode disabled Dec 05 14:05:18 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 05 14:05:18 volumio volumio[15600]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

ANNOUNCEMENT

\n
    \n
  • Production line
    • \n
\n

FIX

\n
    \n
  • Fix for TIDAL low quality (AAC) playback
    • \n
\n","title":"Update v4.072","updateavailable":true} Dec 05 14:05:18 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 05 14:05:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 05 14:05:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:19 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:19 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:19 volumio go-librespot[16196]: go-librespot daemon starting... Dec 05 14:05:19 volumio go-librespot[16197]: time="2025-12-05T14:05:19-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:05:19 volumio go-librespot[16197]: time="2025-12-05T14:05:19-06:00" level=debug msg="app state loaded" Dec 05 14:05:19 volumio go-librespot[16197]: time="2025-12-05T14:05:19-06:00" level=debug msg="stored credentials not found" Dec 05 14:05:19 volumio go-librespot[16197]: time="2025-12-05T14:05:19-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:05:19 volumio go-librespot[16197]: time="2025-12-05T14:05:19-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 05 14:05:19 volumio go-librespot[16197]: time="2025-12-05T14:05:19-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 05 14:05:19 volumio go-librespot[16197]: time="2025-12-05T14:05:19-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 05 14:05:19 volumio go-librespot[16197]: time="2025-12-05T14:05:19-06:00" level=info msg="zeroconf server listening on port 43419" Dec 05 14:05:19 volumio go-librespot[16197]: time="2025-12-05T14:05:19-06:00" level=debug msg="obtained new client token: AADHIcbkiBiXws85aIJY8UYp3W//AE/hx9S4t41aUefaVetLyusq1XptL79OeieekZ0krZd24xzleE0E2Xz+sM4TXZwDJ3hAXFrX7EWeD/eK2daJwg3th93esW0Q8LGjG4JT5RARua+au8lumqB5k7caL1sNUZfcAXpySuBn5z1W6x85RxpZItFLSwQkg/MWU6/fqnKlS6f2ybfzli/td1DU7aFAqfzsQ5Tv78DjmcR+3vTJpEodS0p6uw==" Dec 05 14:05:19 volumio go-librespot[16197]: time="2025-12-05T14:05:19-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:05:19 volumio go-librespot[16197]: time="2025-12-05T14:05:19-06:00" level=debug msg="completed keyexchange" Dec 05 14:05:19 volumio go-librespot[16197]: time="2025-12-05T14:05:19-06:00" level=debug msg="completed challenge" Dec 05 14:05:20 volumio go-librespot[16197]: time="2025-12-05T14:05:20-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:05:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:05:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:05:21 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 05 14:05:21 volumio volumio[15600]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 05 14:05:21 volumio volumio[15600]: info: CoreCommandRouter::volumioGetState Dec 05 14:05:21 volumio volumio[15600]: info: CorePlayQueue::getTrack 0 Dec 05 14:05:22 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:22 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Dec 05 14:05:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:23 volumio go-librespot[16205]: go-librespot daemon starting... Dec 05 14:05:23 volumio go-librespot[16206]: time="2025-12-05T14:05:23-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:05:23 volumio go-librespot[16206]: time="2025-12-05T14:05:23-06:00" level=debug msg="app state loaded" Dec 05 14:05:23 volumio go-librespot[16206]: time="2025-12-05T14:05:23-06:00" level=debug msg="stored credentials not found" Dec 05 14:05:23 volumio go-librespot[16206]: time="2025-12-05T14:05:23-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:05:23 volumio go-librespot[16206]: time="2025-12-05T14:05:23-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 05 14:05:23 volumio go-librespot[16206]: time="2025-12-05T14:05:23-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 05 14:05:23 volumio go-librespot[16206]: time="2025-12-05T14:05:23-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 05 14:05:23 volumio go-librespot[16206]: time="2025-12-05T14:05:23-06:00" level=info msg="zeroconf server listening on port 45617" Dec 05 14:05:23 volumio go-librespot[16206]: time="2025-12-05T14:05:23-06:00" level=debug msg="obtained new client token: AACdGn8uxtacYPkOyQYIh0A9hRMUmstdd/L7dvagtB3D9rHwuLFjinvOqHuqC92NezMYprNxVdDZ1/g44z8cgbB+0qph8TUbrGj5zpSUW9urUZNsGL6xcruNaa5JTBuFhSPwtD7KlyVCBQl98pueM3ZaEbdv3bEvq8H7Q88KseBSDNuioCEGGziFFhvFbxwXWWMcPFAlicPVJxKi7x6XpGE8lyIi9E/2KRQ73FfjeTWOuMF2GntYWvpvug==" Dec 05 14:05:23 volumio go-librespot[16206]: time="2025-12-05T14:05:23-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:05:23 volumio go-librespot[16206]: time="2025-12-05T14:05:23-06:00" level=debug msg="completed keyexchange" Dec 05 14:05:23 volumio go-librespot[16206]: time="2025-12-05T14:05:23-06:00" level=debug msg="completed challenge" Dec 05 14:05:23 volumio go-librespot[16206]: time="2025-12-05T14:05:23-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:05:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:05:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:05:25 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:25 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:26 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 14:05:26 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 14:05:26 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 05 14:05:26 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 05 14:05:26 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 05 14:05:26 volumio volumio[15600]: info: CoreCommandRouter::volumioGetBrowseSources Dec 05 14:05:26 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 05 14:05:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Dec 05 14:05:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:26 volumio go-librespot[16227]: go-librespot daemon starting... Dec 05 14:05:27 volumio go-librespot[16228]: time="2025-12-05T14:05:27-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:05:27 volumio go-librespot[16228]: time="2025-12-05T14:05:27-06:00" level=debug msg="app state loaded" Dec 05 14:05:27 volumio go-librespot[16228]: time="2025-12-05T14:05:27-06:00" level=debug msg="stored credentials not found" Dec 05 14:05:27 volumio go-librespot[16228]: time="2025-12-05T14:05:27-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:05:27 volumio go-librespot[16228]: time="2025-12-05T14:05:27-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 05 14:05:27 volumio go-librespot[16228]: time="2025-12-05T14:05:27-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 05 14:05:27 volumio go-librespot[16228]: time="2025-12-05T14:05:27-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 05 14:05:27 volumio go-librespot[16228]: time="2025-12-05T14:05:27-06:00" level=info msg="zeroconf server listening on port 36787" Dec 05 14:05:27 volumio go-librespot[16228]: time="2025-12-05T14:05:27-06:00" level=debug msg="obtained new client token: AACaT9EerEQX8F3bTZ1tHQTespY1U2xFzAq47tbCeZZx365CF/fMJbCC7SK1hZTC8rXeNmGF53EvCTMs+rw0IB35wR0zPk79lx8IJwn49vzo73Hra95HWQYX+sZV7mstNywblaNVVUGmvWH05v05vL9vUIqLF0dkqzgzokwCMi2QOwlb9hQX3fegVuGd3DHOCS9/UlOHrM1DACl7kTQVznwQf7UQsHwnXkI0Fzl4cYx4Jys1/IQ52YrRDQ==" Dec 05 14:05:27 volumio volumio[15600]: error: MyVolumio Plugin failed to authenticate in a timely fashion Dec 05 14:05:27 volumio volumio[15600]: info: Completed starting MyVolumio Plugin Dec 05 14:05:27 volumio volumio[15600]: [Metrics] CommandRouter: 54s 181.04ms Dec 05 14:05:27 volumio volumio[15600]: info: CoreCommandRouter::volumiosetStartupVolume Dec 05 14:05:27 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 05 14:05:27 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 05 14:05:27 volumio volumio[15600]: info: CoreCommandRouter::Close All Modals sent Dec 05 14:05:27 volumio volumio[15600]: info: CoreCommandRouter::Close All Modals sent Dec 05 14:05:27 volumio go-librespot[16228]: time="2025-12-05T14:05:27-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:05:27 volumio go-librespot[16228]: time="2025-12-05T14:05:27-06:00" level=debug msg="completed keyexchange" Dec 05 14:05:27 volumio go-librespot[16228]: time="2025-12-05T14:05:27-06:00" level=debug msg="completed challenge" Dec 05 14:05:27 volumio go-librespot[16228]: time="2025-12-05T14:05:27-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:05:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:05:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:05:28 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 05 14:05:28 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 05 14:05:28 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 05 14:05:28 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:28 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Dec 05 14:05:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:30 volumio go-librespot[16241]: go-librespot daemon starting... Dec 05 14:05:30 volumio go-librespot[16242]: time="2025-12-05T14:05:30-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:05:30 volumio go-librespot[16242]: time="2025-12-05T14:05:30-06:00" level=debug msg="app state loaded" Dec 05 14:05:30 volumio go-librespot[16242]: time="2025-12-05T14:05:30-06:00" level=debug msg="stored credentials not found" Dec 05 14:05:30 volumio go-librespot[16242]: time="2025-12-05T14:05:30-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:05:30 volumio go-librespot[16242]: time="2025-12-05T14:05:30-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 05 14:05:30 volumio go-librespot[16242]: time="2025-12-05T14:05:30-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 05 14:05:30 volumio go-librespot[16242]: time="2025-12-05T14:05:30-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 05 14:05:30 volumio go-librespot[16242]: time="2025-12-05T14:05:30-06:00" level=info msg="zeroconf server listening on port 35663" Dec 05 14:05:31 volumio go-librespot[16242]: time="2025-12-05T14:05:31-06:00" level=debug msg="obtained new client token: AACybgA4+v0XSx5kR6HQpGhweZGnKxyyb2YHo0Crr2MphQnbgAvqDiZ95PvduYolehxx44QVqM6OcyD56waEwK4COE7FscpCLTSQ+WxMu9nY+7RocCqPXmOXqhISaenxT+9Lf96/EnXdFh0JuloXC/DSTpiM1QoewPErwytFL4aL5hUo+cfYKmEiXkjh3r7fbl5CWnTBEtefqVWRF5UANhTH9u+QZFCzau3PtLcg/xZ7PvZcmBZset4=" Dec 05 14:05:31 volumio go-librespot[16242]: time="2025-12-05T14:05:31-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:05:31 volumio go-librespot[16242]: time="2025-12-05T14:05:31-06:00" level=debug msg="completed keyexchange" Dec 05 14:05:31 volumio go-librespot[16242]: time="2025-12-05T14:05:31-06:00" level=debug msg="completed challenge" Dec 05 14:05:31 volumio go-librespot[16242]: time="2025-12-05T14:05:31-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:05:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:05:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:05:31 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:31 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:34 volumio volumio[15600]: info: BOOT COMPLETED Dec 05 14:05:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Dec 05 14:05:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:34 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:34 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:34 volumio go-librespot[16249]: go-librespot daemon starting... Dec 05 14:05:34 volumio go-librespot[16250]: time="2025-12-05T14:05:34-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:05:34 volumio go-librespot[16250]: time="2025-12-05T14:05:34-06:00" level=debug msg="app state loaded" Dec 05 14:05:34 volumio go-librespot[16250]: time="2025-12-05T14:05:34-06:00" level=debug msg="stored credentials not found" Dec 05 14:05:34 volumio go-librespot[16250]: time="2025-12-05T14:05:34-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:05:34 volumio go-librespot[16250]: time="2025-12-05T14:05:34-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 05 14:05:34 volumio go-librespot[16250]: time="2025-12-05T14:05:34-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 05 14:05:34 volumio go-librespot[16250]: time="2025-12-05T14:05:34-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 05 14:05:34 volumio go-librespot[16250]: time="2025-12-05T14:05:34-06:00" level=info msg="zeroconf server listening on port 43625" Dec 05 14:05:34 volumio go-librespot[16250]: time="2025-12-05T14:05:34-06:00" level=debug msg="obtained new client token: AAC9H7WSMlwUNxim5MigGhAMwnXNECe24Uz7c07mGLTqohlRfpVNvvrj3/Dlv2Gl5onHklHubhV25vChRecAGTYSp1ujjNMQa98UcZrIJteGWAib+pPnXPXdmKZTntuDbaKcs4oaV3KAXx/IYMnkIMbIJIWA38e7PaDNinR0CCMzrICxumnYbA06SaLNtYCG/2z2nIZsa/lTqgPxVASmHuu4VqzzYJrZaAPtxgVMKfmlR8QZA6QeNrTKbg==" Dec 05 14:05:34 volumio go-librespot[16250]: time="2025-12-05T14:05:34-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:05:34 volumio go-librespot[16250]: time="2025-12-05T14:05:34-06:00" level=debug msg="completed keyexchange" Dec 05 14:05:34 volumio go-librespot[16250]: time="2025-12-05T14:05:34-06:00" level=debug msg="completed challenge" Dec 05 14:05:34 volumio go-librespot[16250]: time="2025-12-05T14:05:34-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:05:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:05:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:05:37 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:37 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Dec 05 14:05:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:38 volumio go-librespot[16274]: go-librespot daemon starting... Dec 05 14:05:38 volumio go-librespot[16275]: time="2025-12-05T14:05:38-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:05:38 volumio go-librespot[16275]: time="2025-12-05T14:05:38-06:00" level=debug msg="app state loaded" Dec 05 14:05:38 volumio go-librespot[16275]: time="2025-12-05T14:05:38-06:00" level=debug msg="stored credentials not found" Dec 05 14:05:38 volumio go-librespot[16275]: time="2025-12-05T14:05:38-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:05:38 volumio go-librespot[16275]: time="2025-12-05T14:05:38-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 05 14:05:38 volumio go-librespot[16275]: time="2025-12-05T14:05:38-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 05 14:05:38 volumio go-librespot[16275]: time="2025-12-05T14:05:38-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 05 14:05:38 volumio go-librespot[16275]: time="2025-12-05T14:05:38-06:00" level=info msg="zeroconf server listening on port 46019" Dec 05 14:05:38 volumio go-librespot[16275]: time="2025-12-05T14:05:38-06:00" level=debug msg="obtained new client token: AADyg5U6/8SWAbuuaxt9xap0ikjli9S5GvFodnXdxGor7xFVnVdgZPpPT17hTQddNqiZo5vouZeG7oiyg9jX+TgCouLdDoMXN77oj9rhetLQx52ayV1O5pQV3bKA4WTJy5+0XZ6FsBe8k5eJ/QLx2OIvuftxz5BN3LFXxG9Rdpze4+ZD6VfXvnhkVKZwNzFI6bIARF42+t4I/ofE9dNnfXpDfr57xYdIavL1bZAqS+D0qSnXQbrj9wqtCA==" Dec 05 14:05:38 volumio go-librespot[16275]: time="2025-12-05T14:05:38-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:05:38 volumio go-librespot[16275]: time="2025-12-05T14:05:38-06:00" level=debug msg="completed keyexchange" Dec 05 14:05:38 volumio go-librespot[16275]: time="2025-12-05T14:05:38-06:00" level=debug msg="completed challenge" Dec 05 14:05:38 volumio go-librespot[16275]: time="2025-12-05T14:05:38-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:05:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:05:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:05:40 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:40 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Dec 05 14:05:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:41 volumio go-librespot[16284]: go-librespot daemon starting... Dec 05 14:05:42 volumio go-librespot[16285]: time="2025-12-05T14:05:42-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:05:42 volumio go-librespot[16285]: time="2025-12-05T14:05:42-06:00" level=debug msg="app state loaded" Dec 05 14:05:42 volumio go-librespot[16285]: time="2025-12-05T14:05:42-06:00" level=debug msg="stored credentials not found" Dec 05 14:05:42 volumio go-librespot[16285]: time="2025-12-05T14:05:42-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:05:42 volumio go-librespot[16285]: time="2025-12-05T14:05:42-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 05 14:05:42 volumio go-librespot[16285]: time="2025-12-05T14:05:42-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 05 14:05:42 volumio go-librespot[16285]: time="2025-12-05T14:05:42-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 05 14:05:42 volumio go-librespot[16285]: time="2025-12-05T14:05:42-06:00" level=info msg="zeroconf server listening on port 36655" Dec 05 14:05:42 volumio go-librespot[16285]: time="2025-12-05T14:05:42-06:00" level=debug msg="obtained new client token: AADOVGVwq/lmFf9HaXRELDOcRopb4UuluxwfwIcojYMj4WMdxeefQ7f46UqKatI4uzmKSczM+kThks/ZFNighuKGJlAP4MleeIFkkApEFLCJ837SQqulb4BDeqgwFPGU2wKvWm5VU5wzxqpLMLPPrRuIp7KhzTd7cAx5aBECDT5FOxHktdnIhKnTCZ+Q/TQJGlNEQaGd+qqZ99fqXOk6trYJsRj0cjRS9MaH8VB5wn8iz6kC3gh1VGNMpg==" Dec 05 14:05:42 volumio go-librespot[16285]: time="2025-12-05T14:05:42-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:05:42 volumio go-librespot[16285]: time="2025-12-05T14:05:42-06:00" level=debug msg="completed keyexchange" Dec 05 14:05:42 volumio go-librespot[16285]: time="2025-12-05T14:05:42-06:00" level=debug msg="completed challenge" Dec 05 14:05:42 volumio go-librespot[16285]: time="2025-12-05T14:05:42-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:05:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:05:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:05:43 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:43 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Dec 05 14:05:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:45 volumio go-librespot[16306]: go-librespot daemon starting... Dec 05 14:05:45 volumio go-librespot[16307]: time="2025-12-05T14:05:45-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:05:45 volumio go-librespot[16307]: time="2025-12-05T14:05:45-06:00" level=debug msg="app state loaded" Dec 05 14:05:45 volumio go-librespot[16307]: time="2025-12-05T14:05:45-06:00" level=debug msg="stored credentials not found" Dec 05 14:05:45 volumio go-librespot[16307]: time="2025-12-05T14:05:45-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:05:45 volumio go-librespot[16307]: time="2025-12-05T14:05:45-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 05 14:05:45 volumio go-librespot[16307]: time="2025-12-05T14:05:45-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 05 14:05:45 volumio go-librespot[16307]: time="2025-12-05T14:05:45-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 05 14:05:46 volumio go-librespot[16307]: time="2025-12-05T14:05:46-06:00" level=info msg="zeroconf server listening on port 34339" Dec 05 14:05:46 volumio go-librespot[16307]: time="2025-12-05T14:05:46-06:00" level=debug msg="obtained new client token: AADZ3YkK1okxiH77cqg2LOJzEUCmgtGWhUPgZEw7uxdWLIeKa0dDEEhcZlXL7L0HPQ3+wZ3Pri8IxMfLz6Hpocvu6uAZ15oRWviWVZ0DFE6z/ezqVzrLEcWedRit9+6WulyveIpogw0mc8rduIx8+XnK51Ux01C7T50CZCoah53Exa4yAiBS2nHxUAsqfU88GQL4pb8lbomdYJvfR3NYdYllUAoKmJu3X/J77QCL8YnETEBsj5V+hjs=" Dec 05 14:05:46 volumio go-librespot[16307]: time="2025-12-05T14:05:46-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:05:46 volumio go-librespot[16307]: time="2025-12-05T14:05:46-06:00" level=debug msg="completed keyexchange" Dec 05 14:05:46 volumio go-librespot[16307]: time="2025-12-05T14:05:46-06:00" level=debug msg="completed challenge" Dec 05 14:05:46 volumio go-librespot[16307]: time="2025-12-05T14:05:46-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:05:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:05:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:05:46 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:46 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:48 volumio volumio[15600]: info: UPDATER: Scheduling automatic update Dec 05 14:05:48 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStartTime Dec 05 14:05:48 volumio volumio[15600]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStopTime Dec 05 14:05:48 volumio volumio[15600]: info: UPDATER: Auto update will take place at: Sat Dec 06 2025 03:32:02 GMT-0600 (Central Standard Time) Dec 05 14:05:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Dec 05 14:05:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:49 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:49 volumio go-librespot[16314]: go-librespot daemon starting... Dec 05 14:05:49 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:49 volumio go-librespot[16315]: time="2025-12-05T14:05:49-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:05:49 volumio go-librespot[16315]: time="2025-12-05T14:05:49-06:00" level=debug msg="app state loaded" Dec 05 14:05:49 volumio go-librespot[16315]: time="2025-12-05T14:05:49-06:00" level=debug msg="stored credentials not found" Dec 05 14:05:49 volumio go-librespot[16315]: time="2025-12-05T14:05:49-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:05:49 volumio go-librespot[16315]: time="2025-12-05T14:05:49-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 05 14:05:49 volumio go-librespot[16315]: time="2025-12-05T14:05:49-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 05 14:05:49 volumio go-librespot[16315]: time="2025-12-05T14:05:49-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 05 14:05:49 volumio go-librespot[16315]: time="2025-12-05T14:05:49-06:00" level=info msg="zeroconf server listening on port 37697" Dec 05 14:05:49 volumio go-librespot[16315]: time="2025-12-05T14:05:49-06:00" level=debug msg="obtained new client token: AAC4tpLpcjO6mPPDT6yTDaUi/gvpT7l21/2hwD2/YkyRVUzpl62eWAT/BadOzPd+Bhlh7w1Pqw07bs9rBaCHQw/bYTKkq8jTG0emlVTw5SPWKCTCBfx+Aye3jgfWb0cDeyUf/mx+Lvrc5SMS4YuO1N49pghI4OsoaGOhohPPfygTq2gsKm1XRGpc7ZdVJv02U0RGb1JjgA8ZEbtXBZS7Tj+sGfGg9Fv/YyHXIDLwp6znRELIg5MpLLFPmg==" Dec 05 14:05:49 volumio go-librespot[16315]: time="2025-12-05T14:05:49-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:05:49 volumio go-librespot[16315]: time="2025-12-05T14:05:49-06:00" level=debug msg="completed keyexchange" Dec 05 14:05:49 volumio go-librespot[16315]: time="2025-12-05T14:05:49-06:00" level=debug msg="completed challenge" Dec 05 14:05:50 volumio go-librespot[16315]: time="2025-12-05T14:05:50-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:05:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:05:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:05:52 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:52 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Dec 05 14:05:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:53 volumio go-librespot[16322]: go-librespot daemon starting... Dec 05 14:05:53 volumio go-librespot[16323]: time="2025-12-05T14:05:53-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:05:53 volumio go-librespot[16323]: time="2025-12-05T14:05:53-06:00" level=debug msg="app state loaded" Dec 05 14:05:53 volumio go-librespot[16323]: time="2025-12-05T14:05:53-06:00" level=debug msg="stored credentials not found" Dec 05 14:05:53 volumio go-librespot[16323]: time="2025-12-05T14:05:53-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:05:53 volumio go-librespot[16323]: time="2025-12-05T14:05:53-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 05 14:05:53 volumio go-librespot[16323]: time="2025-12-05T14:05:53-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 05 14:05:53 volumio go-librespot[16323]: time="2025-12-05T14:05:53-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 05 14:05:53 volumio go-librespot[16323]: time="2025-12-05T14:05:53-06:00" level=info msg="zeroconf server listening on port 42053" Dec 05 14:05:53 volumio go-librespot[16323]: time="2025-12-05T14:05:53-06:00" level=debug msg="obtained new client token: AABqjrCHVL78Vt9JL3Y8JtnuFL732IwkWvXNL1tmE4Rinf9eH0APe0crmYKGoH+WWnXkAqgLvslcLvMg4S9/HSHXi/ok8XPp+RQtOUplQWpd56cLTq5lCzitnR/SA9jvs8W3R+8F4HRaizekkRMUfpUrcT+7AjC9hx0JMb7Wd4/NmGStq7P6nuQFgNmQTJctiH7nFsR2J5FIolPlAI/dP7n1p6SpQ0eP2W7/12NZpjTPJg9SIAOq/72M4w==" Dec 05 14:05:53 volumio go-librespot[16323]: time="2025-12-05T14:05:53-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:05:53 volumio go-librespot[16323]: time="2025-12-05T14:05:53-06:00" level=debug msg="completed keyexchange" Dec 05 14:05:53 volumio go-librespot[16323]: time="2025-12-05T14:05:53-06:00" level=debug msg="completed challenge" Dec 05 14:05:53 volumio go-librespot[16323]: time="2025-12-05T14:05:53-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:05:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:05:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:05:55 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:55 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:05:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Dec 05 14:05:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:05:56 volumio go-librespot[16344]: go-librespot daemon starting... Dec 05 14:05:57 volumio go-librespot[16345]: time="2025-12-05T14:05:57-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:05:57 volumio go-librespot[16345]: time="2025-12-05T14:05:57-06:00" level=debug msg="app state loaded" Dec 05 14:05:57 volumio go-librespot[16345]: time="2025-12-05T14:05:57-06:00" level=debug msg="stored credentials not found" Dec 05 14:05:57 volumio go-librespot[16345]: time="2025-12-05T14:05:57-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:05:57 volumio go-librespot[16345]: time="2025-12-05T14:05:57-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 05 14:05:57 volumio go-librespot[16345]: time="2025-12-05T14:05:57-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 05 14:05:57 volumio go-librespot[16345]: time="2025-12-05T14:05:57-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 05 14:05:57 volumio go-librespot[16345]: time="2025-12-05T14:05:57-06:00" level=info msg="zeroconf server listening on port 37293" Dec 05 14:05:57 volumio go-librespot[16345]: time="2025-12-05T14:05:57-06:00" level=debug msg="obtained new client token: AAAs03+JpvrasR+ddX9BYAx96s7Hp4UPBMzVIlT0ZoAjvtOVKfMoi8G9R9C4G8Hox3UkzfzFaIUxsrmkZubFOM2TCbhdhC0SQaVClrkievhMxqMKWRVl1p0VMcXTcKO/9uvBmELGUjkv+UeY41HgtkkwrRjasahob4gcbKcAgu0DZyHdknC0EvpT90lJuuSSgeXU4ReuArbnkaHvyeQfxMdKHIHszP6n4QwQpH+bVj7YHDorf2va4NFyKQ==" Dec 05 14:05:57 volumio go-librespot[16345]: time="2025-12-05T14:05:57-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:05:57 volumio go-librespot[16345]: time="2025-12-05T14:05:57-06:00" level=debug msg="completed keyexchange" Dec 05 14:05:57 volumio go-librespot[16345]: time="2025-12-05T14:05:57-06:00" level=debug msg="completed challenge" Dec 05 14:05:57 volumio go-librespot[16345]: time="2025-12-05T14:05:57-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:05:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:05:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:05:58 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:05:58 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:06:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Dec 05 14:06:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:06:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:06:00 volumio go-librespot[16355]: go-librespot daemon starting... Dec 05 14:06:00 volumio go-librespot[16356]: time="2025-12-05T14:06:00-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:06:00 volumio go-librespot[16356]: time="2025-12-05T14:06:00-06:00" level=debug msg="app state loaded" Dec 05 14:06:00 volumio go-librespot[16356]: time="2025-12-05T14:06:00-06:00" level=debug msg="stored credentials not found" Dec 05 14:06:00 volumio go-librespot[16356]: time="2025-12-05T14:06:00-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:06:00 volumio go-librespot[16356]: time="2025-12-05T14:06:00-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 05 14:06:00 volumio go-librespot[16356]: time="2025-12-05T14:06:00-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 05 14:06:00 volumio go-librespot[16356]: time="2025-12-05T14:06:00-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 05 14:06:00 volumio go-librespot[16356]: time="2025-12-05T14:06:00-06:00" level=info msg="zeroconf server listening on port 41681" Dec 05 14:06:01 volumio go-librespot[16356]: time="2025-12-05T14:06:01-06:00" level=debug msg="obtained new client token: AACCZESmHTQzOL+m2IeqAS0Izl+1RPvwNFgb27JfwoXBSZgcmfkC6z8z48F3eUd4I3KLQSz9Vhxlt/h8Fum/NlhEt+8uGbv2c99YGuZwpQ8YruNlaRUPoKBguJVWQ+sbKvUA6vYZwjdu0ihbs8bEQKnYUCrMbmvTMycpohVZ3RSHbbFlJooFiLw/Ny+kwCAYPMpXDaha+W1Ze07mSXRRN2S4Kydk4tjbOOO9JZm4EmB3fD/qifuCPvw=" Dec 05 14:06:01 volumio go-librespot[16356]: time="2025-12-05T14:06:01-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:06:01 volumio go-librespot[16356]: time="2025-12-05T14:06:01-06:00" level=debug msg="completed keyexchange" Dec 05 14:06:01 volumio go-librespot[16356]: time="2025-12-05T14:06:01-06:00" level=debug msg="completed challenge" Dec 05 14:06:01 volumio go-librespot[16356]: time="2025-12-05T14:06:01-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:06:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:06:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:06:01 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:06:01 volumio volumio[15600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:06:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Dec 05 14:06:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:06:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:06:04 volumio go-librespot[16364]: go-librespot daemon starting... Dec 05 14:06:04 volumio go-librespot[16365]: time="2025-12-05T14:06:04-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:06:04 volumio go-librespot[16365]: time="2025-12-05T14:06:04-06:00" level=debug msg="app state loaded" Dec 05 14:06:04 volumio go-librespot[16365]: time="2025-12-05T14:06:04-06:00" level=debug msg="stored credentials not found" Dec 05 14:06:04 volumio go-librespot[16365]: time="2025-12-05T14:06:04-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:06:04 volumio volumio[15600]: info: Initializing connection to go-librespot Websocket Dec 05 14:06:04 volumio go-librespot[16365]: time="2025-12-05T14:06:04-06:00" level=debug msg="new websocket client" Dec 05 14:06:04 volumio volumio[15600]: info: Connection to go-librespot Websocket established Dec 05 14:06:04 volumio go-librespot[16365]: time="2025-12-05T14:06:04-06:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 05 14:06:04 volumio go-librespot[16365]: time="2025-12-05T14:06:04-06:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 05 14:06:04 volumio go-librespot[16365]: time="2025-12-05T14:06:04-06:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 05 14:06:04 volumio go-librespot[16365]: time="2025-12-05T14:06:04-06:00" level=info msg="zeroconf server listening on port 34493" Dec 05 14:06:04 volumio go-librespot[16365]: time="2025-12-05T14:06:04-06:00" level=debug msg="obtained new client token: AABpAkTXn/h9xcXL1Shoes6yw/W8NjjSq2FgrNwvE/J59Al/Y/Ea+bov3ArulDPMfKqzZww3+T3maEFTI5YnhN9AKF3LERlRO+5tI//u7uWPnddaSy1LnJwdkI3wzOrU2qLW4FGGjKf82Bvx8UJMXKYYGN6Kg9cnEWYpp9egl03E80uwVCrtOi8wwpAa1LwW995kUR4y9l1KeSY3zio15Scl+XDsbNP/LKJEht8Lu7IDMrNqMfVZYA2HmA==" Dec 05 14:06:04 volumio go-librespot[16365]: time="2025-12-05T14:06:04-06:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Dec 05 14:06:04 volumio go-librespot[16365]: time="2025-12-05T14:06:04-06:00" level=debug msg="completed keyexchange" Dec 05 14:06:04 volumio go-librespot[16365]: time="2025-12-05T14:06:04-06:00" level=debug msg="completed challenge" Dec 05 14:06:05 volumio go-librespot[16365]: time="2025-12-05T14:06:05-06:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with username and spotify token: failed authenticating: accesspoint login failed: BadCredentials " Dec 05 14:06:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 05 14:06:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 05 14:06:05 volumio volumio[15600]: info: Connection to go-librespot Websocket closed Dec 05 14:06:07 volumio volumio[15600]: info: Getting Spotify volume Dec 05 14:06:07 volumio volumio[15600]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 05 14:06:07 volumio volumio[15600]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 05 14:06:07 volumio volumio[15600]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 05 14:06:07 volumio volumio[15600]: errno: -111, Dec 05 14:06:07 volumio volumio[15600]: code: 'ECONNREFUSED', Dec 05 14:06:07 volumio volumio[15600]: syscall: 'connect', Dec 05 14:06:07 volumio volumio[15600]: address: '127.0.0.1', Dec 05 14:06:07 volumio volumio[15600]: port: 9879, Dec 05 14:06:07 volumio volumio[15600]: response: undefined Dec 05 14:06:07 volumio volumio[15600]: } Dec 05 14:06:07 volumio volumio[15600]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 05 14:06:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Dec 05 14:06:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:06:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 05 14:06:08 volumio go-librespot[16398]: go-librespot daemon starting... Dec 05 14:06:08 volumio go-librespot[16399]: time="2025-12-05T14:06:08-06:00" level=info msg="running go-librespot 0.4.0" Dec 05 14:06:08 volumio go-librespot[16399]: time="2025-12-05T14:06:08-06:00" level=debug msg="app state loaded" Dec 05 14:06:08 volumio go-librespot[16399]: time="2025-12-05T14:06:08-06:00" level=debug msg="stored credentials not found" Dec 05 14:06:08 volumio go-librespot[16399]: time="2025-12-05T14:06:08-06:00" level=info msg="api server listening on 127.0.0.1:9879" Dec 05 14:06:08 volumio sudo[16407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-05 14:05' Dec 05 14:06:08 volumio sudo[16407]: 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="ac7dd5922ede329d1459d48b226ddc71f5209a2c" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="3441cddd43405c36fe444484553f10f2f5bc830b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Nov 13 11:04:27 UTC 2025" VOLUMIO_VERSION="4.069" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="7da8d6d9f8baf8621af4ec2af5a00f00"