Nov 04 23:42:00 volumio volumio[32284]: info: CoreCommandRouter::volumioGetState Nov 04 23:42:00 volumio volumio[32284]: info: CorePlayQueue::getTrack 0 Nov 04 23:42:00 volumio volumio[32284]: info: Listing playlists Nov 04 23:42:00 volumio volumio[32284]: info: Listing playlists Nov 04 23:42:00 volumio volumio[32284]: info: go-librespot daemon successfully initialized Nov 04 23:42:00 volumio sudo[32539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 04 23:42:00 volumio sudo[32539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 23:42:00 volumio sudo[32541]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 04 23:42:00 volumio sudo[32541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 23:42:00 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Nov 04 23:42:00 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Nov 04 23:42:00 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Nov 04 23:42:00 volumio sudo[32541]: pam_unix(sudo:session): session closed for user root Nov 04 23:42:00 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Nov 04 23:42:00 volumio mpd_monitor.sh[32544]: MPD Monitor Service: Starting MPD Monitor Service Nov 04 23:42:00 volumio volumio[32284]: info: Successfully started MPD Monitor Nov 04 23:42:00 volumio sudo[32539]: pam_unix(sudo:session): session closed for user root Nov 04 23:42:00 volumio volumio[32284]: info: Successfully started MPD Monitor Nov 04 23:42:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 60. Nov 04 23:42:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:00 volumio go-librespot[32548]: go-librespot daemon starting... Nov 04 23:42:00 volumio go-librespot[32549]: time="2025-11-04T23:42:00Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:00 volumio go-librespot[32549]: time="2025-11-04T23:42:00Z" level=debug msg="app state loaded" Nov 04 23:42:00 volumio go-librespot[32549]: time="2025-11-04T23:42:00Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:00 volumio go-librespot[32549]: time="2025-11-04T23:42:00Z" 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]" Nov 04 23:42:00 volumio go-librespot[32549]: time="2025-11-04T23:42:00Z" 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]" Nov 04 23:42:00 volumio go-librespot[32549]: time="2025-11-04T23:42:00Z" 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]" Nov 04 23:42:00 volumio go-librespot[32549]: time="2025-11-04T23:42:00Z" level=info msg="zeroconf server listening on port 33221" Nov 04 23:42:00 volumio go-librespot[32549]: time="2025-11-04T23:42:00Z" level=debug msg="obtained new client token: AAAO5qWXLw+A0w0KKFfSD6uz++vYucluN/obHXvFIPS8mDf9Jf2zpjUNBrMna4/PxpzmwE+D3eLADgrSnXOB0VJs3FlXrTAXIZOoKqjyFrAOVQqQWTw0thd79+COM3oHnbYqRurzbWkE2Qq52ic8x5vRSG0xtNMdbeGEc4zYxj+T9gn+DEtshwLPnV/JC7kA/jiNMkU3VCBPBOCCbIQrbtbehDgurqp8UorbRCNJZXLxW5zQeGJEjNU=" Nov 04 23:42:00 volumio go-librespot[32549]: time="2025-11-04T23:42:00Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 04 23:42:00 volumio go-librespot[32549]: time="2025-11-04T23:42:00Z" level=debug msg="completed keyexchange" Nov 04 23:42:00 volumio go-librespot[32549]: time="2025-11-04T23:42:00Z" level=debug msg="completed challenge" Nov 04 23:42:00 volumio go-librespot[32549]: time="2025-11-04T23:42:00Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:02 volumio volumio[32284]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Nov 04 23:42:03 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:03 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 61. Nov 04 23:42:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:04 volumio go-librespot[32556]: go-librespot daemon starting... Nov 04 23:42:04 volumio go-librespot[32557]: time="2025-11-04T23:42:04Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:04 volumio go-librespot[32557]: time="2025-11-04T23:42:04Z" level=debug msg="app state loaded" Nov 04 23:42:04 volumio go-librespot[32557]: time="2025-11-04T23:42:04Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:04 volumio go-librespot[32557]: time="2025-11-04T23:42:04Z" 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]" Nov 04 23:42:04 volumio go-librespot[32557]: time="2025-11-04T23:42:04Z" 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]" Nov 04 23:42:04 volumio go-librespot[32557]: time="2025-11-04T23:42:04Z" 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]" Nov 04 23:42:04 volumio go-librespot[32557]: time="2025-11-04T23:42:04Z" level=info msg="zeroconf server listening on port 41449" Nov 04 23:42:04 volumio go-librespot[32557]: time="2025-11-04T23:42:04Z" level=debug msg="obtained new client token: AAA6DI9QdC7VmFQdCZjlH00OuMpjgEo2fWHBbMGCUIklFULe+N9wwwEjwOfYnB+7PhUB4w3BYcjwWorJgYSEMzWfognVV3nNJ4SJh9V6LE0LXbnGkBd0Umxk5P7l2suihwWCZs2WJFh8L1WWebIDghlcBS6DRiH3mAxNhHItENOlmN2IhDzjW4Xl/ClVu9A5zoxFJAv7V9lfv11EFGSvz91Ct2/Ctq7WN7MBOTsYS7bFLreZDGVb" Nov 04 23:42:04 volumio go-librespot[32557]: time="2025-11-04T23:42:04Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 04 23:42:04 volumio go-librespot[32557]: time="2025-11-04T23:42:04Z" level=debug msg="completed keyexchange" Nov 04 23:42:04 volumio go-librespot[32557]: time="2025-11-04T23:42:04Z" level=debug msg="completed challenge" Nov 04 23:42:04 volumio go-librespot[32557]: time="2025-11-04T23:42:04Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:04 volumio volumio[32284]: info: Cannot mount NAS NAS at system boot, trial number 3 ,retrying in 5 seconds Nov 04 23:42:04 volumio sudo[32579]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 04 23:42:04 volumio sudo[32579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 23:42:04 volumio sudo[32581]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 04 23:42:04 volumio sudo[32581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 23:42:04 volumio sudo[32579]: pam_unix(sudo:session): session closed for user root Nov 04 23:42:04 volumio sudo[32581]: pam_unix(sudo:session): session closed for user root Nov 04 23:42:04 volumio sudo[32585]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 04 23:42:04 volumio sudo[32585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 23:42:04 volumio sudo[32585]: pam_unix(sudo:session): session closed for user root Nov 04 23:42:04 volumio volumio[32284]: info: Upmpdcli Daemon Started Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Nov 04 23:42:06 volumio volumio[32284]: info: Adding plugin bluetooth to MyMusic Plugins Nov 04 23:42:06 volumio volumio[32284]: info: Adding plugin multiroom to MyMusic Plugins Nov 04 23:42:06 volumio volumio[32284]: info: Adding plugin metavolumio to MyMusic Plugins Nov 04 23:42:06 volumio volumio[32284]: info: Adding plugin cd_controller to MyMusic Plugins Nov 04 23:42:06 volumio volumio[32284]: info: Adding plugin qobuzconnect to MyMusic Plugins Nov 04 23:42:06 volumio volumio[32284]: info: Adding plugin smart_inputs to MyMusic Plugins Nov 04 23:42:06 volumio volumio[32284]: info: Adding plugin tidalconnect to MyMusic Plugins Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 04 23:42:06 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 23:42:06 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 23:42:06 volumio volumio[32284]: info: Starting MyVolumio Remote Streaming Endpoints Nov 04 23:42:06 volumio volumio[32284]: info: MyVolumio login type: Token Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 04 23:42:06 volumio volumio[32284]: info: Streaming services startup Nov 04 23:42:06 volumio volumio[32284]: info: Starting Streaming Daemon Nov 04 23:42:06 volumio sudo[32588]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 04 23:42:06 volumio sudo[32588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 23:42:06 volumio volumio[32284]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 04 23:42:06 volumio sudo[32588]: pam_unix(sudo:session): session closed for user root Nov 04 23:42:06 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:06 volumio volumio[32284]: error: Cannot start Volumio Streaming Daemon Nov 04 23:42:06 volumio volumio[32284]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 04 23:42:06 volumio volumio[32284]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 04 23:42:06 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:06 volumio volumio[32284]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Nov 04 23:42:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 62. Nov 04 23:42:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:07 volumio go-librespot[32594]: go-librespot daemon starting... Nov 04 23:42:07 volumio go-librespot[32595]: time="2025-11-04T23:42:07Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:07 volumio go-librespot[32595]: time="2025-11-04T23:42:07Z" level=debug msg="app state loaded" Nov 04 23:42:07 volumio go-librespot[32595]: time="2025-11-04T23:42:07Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:07 volumio go-librespot[32595]: time="2025-11-04T23:42:07Z" 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]" Nov 04 23:42:07 volumio go-librespot[32595]: time="2025-11-04T23:42:07Z" 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]" Nov 04 23:42:07 volumio go-librespot[32595]: time="2025-11-04T23:42:07Z" 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]" Nov 04 23:42:07 volumio go-librespot[32595]: time="2025-11-04T23:42:07Z" level=info msg="zeroconf server listening on port 35525" Nov 04 23:42:07 volumio go-librespot[32595]: time="2025-11-04T23:42:07Z" level=debug msg="obtained new client token: AADUD32Ko9AuxivWqnb57WHBPlrD0y2mU1pLnpRD8YHkkGcvbYiyZNRFC4uljiBBzYMClQam3tPOci5QcIK5wcmUFgSNNfoYCLw7ziZcA2M/8GsWQbclrkioVl0G8D+GmWxB36rjBX6C5Oyd7uV6cTnVgEnTCbbtS8245DO62derB7c0HS81e+BD2JM6JEAa0dOpVGQmF209WuXgzWZQPA42J8+hRcuZkTRTUNMxfBRgAxULNSjfxqM=" Nov 04 23:42:07 volumio go-librespot[32595]: time="2025-11-04T23:42:07Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 04 23:42:07 volumio go-librespot[32595]: time="2025-11-04T23:42:07Z" level=debug msg="completed keyexchange" Nov 04 23:42:07 volumio go-librespot[32595]: time="2025-11-04T23:42:07Z" level=debug msg="completed challenge" Nov 04 23:42:07 volumio volumio[32284]: info: MyVolumio token set successfully Nov 04 23:42:07 volumio volumio[32284]: info: MYVOLUMIO: Adding device Nov 04 23:42:07 volumio volumio[32284]: info: MYVOLUMIO: Evaluating Server Nov 04 23:42:07 volumio go-librespot[32595]: time="2025-11-04T23:42:07Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:07 volumio volumio[32284]: info: MyVolumio status changed Nov 04 23:42:07 volumio volumio[32284]: info: Streaming services startup Nov 04 23:42:07 volumio volumio[32284]: info: Starting Streaming Daemon Nov 04 23:42:07 volumio volumio[32284]: info: Removing browser output: myVolumio user plan is not superstar Nov 04 23:42:07 volumio volumio[32284]: info: Removing audio output: Nov 04 23:42:07 volumio volumio[32284]: info: Stoppping Tunnel 1 Nov 04 23:42:07 volumio sudo[32621]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 04 23:42:07 volumio sudo[32621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 23:42:07 volumio sudo[32623]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Nov 04 23:42:07 volumio sudo[32623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 23:42:07 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. Nov 04 23:42:07 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. Nov 04 23:42:07 volumio sudo[32621]: pam_unix(sudo:session): session closed for user root Nov 04 23:42:07 volumio volumio[32284]: error: Cannot start Volumio Streaming Daemon Nov 04 23:42:07 volumio volumio[32284]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 04 23:42:07 volumio volumio[32284]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 04 23:42:07 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. Nov 04 23:42:07 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. Nov 04 23:42:07 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. Nov 04 23:42:07 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. Nov 04 23:42:07 volumio sudo[32623]: pam_unix(sudo:session): session closed for user root Nov 04 23:42:07 volumio volumio[32284]: info: Remote SSH Stopped Nov 04 23:42:08 volumio volumio[32284]: info: Setting Geolocation for MyVolumio to eu3 Nov 04 23:42:08 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 23:42:08 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 23:42:08 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 23:42:08 volumio volumio[32284]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 04 23:42:09 volumio volumio[32284]: info: Updating MyVolumio device info Nov 04 23:42:09 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 23:42:09 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 23:42:09 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 23:42:09 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:09 volumio volumio[32284]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 04 23:42:09 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:09 volumio volumio[32284]: info: Cannot mount NAS NAS at system boot, trial number 4 ,retrying in 5 seconds Nov 04 23:42:10 volumio volumio[32284]: info: CoreCommandRouter::volumioGetState Nov 04 23:42:10 volumio volumio[32284]: info: CorePlayQueue::getTrack 0 Nov 04 23:42:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63. Nov 04 23:42:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:11 volumio go-librespot[32626]: go-librespot daemon starting... Nov 04 23:42:11 volumio go-librespot[32627]: time="2025-11-04T23:42:11Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:11 volumio go-librespot[32627]: time="2025-11-04T23:42:11Z" level=debug msg="app state loaded" Nov 04 23:42:11 volumio go-librespot[32627]: time="2025-11-04T23:42:11Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:11 volumio go-librespot[32627]: time="2025-11-04T23:42:11Z" 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]" Nov 04 23:42:11 volumio go-librespot[32627]: time="2025-11-04T23:42:11Z" 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]" Nov 04 23:42:11 volumio go-librespot[32627]: time="2025-11-04T23:42:11Z" 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]" Nov 04 23:42:11 volumio go-librespot[32627]: time="2025-11-04T23:42:11Z" level=info msg="zeroconf server listening on port 36995" Nov 04 23:42:11 volumio go-librespot[32627]: time="2025-11-04T23:42:11Z" level=debug msg="obtained new client token: AACwBv8LlXMHwd26f55o6baG31oSSeIzXKZ2AEpjSgEl4QRvK/sLZm4NApzl0GoWW+vYBPTafm2v9j2+vf3VcVyw443v1B6nbFne19X+9ZmHT1OsHOVNzwHZFKNC6FRUSnpDbGZxO2zRu3t4gqB1BVvkwM4hW58BKkieCRgezqfu2sUXS2Aa2uzr3aRzk8ryEHD0+R12qfayjbRytakDrYuzYtGuugNGVLHI6MZ1mAQ6JWaOOY4z" Nov 04 23:42:11 volumio go-librespot[32627]: time="2025-11-04T23:42:11Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 04 23:42:11 volumio go-librespot[32627]: time="2025-11-04T23:42:11Z" level=debug msg="completed keyexchange" Nov 04 23:42:11 volumio go-librespot[32627]: time="2025-11-04T23:42:11Z" level=debug msg="completed challenge" Nov 04 23:42:11 volumio go-librespot[32627]: time="2025-11-04T23:42:11Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:12 volumio volumio[32284]: info: MYVOLUMIO: Adding device Nov 04 23:42:12 volumio volumio[32284]: info: MYVOLUMIO: Evaluating Server Nov 04 23:42:12 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:12 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:12 volumio volumio[32284]: info: Setting Geolocation for MyVolumio to eu3 Nov 04 23:42:12 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 23:42:12 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 23:42:12 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 23:42:13 volumio volumio[32284]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 04 23:42:13 volumio volumio[32284]: info: Updating MyVolumio device info Nov 04 23:42:13 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 23:42:13 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 23:42:13 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 23:42:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64. Nov 04 23:42:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:14 volumio go-librespot[32651]: go-librespot daemon starting... Nov 04 23:42:14 volumio go-librespot[32652]: time="2025-11-04T23:42:14Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:14 volumio go-librespot[32652]: time="2025-11-04T23:42:14Z" level=debug msg="app state loaded" Nov 04 23:42:14 volumio go-librespot[32652]: time="2025-11-04T23:42:14Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:14 volumio go-librespot[32652]: time="2025-11-04T23:42:14Z" 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]" Nov 04 23:42:14 volumio go-librespot[32652]: time="2025-11-04T23:42:14Z" 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]" Nov 04 23:42:14 volumio go-librespot[32652]: time="2025-11-04T23:42:14Z" 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]" Nov 04 23:42:14 volumio go-librespot[32652]: time="2025-11-04T23:42:14Z" level=info msg="zeroconf server listening on port 36597" Nov 04 23:42:14 volumio go-librespot[32652]: time="2025-11-04T23:42:14Z" level=debug msg="obtained new client token: AAAswA/OyC570C/uGKDRo51yyeN4DuZUISz6LDTDJ0gbZUsB7j5HlL4/tSEnBii7vp2DP62/1xx6bY+uzJexRPAtafP67RxDV3zqIzA4FdHEx6XxaVWzuqQBvxgXlMxIZZpJY+E+yTZUinzBB5wujgZWxITpvHgnlTbH60OR2Jmzup7y5kltAhdGjpHbd2xUgfy6CzIeM6oOH7QxhfArhGOUflOD89dLAFeruuluW9980w9klzpI21A=" Nov 04 23:42:14 volumio go-librespot[32652]: time="2025-11-04T23:42:14Z" 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" Nov 04 23:42:14 volumio go-librespot[32652]: time="2025-11-04T23:42:14Z" level=debug msg="connected to ap-gew1.spotify.com:443" Nov 04 23:42:14 volumio go-librespot[32652]: time="2025-11-04T23:42:14Z" level=debug msg="completed keyexchange" Nov 04 23:42:14 volumio go-librespot[32652]: time="2025-11-04T23:42:14Z" level=debug msg="completed challenge" Nov 04 23:42:14 volumio volumio[32284]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Nov 04 23:42:14 volumio volumio[32284]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 04 23:42:14 volumio go-librespot[32652]: time="2025-11-04T23:42:14Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:15 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:15 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 65. Nov 04 23:42:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:18 volumio go-librespot[32673]: go-librespot daemon starting... Nov 04 23:42:18 volumio go-librespot[32674]: time="2025-11-04T23:42:18Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:18 volumio go-librespot[32674]: time="2025-11-04T23:42:18Z" level=debug msg="app state loaded" Nov 04 23:42:18 volumio go-librespot[32674]: time="2025-11-04T23:42:18Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:18 volumio go-librespot[32674]: time="2025-11-04T23:42:18Z" 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]" Nov 04 23:42:18 volumio go-librespot[32674]: time="2025-11-04T23:42:18Z" 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]" Nov 04 23:42:18 volumio go-librespot[32674]: time="2025-11-04T23:42:18Z" 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]" Nov 04 23:42:18 volumio go-librespot[32674]: time="2025-11-04T23:42:18Z" level=info msg="zeroconf server listening on port 39219" Nov 04 23:42:18 volumio go-librespot[32674]: time="2025-11-04T23:42:18Z" level=debug msg="obtained new client token: AADc1cwSb+6Thc4XGA8oMj0BM585zfkAMkkw6iht8glCucYyRq/0fa5c2Kvu8Z4Rh/UNVNt0ZOLXq6yDZdRv0T4NLCsHIIP7KEPOl32+qMbUuESanw+daxcDg22ma0MdpzUKIsvE50L4SH7Pj7cIbqF6tJhrSp++U0Y6MDxtvCoa+OPFTWURSh1VaI4Qx9uchecfmsvmlUprYw0PRCIQeel/Q1XYi+KtTJ/Rl9FSx5J56VZLwf+0" Nov 04 23:42:18 volumio go-librespot[32674]: time="2025-11-04T23:42:18Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 04 23:42:18 volumio go-librespot[32674]: time="2025-11-04T23:42:18Z" level=debug msg="completed keyexchange" Nov 04 23:42:18 volumio go-librespot[32674]: time="2025-11-04T23:42:18Z" level=debug msg="completed challenge" Nov 04 23:42:18 volumio go-librespot[32674]: time="2025-11-04T23:42:18Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:18 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:18 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:20 volumio volumio[32284]: info: CoreCommandRouter::volumioGetState Nov 04 23:42:20 volumio volumio[32284]: info: CorePlayQueue::getTrack 0 Nov 04 23:42:20 volumio volumio[32284]: info: Listing playlists Nov 04 23:42:20 volumio volumio[32284]: info: Listing playlists Nov 04 23:42:21 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 04 23:42:21 volumio volumio[32284]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Nov 04 23:42:21 volumio volumio[32284]: info: CoreCommandRouter::volumioGetState Nov 04 23:42:21 volumio volumio[32284]: info: CorePlayQueue::getTrack 0 Nov 04 23:42:21 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:21 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 66. Nov 04 23:42:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:21 volumio go-librespot[32684]: go-librespot daemon starting... Nov 04 23:42:21 volumio go-librespot[32685]: time="2025-11-04T23:42:21Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:21 volumio go-librespot[32685]: time="2025-11-04T23:42:21Z" level=debug msg="app state loaded" Nov 04 23:42:21 volumio go-librespot[32685]: time="2025-11-04T23:42:21Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:21 volumio go-librespot[32685]: time="2025-11-04T23:42:21Z" 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]" Nov 04 23:42:21 volumio go-librespot[32685]: time="2025-11-04T23:42:21Z" 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]" Nov 04 23:42:21 volumio go-librespot[32685]: time="2025-11-04T23:42:21Z" 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]" Nov 04 23:42:21 volumio go-librespot[32685]: time="2025-11-04T23:42:21Z" level=info msg="zeroconf server listening on port 34735" Nov 04 23:42:21 volumio go-librespot[32685]: time="2025-11-04T23:42:21Z" level=debug msg="obtained new client token: AAC2cmciswpLOXmsPJJ+H5OAvrFwO40Kx7vM0hTKJ1uUz6U8k+NWr9c3Q4UP9ftzZw7GOpNhUI+b3H+YS3hmXiaRkCoA2VXAxl0yIyCdQWo9LZDfu5XF87cEYSRFgJAoB0yjs8KI1VAuzOoHggoqupHXOzkdbHjw6YkNcxdiVIiT2BMUoi0aOVcCtEtyCAa2GOGayJpsbS0CnLnrdNEMtFfJpLdsEOlUzXsVKVFJd4Qf1qh6at22AVg=" Nov 04 23:42:21 volumio go-librespot[32685]: time="2025-11-04T23:42:21Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 04 23:42:21 volumio go-librespot[32685]: time="2025-11-04T23:42:21Z" level=debug msg="completed keyexchange" Nov 04 23:42:21 volumio go-librespot[32685]: time="2025-11-04T23:42:21Z" level=debug msg="completed challenge" Nov 04 23:42:21 volumio go-librespot[32685]: time="2025-11-04T23:42:21Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:24 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:24 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 67. Nov 04 23:42:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:25 volumio go-librespot[32708]: go-librespot daemon starting... Nov 04 23:42:25 volumio go-librespot[32709]: time="2025-11-04T23:42:25Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:25 volumio go-librespot[32709]: time="2025-11-04T23:42:25Z" level=debug msg="app state loaded" Nov 04 23:42:25 volumio go-librespot[32709]: time="2025-11-04T23:42:25Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:25 volumio go-librespot[32709]: time="2025-11-04T23:42:25Z" 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]" Nov 04 23:42:25 volumio go-librespot[32709]: time="2025-11-04T23:42:25Z" 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]" Nov 04 23:42:25 volumio go-librespot[32709]: time="2025-11-04T23:42:25Z" 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]" Nov 04 23:42:25 volumio go-librespot[32709]: time="2025-11-04T23:42:25Z" level=info msg="zeroconf server listening on port 33497" Nov 04 23:42:25 volumio go-librespot[32709]: time="2025-11-04T23:42:25Z" level=debug msg="obtained new client token: AABdHP95+LumfT4W8zciBfjfed8mpR4s9RvYkSaPwQpaembwY3J70ITUgNJctDJCt5r92qg+XHrgbvmrqBALwfrPwf1wq0o0AKbfk5Ruw42DR4kPA0v4hmisbyqEKVt2LoTPYnzGz5KW0NhHYel5jn4F7UX4d4YJ23Si8LNaTB2MeZ7X3chPhkmSIjaP2sOuAbWzoDdC555O9HoH/PJnynsUsQr2GUuB5Jhszz8Q4BVCRWwCcVCe" Nov 04 23:42:25 volumio go-librespot[32709]: time="2025-11-04T23:42:25Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 04 23:42:25 volumio go-librespot[32709]: time="2025-11-04T23:42:25Z" level=debug msg="completed keyexchange" Nov 04 23:42:25 volumio go-librespot[32709]: time="2025-11-04T23:42:25Z" level=debug msg="completed challenge" Nov 04 23:42:25 volumio go-librespot[32709]: time="2025-11-04T23:42:25Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:26 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 23:42:26 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 23:42:26 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 04 23:42:26 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 04 23:42:26 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Nov 04 23:42:26 volumio volumio[32284]: info: CoreCommandRouter::volumioGetBrowseSources Nov 04 23:42:26 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 04 23:42:26 volumio volumio[32284]: error: MyVolumio Plugin failed to authenticate in a timely fashion Nov 04 23:42:26 volumio volumio[32284]: info: Completed starting MyVolumio Plugin Nov 04 23:42:26 volumio volumio[32284]: [Metrics] CommandRouter: 32s 73.70ms Nov 04 23:42:26 volumio volumio[32284]: info: CoreCommandRouter::volumiosetStartupVolume Nov 04 23:42:26 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 23:42:26 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 23:42:26 volumio volumio[32284]: info: CoreCommandRouter::Close All Modals sent Nov 04 23:42:26 volumio volumio[32284]: info: CoreCommandRouter::Close All Modals sent Nov 04 23:42:26 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 04 23:42:26 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 23:42:26 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 04 23:42:26 volumio volumio-remote-updater[874]: Test mode disabled Nov 04 23:42:26 volumio volumio-remote-updater[874]: Alpha mode disabled Nov 04 23:42:26 volumio volumio-remote-updater[874]: Alpha legacy test mode disabled Nov 04 23:42:26 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Nov 04 23:42:27 volumio volumio[32284]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 04 23:42:27 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 04 23:42:27 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 04 23:42:27 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 04 23:42:27 volumio volumio[32284]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 04 23:42:27 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:27 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 68. Nov 04 23:42:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:28 volumio go-librespot[32726]: go-librespot daemon starting... Nov 04 23:42:28 volumio go-librespot[32727]: time="2025-11-04T23:42:28Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:28 volumio go-librespot[32727]: time="2025-11-04T23:42:28Z" level=debug msg="app state loaded" Nov 04 23:42:28 volumio go-librespot[32727]: time="2025-11-04T23:42:28Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:28 volumio go-librespot[32727]: time="2025-11-04T23:42:28Z" 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]" Nov 04 23:42:28 volumio go-librespot[32727]: time="2025-11-04T23:42:28Z" 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]" Nov 04 23:42:28 volumio go-librespot[32727]: time="2025-11-04T23:42:28Z" 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]" Nov 04 23:42:28 volumio go-librespot[32727]: time="2025-11-04T23:42:28Z" level=info msg="zeroconf server listening on port 33173" Nov 04 23:42:28 volumio go-librespot[32727]: time="2025-11-04T23:42:28Z" level=debug msg="obtained new client token: AADOuai6nwhBD7ksM+UgsEYtNat/8LMnI+VYX1oNR8RYUVKaq2haqHc2oRYUMOqXYSJIHJ9kYYoft3jLEw8aPSah77mYvzMbKg3QtikIq84fVocOK2i8XOBFyhosMNFQqJ0ky7T59ATjfTv63seQUtR90sWpC3plmorPVjsk9U4hwDXNmTqfXwr80TVWph3MBccWBM+tv5mzlYAl77DYxTVEItj9HmKdsh/ETdk9wRg5E8DCE0HKUj0=" Nov 04 23:42:28 volumio go-librespot[32727]: time="2025-11-04T23:42:28Z" 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" Nov 04 23:42:28 volumio go-librespot[32727]: time="2025-11-04T23:42:28Z" level=debug msg="connected to ap-gew1.spotify.com:443" Nov 04 23:42:28 volumio go-librespot[32727]: time="2025-11-04T23:42:28Z" level=debug msg="completed keyexchange" Nov 04 23:42:28 volumio go-librespot[32727]: time="2025-11-04T23:42:28Z" level=debug msg="completed challenge" Nov 04 23:42:28 volumio go-librespot[32727]: time="2025-11-04T23:42:28Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:30 volumio volumio[32284]: info: CoreCommandRouter::volumioGetState Nov 04 23:42:30 volumio volumio[32284]: info: CorePlayQueue::getTrack 0 Nov 04 23:42:30 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:30 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 69. Nov 04 23:42:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:32 volumio go-librespot[32734]: go-librespot daemon starting... Nov 04 23:42:32 volumio go-librespot[32735]: time="2025-11-04T23:42:32Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:32 volumio go-librespot[32735]: time="2025-11-04T23:42:32Z" level=debug msg="app state loaded" Nov 04 23:42:32 volumio go-librespot[32735]: time="2025-11-04T23:42:32Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:32 volumio go-librespot[32735]: time="2025-11-04T23:42:32Z" 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]" Nov 04 23:42:32 volumio go-librespot[32735]: time="2025-11-04T23:42:32Z" 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]" Nov 04 23:42:32 volumio go-librespot[32735]: time="2025-11-04T23:42:32Z" 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]" Nov 04 23:42:32 volumio go-librespot[32735]: time="2025-11-04T23:42:32Z" level=info msg="zeroconf server listening on port 38151" Nov 04 23:42:32 volumio go-librespot[32735]: time="2025-11-04T23:42:32Z" level=debug msg="obtained new client token: AAD2C4nNdh59ADte7g4aLmhxuDYTHCxZiwDultwxnMjhIMwuLevlYGd6ha6HoXA7MFhzgs7RyIYUksPkwgjAhNwC1V1vpoucpDPtgibjXTEKJNWB9/hsEN7xyJw3oUQm6Q4qgDIfjZ5sp3GmL3LPj9dG9YpAQOX0xHTeiZgfqJFHdIA69UhnUIjTbP2xduNiXISUyUyOSG1sXVCbiTcDdMdR5Gi8sOGYFl/VLJyR3fIUB5UUp1V6" Nov 04 23:42:32 volumio go-librespot[32735]: time="2025-11-04T23:42:32Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 04 23:42:32 volumio go-librespot[32735]: time="2025-11-04T23:42:32Z" level=debug msg="completed keyexchange" Nov 04 23:42:32 volumio go-librespot[32735]: time="2025-11-04T23:42:32Z" level=debug msg="completed challenge" Nov 04 23:42:32 volumio go-librespot[32735]: time="2025-11-04T23:42:32Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:33 volumio volumio[32284]: info: BOOT COMPLETED Nov 04 23:42:33 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:33 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 70. Nov 04 23:42:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:35 volumio go-librespot[32757]: go-librespot daemon starting... Nov 04 23:42:35 volumio go-librespot[32758]: time="2025-11-04T23:42:35Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:35 volumio go-librespot[32758]: time="2025-11-04T23:42:35Z" level=debug msg="app state loaded" Nov 04 23:42:35 volumio go-librespot[32758]: time="2025-11-04T23:42:35Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:35 volumio go-librespot[32758]: time="2025-11-04T23:42:35Z" 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]" Nov 04 23:42:35 volumio go-librespot[32758]: time="2025-11-04T23:42:35Z" 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]" Nov 04 23:42:35 volumio go-librespot[32758]: time="2025-11-04T23:42:35Z" 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]" Nov 04 23:42:35 volumio go-librespot[32758]: time="2025-11-04T23:42:35Z" level=info msg="zeroconf server listening on port 41131" Nov 04 23:42:35 volumio go-librespot[32758]: time="2025-11-04T23:42:35Z" level=debug msg="obtained new client token: AABy502yfeFGOH0eHMt9SELOqm4QEkdUmkrX/IacJZ/7p5goz8dOsM82He3F3Q59M3ekpVlVTJUV0+dhslm3g2eP3b9pPk+06dFFrERxEeqK7NzLlTYoVUf/zfPzcpo8UAeeBMXPF+9He9PmkV2TIJXdSjxstistgASs+/au5rFoE/7BNA1JZTPsBXQ5nSE0e7J1wHhdWYB48NFBoZvtFcYAGkYHBIikiWNGvGDRzGaWaw8e0m1mXpQ=" Nov 04 23:42:35 volumio go-librespot[32758]: time="2025-11-04T23:42:35Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 04 23:42:35 volumio go-librespot[32758]: time="2025-11-04T23:42:35Z" level=debug msg="completed keyexchange" Nov 04 23:42:35 volumio go-librespot[32758]: time="2025-11-04T23:42:35Z" level=debug msg="completed challenge" Nov 04 23:42:35 volumio go-librespot[32758]: time="2025-11-04T23:42:35Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:36 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:36 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 71. Nov 04 23:42:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:39 volumio go-librespot[32766]: go-librespot daemon starting... Nov 04 23:42:39 volumio go-librespot[32767]: time="2025-11-04T23:42:39Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:39 volumio go-librespot[32767]: time="2025-11-04T23:42:39Z" level=debug msg="app state loaded" Nov 04 23:42:39 volumio go-librespot[32767]: time="2025-11-04T23:42:39Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:39 volumio go-librespot[32767]: time="2025-11-04T23:42:39Z" 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]" Nov 04 23:42:39 volumio go-librespot[32767]: time="2025-11-04T23:42:39Z" 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]" Nov 04 23:42:39 volumio go-librespot[32767]: time="2025-11-04T23:42:39Z" 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]" Nov 04 23:42:39 volumio go-librespot[32767]: time="2025-11-04T23:42:39Z" level=info msg="zeroconf server listening on port 41599" Nov 04 23:42:39 volumio go-librespot[32767]: time="2025-11-04T23:42:39Z" level=debug msg="obtained new client token: AAB4uOEZK+KDePnpft8Ht6moAjptNDFsJifztO7F6xfj/ZfQ5Spafn1d77s7WVz3ikML9A+E5KaTeIVbZhUmbKssRQcRWNKkDa5Mba4JBowKFXHotD2ebPdqq9GVGBzTuIQDm/AjYiIFztbogsd3fVnz7TybraiO9BLNZ3VYmzGTI6+XwWoxGFb+ovdAWs4ahbwMTtc4XZfzyjLtShQUt8dmNu/nUwcDeQ5VozQj52qQssTEd2vT" Nov 04 23:42:39 volumio go-librespot[32767]: time="2025-11-04T23:42:39Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 04 23:42:39 volumio go-librespot[32767]: time="2025-11-04T23:42:39Z" level=debug msg="completed keyexchange" Nov 04 23:42:39 volumio go-librespot[32767]: time="2025-11-04T23:42:39Z" level=debug msg="completed challenge" Nov 04 23:42:39 volumio go-librespot[32767]: time="2025-11-04T23:42:39Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:39 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:39 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:40 volumio volumio[32284]: info: CoreCommandRouter::volumioGetState Nov 04 23:42:40 volumio volumio[32284]: info: CorePlayQueue::getTrack 0 Nov 04 23:42:40 volumio volumio[32284]: info: Listing playlists Nov 04 23:42:40 volumio volumio[32284]: info: Listing playlists Nov 04 23:42:42 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:42 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 72. Nov 04 23:42:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:42 volumio go-librespot[309]: go-librespot daemon starting... Nov 04 23:42:42 volumio go-librespot[310]: time="2025-11-04T23:42:42Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:42 volumio go-librespot[310]: time="2025-11-04T23:42:42Z" level=debug msg="app state loaded" Nov 04 23:42:42 volumio go-librespot[310]: time="2025-11-04T23:42:42Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:42 volumio go-librespot[310]: time="2025-11-04T23:42:42Z" 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]" Nov 04 23:42:42 volumio go-librespot[310]: time="2025-11-04T23:42:42Z" 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]" Nov 04 23:42:42 volumio go-librespot[310]: time="2025-11-04T23:42:42Z" 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]" Nov 04 23:42:42 volumio go-librespot[310]: time="2025-11-04T23:42:42Z" level=info msg="zeroconf server listening on port 43799" Nov 04 23:42:42 volumio go-librespot[310]: time="2025-11-04T23:42:42Z" level=debug msg="obtained new client token: AACsA7AL7RtFKz2uifAvUEqlGeu6VNXpC6xq8dyBCEQ7cLNrkn4kB94kEWbk33+K1IlLWNrslim2Ui6bP/8t5le999MDjXhaldBAe7BEMEAP+o+sq4UdJ4CxQsjtSPzzyRjiuakI0JnR86YgckO0dLG8YYdCd51zB6dgGuQPSUIDRHDGJhOolNo1k1VlW5iMNdhXkkLSO1cTGdkkmM5aWkbeyySKgd7t9+MMFfvpfaJObMAkcVfuL1k=" Nov 04 23:42:42 volumio go-librespot[310]: time="2025-11-04T23:42:42Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 04 23:42:42 volumio go-librespot[310]: time="2025-11-04T23:42:42Z" level=debug msg="completed keyexchange" Nov 04 23:42:42 volumio go-librespot[310]: time="2025-11-04T23:42:42Z" level=debug msg="completed challenge" Nov 04 23:42:42 volumio go-librespot[310]: time="2025-11-04T23:42:42Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:45 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:45 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 73. Nov 04 23:42:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:46 volumio go-librespot[334]: go-librespot daemon starting... Nov 04 23:42:46 volumio go-librespot[335]: time="2025-11-04T23:42:46Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:46 volumio go-librespot[335]: time="2025-11-04T23:42:46Z" level=debug msg="app state loaded" Nov 04 23:42:46 volumio go-librespot[335]: time="2025-11-04T23:42:46Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:46 volumio go-librespot[335]: time="2025-11-04T23:42:46Z" 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]" Nov 04 23:42:46 volumio go-librespot[335]: time="2025-11-04T23:42:46Z" 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]" Nov 04 23:42:46 volumio go-librespot[335]: time="2025-11-04T23:42:46Z" 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]" Nov 04 23:42:46 volumio go-librespot[335]: time="2025-11-04T23:42:46Z" level=info msg="zeroconf server listening on port 38593" Nov 04 23:42:46 volumio go-librespot[335]: time="2025-11-04T23:42:46Z" level=debug msg="obtained new client token: AAAlcEO66LvagnHoByqtPCMjyzK73JAEStoha2uTD19GMYzG9S480BkmE/pgPEOaD9jOcnb8KCsfHe4fi1XzVU45BBmZzWFNjoxcm+JLdAFafL9+0z6M9CQoMMqCyhlLuFPAp5RFuW9r5u/W6ti5CoTbQ7nrNulNsc2tTlB1rST1S4+OqZOqQreGxJXngn1Fh/5wod129Mf79WQVFB5/LvyUvO96BdRpN0EXG8JLBFISdjcIt6ba" Nov 04 23:42:46 volumio go-librespot[335]: time="2025-11-04T23:42:46Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 04 23:42:46 volumio go-librespot[335]: time="2025-11-04T23:42:46Z" level=debug msg="completed keyexchange" Nov 04 23:42:46 volumio go-librespot[335]: time="2025-11-04T23:42:46Z" level=debug msg="completed challenge" Nov 04 23:42:46 volumio go-librespot[335]: time="2025-11-04T23:42:46Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:48 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:48 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 74. Nov 04 23:42:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:49 volumio go-librespot[342]: go-librespot daemon starting... Nov 04 23:42:49 volumio go-librespot[343]: time="2025-11-04T23:42:49Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:49 volumio go-librespot[343]: time="2025-11-04T23:42:49Z" level=debug msg="app state loaded" Nov 04 23:42:49 volumio go-librespot[343]: time="2025-11-04T23:42:49Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:49 volumio go-librespot[343]: time="2025-11-04T23:42:49Z" 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]" Nov 04 23:42:49 volumio go-librespot[343]: time="2025-11-04T23:42:49Z" 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]" Nov 04 23:42:49 volumio go-librespot[343]: time="2025-11-04T23:42:49Z" 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]" Nov 04 23:42:49 volumio go-librespot[343]: time="2025-11-04T23:42:49Z" level=info msg="zeroconf server listening on port 44939" Nov 04 23:42:49 volumio go-librespot[343]: time="2025-11-04T23:42:49Z" level=debug msg="obtained new client token: AAD62Hpmr6QTL31RB4MGy9BoZyensK/BTYN2y88g8VilUVVogKgNVXqCjkT5vePMjeaJVw0H9wDY6JeRUll7fnuGpIzw1UPTj7Eio049/HYXAKus6LzX/RmEewizzE+v64qFddLeEE8V0XsCu/WC+RkxPjba2Id31K0Xegu9LdhlLqi7a366q20LOUt0xdR81iTIznZH7STAPjVfwVj1d40z5K8k5vfD3uvnLH4lU5fUQz/xSdZB7a8=" Nov 04 23:42:49 volumio go-librespot[343]: time="2025-11-04T23:42:49Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 04 23:42:49 volumio go-librespot[343]: time="2025-11-04T23:42:49Z" level=debug msg="completed keyexchange" Nov 04 23:42:49 volumio go-librespot[343]: time="2025-11-04T23:42:49Z" level=debug msg="completed challenge" Nov 04 23:42:49 volumio go-librespot[343]: time="2025-11-04T23:42:49Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:50 volumio volumio[32284]: info: CoreCommandRouter::volumioGetState Nov 04 23:42:50 volumio volumio[32284]: info: CorePlayQueue::getTrack 0 Nov 04 23:42:51 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:51 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 75. Nov 04 23:42:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:53 volumio go-librespot[351]: go-librespot daemon starting... Nov 04 23:42:53 volumio go-librespot[352]: time="2025-11-04T23:42:53Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:53 volumio go-librespot[352]: time="2025-11-04T23:42:53Z" level=debug msg="app state loaded" Nov 04 23:42:53 volumio go-librespot[352]: time="2025-11-04T23:42:53Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:53 volumio go-librespot[352]: time="2025-11-04T23:42:53Z" 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]" Nov 04 23:42:53 volumio go-librespot[352]: time="2025-11-04T23:42:53Z" 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]" Nov 04 23:42:53 volumio go-librespot[352]: time="2025-11-04T23:42:53Z" 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]" Nov 04 23:42:53 volumio go-librespot[352]: time="2025-11-04T23:42:53Z" level=info msg="zeroconf server listening on port 36973" Nov 04 23:42:53 volumio go-librespot[352]: time="2025-11-04T23:42:53Z" level=debug msg="obtained new client token: AADcglXTHEROH1PpkC+/A9uAzrRxn7jH3B3vwiFl/EZw3kms2MAJDD4klVo8/xyf/nM6eibEtws7brM8ORoLj7tAloffBBBy6d9XjYdZtSTaiEvguj94fS8Tmgc/0dDotWDy0BtE1zpL9RWT4wzZS6r6dBL1qbH3YCZNggPnl69RZm5gKZqhNCiRbNjduCot7ErlnzNTS90Jf3C3sfxOObLl8ldZQa0PLxNQZ/Y+BVuNjv6J+u0k" Nov 04 23:42:53 volumio go-librespot[352]: time="2025-11-04T23:42:53Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 04 23:42:53 volumio go-librespot[352]: time="2025-11-04T23:42:53Z" level=debug msg="completed keyexchange" Nov 04 23:42:53 volumio go-librespot[352]: time="2025-11-04T23:42:53Z" level=debug msg="completed challenge" Nov 04 23:42:53 volumio go-librespot[352]: time="2025-11-04T23:42:53Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:54 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:54 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:42:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 76. Nov 04 23:42:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:42:56 volumio go-librespot[376]: go-librespot daemon starting... Nov 04 23:42:56 volumio go-librespot[377]: time="2025-11-04T23:42:56Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:42:56 volumio go-librespot[377]: time="2025-11-04T23:42:56Z" level=debug msg="app state loaded" Nov 04 23:42:56 volumio go-librespot[377]: time="2025-11-04T23:42:56Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:42:56 volumio go-librespot[377]: time="2025-11-04T23:42:56Z" 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]" Nov 04 23:42:56 volumio go-librespot[377]: time="2025-11-04T23:42:56Z" 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]" Nov 04 23:42:56 volumio go-librespot[377]: time="2025-11-04T23:42:56Z" 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]" Nov 04 23:42:56 volumio go-librespot[377]: time="2025-11-04T23:42:56Z" level=info msg="zeroconf server listening on port 42581" Nov 04 23:42:56 volumio go-librespot[377]: time="2025-11-04T23:42:56Z" level=debug msg="obtained new client token: AAB5L3K1e/rlqJi2OxAdMD/8ypLdIJBtXRpXF7PZVPfhiP61zJUskMQUhcg+wya8zDrz7mFchAa7xhUx5HP9ADFC1wLTKcbX+6I1PuBCCDzgkFQXI0i2WN0PaL/von8ZF0ME+a5tx5t7GncP2jyDJ4CtksZ27zGUZDGbHcRyJIExApD+/ZGkywnF8ANEVRIWr8lCOhDiPqfbL+urB485YGg+l+HZKzwNNTblHWvM22M6XoVPlXX3yKg=" Nov 04 23:42:56 volumio go-librespot[377]: time="2025-11-04T23:42:56Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 04 23:42:56 volumio go-librespot[377]: time="2025-11-04T23:42:56Z" level=debug msg="completed keyexchange" Nov 04 23:42:56 volumio go-librespot[377]: time="2025-11-04T23:42:56Z" level=debug msg="completed challenge" Nov 04 23:42:56 volumio go-librespot[377]: time="2025-11-04T23:42:56Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:42:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:42:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:42:57 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:42:57 volumio volumio[32284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:43:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 77. Nov 04 23:43:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:43:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 04 23:43:00 volumio go-librespot[384]: go-librespot daemon starting... Nov 04 23:43:00 volumio go-librespot[385]: time="2025-11-04T23:43:00Z" level=info msg="running go-librespot 0.4.0" Nov 04 23:43:00 volumio go-librespot[385]: time="2025-11-04T23:43:00Z" level=debug msg="app state loaded" Nov 04 23:43:00 volumio go-librespot[385]: time="2025-11-04T23:43:00Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 04 23:43:00 volumio volumio[32284]: info: CoreCommandRouter::volumioGetState Nov 04 23:43:00 volumio volumio[32284]: info: CorePlayQueue::getTrack 0 Nov 04 23:43:00 volumio volumio[32284]: info: Listing playlists Nov 04 23:43:00 volumio volumio[32284]: info: Listing playlists Nov 04 23:43:00 volumio go-librespot[385]: time="2025-11-04T23:43:00Z" 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]" Nov 04 23:43:00 volumio go-librespot[385]: time="2025-11-04T23:43:00Z" 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]" Nov 04 23:43:00 volumio go-librespot[385]: time="2025-11-04T23:43:00Z" 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]" Nov 04 23:43:00 volumio go-librespot[385]: time="2025-11-04T23:43:00Z" level=info msg="zeroconf server listening on port 34079" Nov 04 23:43:00 volumio go-librespot[385]: time="2025-11-04T23:43:00Z" level=debug msg="obtained new client token: AACsuXicVJIfDzqsL4Y1oveCJXZLgOHsSqyOTGKduipQRCwAquEgi7jsJgKLkbyvCNedFOSEVa0CqnaammjE6klFp83sCDQ0MP/lGA2fkQ8Lh9WXc9OVlg4socY6LkGVgqH8cJ+TExXOuDBcekQiZixtaOT8KcxRuXGwiOEuCXH0VWZUSdT7rUtdsO3vieVyS3ZNMmrdpno+p0blYfS/C/e0zAoDveIdFd6Q9EKD10W2Z9uBh6W6lUI=" Nov 04 23:43:00 volumio go-librespot[385]: time="2025-11-04T23:43:00Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 04 23:43:00 volumio go-librespot[385]: time="2025-11-04T23:43:00Z" level=debug msg="completed keyexchange" Nov 04 23:43:00 volumio go-librespot[385]: time="2025-11-04T23:43:00Z" level=debug msg="completed challenge" Nov 04 23:43:00 volumio volumio[32284]: info: Initializing connection to go-librespot Websocket Nov 04 23:43:00 volumio go-librespot[385]: time="2025-11-04T23:43:00Z" level=debug msg="new websocket client" Nov 04 23:43:00 volumio volumio[32284]: info: Connection to go-librespot Websocket established Nov 04 23:43:00 volumio go-librespot[385]: time="2025-11-04T23:43:00Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 04 23:43:00 volumio volumio[32284]: info: Connection to go-librespot Websocket closed Nov 04 23:43:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 04 23:43:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 04 23:43:03 volumio volumio[32284]: info: Getting Spotify volume Nov 04 23:43:03 volumio volumio[32284]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 04 23:43:03 volumio volumio[32284]: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 04 23:43:03 volumio volumio[32284]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Nov 04 23:43:03 volumio volumio[32284]: errno: -111, Nov 04 23:43:03 volumio volumio[32284]: code: 'ECONNREFUSED', Nov 04 23:43:03 volumio volumio[32284]: syscall: 'connect', Nov 04 23:43:03 volumio volumio[32284]: address: '127.0.0.1', Nov 04 23:43:03 volumio volumio[32284]: port: 9879, Nov 04 23:43:03 volumio volumio[32284]: response: undefined Nov 04 23:43:03 volumio volumio[32284]: } Nov 04 23:43:03 volumio volumio[32284]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 04 23:43:03 volumio sudo[410]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-11-04 23:42' Nov 04 23:43:03 volumio sudo[410]: 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="c22b72a8acb34a699a626adb0a09a6b88ee7233a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="40400d6a6fa57cf20e36499e510876b3654e9c4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Oct 4 16:40:08 UTC 2025" VOLUMIO_VERSION="4.061" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="7f8ace80645f85765fa10c72d1769d04"