Nov 01 20:27:00 volumio volumio[27159]: info: Loading plugin "outputs"... Nov 01 20:27:00 volumio volumio[27159]: info: Loading plugin "albumart"... Nov 01 20:27:00 volumio volumio[27159]: info: Plugin example_plugin is not enabled Nov 01 20:27:00 volumio volumio[27159]: info: Loading plugin "inputs"... Nov 01 20:27:00 volumio volumio[27159]: info: Loading plugin "updater_comm"... Nov 01 20:27:00 volumio volumio[27159]: info: Plugin mpdemulation is not enabled Nov 01 20:27:00 volumio volumio[27159]: info: Loading plugin "rest_api"... Nov 01 20:27:00 volumio volumio[27159]: info: Loading plugin "websocket"... Nov 01 20:27:00 volumio volumio[27159]: info: Starting Socket.io Server version 1.7.4 Nov 01 20:27:00 volumio volumio[27159]: info: Loading plugin "Systeminfo"... Nov 01 20:27:00 volumio volumio[27159]: info: Loading i18n strings for locale en Nov 01 20:27:00 volumio volumio[27159]: Updating browse sources language Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 20:27:00 volumio volumio[27219]: Forking 3 albumart workers Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::initPlayerControls Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 20:27:00 volumio volumio[27159]: Express server listening on port 3000 Nov 01 20:27:00 volumio volumio[27159]: [Metrics] WebUI: 1s 938.65ms Nov 01 20:27:00 volumio volumio[27159]: info: CoreStateMachine::resetVolumioState Nov 01 20:27:00 volumio volumio[27159]: info: CoreStateMachine::getcurrentVolume Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:00 volumio volumio[27159]: info: Cannot read play queue from file Nov 01 20:27:00 volumio volumio[27159]: info: Volumio Network Manager: Network status updated: 1 Nov 01 20:27:00 volumio volumio[27159]: info: CoreStateMachine::setRepeat null single undefined Nov 01 20:27:00 volumio volumio[27159]: info: CoreStateMachine::pushState Nov 01 20:27:00 volumio volumio[27159]: info: CorePlayQueue::getTrack 0 Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::volumioPushState Nov 01 20:27:00 volumio volumio[27159]: info: CoreStateMachine::setRandom null Nov 01 20:27:00 volumio volumio[27159]: info: CoreStateMachine::pushState Nov 01 20:27:00 volumio volumio[27159]: info: CorePlayQueue::getTrack 0 Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::volumioPushState Nov 01 20:27:00 volumio volumio[27159]: info: VolumeController:: Volume=33 Mute =false Nov 01 20:27:00 volumio volumio[27159]: info: CoreStateMachine::pushState Nov 01 20:27:00 volumio volumio[27159]: info: CorePlayQueue::getTrack 0 Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::volumioPushState Nov 01 20:27:00 volumio volumio[27159]: info: CoreStateMachine::updateTrackBlock Nov 01 20:27:00 volumio volumio[27159]: info: CorePlayQueue::getTrackBlock Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 20:27:00 volumio volumio[27159]: info: Setting Device type: Raspberry PI Nov 01 20:27:00 volumio volumio[27159]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Nov 01 20:27:00 volumio volumio[27159]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b04170 Nov 01 20:27:00 volumio volumio[27159]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Nov 01 20:27:00 volumio volumio[27159]: info: VolumeController:: Volume=33 Mute =false Nov 01 20:27:00 volumio volumio[27159]: info: CoreStateMachine::pushState Nov 01 20:27:00 volumio volumio[27159]: info: CorePlayQueue::getTrack 0 Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::volumioPushState Nov 01 20:27:00 volumio volumio[27159]: info: Discovery: adding 70853f74-8210-4683-a3fa-e1217517bd40 Nov 01 20:27:00 volumio volumio[27159]: info: Discovery: Found device Volumio Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::volumioGetState Nov 01 20:27:00 volumio volumio[27159]: info: CorePlayQueue::getTrack 0 Nov 01 20:27:00 volumio volumio[27159]: info: Discovery: this is already registered, 70853f74-8210-4683-a3fa-e1217517bd40 Nov 01 20:27:00 volumio volumio[27159]: info: Discovery: Found device Volumio Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::volumioGetState Nov 01 20:27:00 volumio volumio[27159]: info: CorePlayQueue::getTrack 0 Nov 01 20:27:00 volumio volumio[27159]: info: Completed loading Core Plugins Nov 01 20:27:00 volumio volumio[27159]: info: Preparing to generate the ALSA configuration file Nov 01 20:27:00 volumio volumio[27159]: info: Asound.conf file unchanged, so no further update is needed Nov 01 20:27:00 volumio volumio[27159]: info: Output device has changed, restarting MPD Nov 01 20:27:00 volumio volumio[27159]: info: Output device has changed, restarting Shairport Sync Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:00 volumio sudo[27275]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 20:27:00 volumio sudo[27277]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 20:27:00 volumio sudo[27277]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 20:27:00 volumio sudo[27275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 20:27:00 volumio sudo[27275]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:00 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Nov 01 20:27:00 volumio volumio[27159]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 20:27:00 volumio volumio[27159]: info: ___________ START PLUGINS ___________ Nov 01 20:27:00 volumio volumio[27159]: info: ControllerMpd::onStart: Initializing MPD Nov 01 20:27:00 volumio volumio[27159]: info: Creating MPD Configuration file Nov 01 20:27:00 volumio systemd[1]: mpd.service: Deactivated successfully. Nov 01 20:27:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 01 20:27:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 01 20:27:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 01 20:27:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 20:27:00 volumio volumio[27159]: info: [1762028820442] CoreMusicLibrary::Adding element Media Servers Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 20:27:00 volumio sudo[27285]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 01 20:27:00 volumio sudo[27287]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 01 20:27:00 volumio sudo[27287]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 20:27:00 volumio sudo[27285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:00 volumio sudo[27285]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:00 volumio volumio[27159]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 01 20:27:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 01 20:27:00 volumio volumio[27159]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 20:27:00 volumio volumio[27159]: info: [1762028820483] CoreMusicLibrary::Adding element Last_100 Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 20:27:00 volumio volumio[27159]: info: [1762028820484] CoreMusicLibrary::Adding element Webradio Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 20:27:00 volumio volumio[27159]: info: Initializing BBC Radios Nov 01 20:27:00 volumio systemd[1]: mpd.service: Deactivated successfully. Nov 01 20:27:00 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 01 20:27:00 volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 01 20:27:00 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 01 20:27:00 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 01 20:27:00 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 01 20:27:00 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 01 20:27:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 71. Nov 01 20:27:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:00 volumio go-librespot[27305]: go-librespot daemon starting... Nov 01 20:27:00 volumio go-librespot[27307]: time="2025-11-01T20:27:00Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:00 volumio go-librespot[27307]: time="2025-11-01T20:27:00Z" level=debug msg="app state loaded" Nov 01 20:27:00 volumio go-librespot[27307]: time="2025-11-01T20:27:00Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:00 volumio sudo[27302]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 01 20:27:00 volumio sudo[27302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 01 20:27:00 volumio sudo[27302]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:00 volumio volumio[27159]: info: Creating Spotify config file Nov 01 20:27:00 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:00 volumio volumio[27231]: Starting albumart workers Nov 01 20:27:00 volumio go-librespot[27307]: time="2025-11-01T20:27:00Z" 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 01 20:27:00 volumio go-librespot[27307]: time="2025-11-01T20:27:00Z" 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 01 20:27:00 volumio go-librespot[27307]: time="2025-11-01T20:27:00Z" 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 01 20:27:00 volumio go-librespot[27307]: time="2025-11-01T20:27:00Z" level=info msg="zeroconf server listening on port 37135" Nov 01 20:27:00 volumio go-librespot[27307]: time="2025-11-01T20:27:00Z" level=debug msg="obtained new client token: AACubY8dgDpwKGLBoLM8QnJYtBYPa9G1xh/2R9OERGFjdV5AgG6umvlcQ56V/B8uu6t06Cb0sPJW4yZjwhmfLORlTN+br0F1TehU+SGLUmIAuOCqTatDhlUx67yKijTf7yh7+CEa40cqo1+fcyd3eSDhsqbZfzAHkQVjdD2bVGuZPbyuwPLFSD6tD8NRmE04yroyI6d8tlv0ZBoKNKL325JCGHeCReMDwRdQYtGKBCxTgB/0kNxrtD8=" Nov 01 20:27:00 volumio go-librespot[27307]: time="2025-11-01T20:27:00Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:00 volumio volumio[27159]: info: Volumio Calling Home Nov 01 20:27:00 volumio go-librespot[27307]: time="2025-11-01T20:27:00Z" level=debug msg="completed keyexchange" Nov 01 20:27:00 volumio go-librespot[27307]: time="2025-11-01T20:27:00Z" level=debug msg="completed challenge" Nov 01 20:27:00 volumio volumio[27230]: Starting albumart workers Nov 01 20:27:00 volumio go-librespot[27307]: time="2025-11-01T20:27: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 01 20:27:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:00 volumio volumio[27229]: Starting albumart workers Nov 01 20:27:00 volumio volumio[27159]: info: MPD Permissions set Nov 01 20:27:00 volumio volumio[27159]: info: MPD Permissions set Nov 01 20:27:01 volumio volumio[27159]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Nov 01 20:27:01 volumio volumio[27159]: info: Volumio called home Nov 01 20:27:01 volumio volumio[27159]: info: Spotify config file written Nov 01 20:27:01 volumio sudo[27342]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 01 20:27:01 volumio sudo[27342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 20:27:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:01 volumio mpd[27324]: 2025-11-01T20:27:01 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:01 volumio go-librespot[27344]: go-librespot daemon starting... Nov 01 20:27:01 volumio systemd[1]: Started mpd.service - Music Player Daemon. Nov 01 20:27:01 volumio go-librespot[27348]: time="2025-11-01T20:27:01Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:01 volumio go-librespot[27348]: time="2025-11-01T20:27:01Z" level=debug msg="app state loaded" Nov 01 20:27:01 volumio sudo[27277]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:01 volumio go-librespot[27348]: time="2025-11-01T20:27:01Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:01 volumio sudo[27287]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:01 volumio sudo[27342]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:01 volumio volumio[27159]: info: No need to fix Spotify hosts Nov 01 20:27:01 volumio volumio[27159]: info: Starting Shairport Sync Nov 01 20:27:01 volumio volumio[27159]: info: Starting Shairport Sync Nov 01 20:27:01 volumio volumio[27159]: info: Starting Shairport Sync Nov 01 20:27:01 volumio sudo[27373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 01 20:27:01 volumio sudo[27373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 20:27:01 volumio volumio[27159]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 01 20:27:01 volumio volumio[27159]: SPOTIFY: BQD7IQJ1BPtB4oUrzd2QwW1jy90_3tEGDDPk1uWxBP2-FgwERmla4LMtdGKZkE4faQC-dDZpYWx7MYzMABI-5F_ALl04TF9wSRlMrVZmo8Jawd7BvtJn2zDj-m4jE-6oG_GwQVO4KfNzmuJH27HxCO5WeUinDsmB9UH9QC1jUydpbwsKjxPpl4MN1T5maB9sJ2EpXDUlAivwhcAKwdXxD7q9cm-NQo7PWjjN-sZxsWiznY7pQd4IFLrIWiU-WfffRXS1c0HLPbCrkVpYWo0pK_V7mfa54dbrWwYJOXiMekMjnnn1dhg Nov 01 20:27:01 volumio volumio[27159]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 01 20:27:01 volumio volumio[27159]: info: New Spotify access token = BQD7IQJ1BPtB4oUrzd2QwW1jy90_3tEGDDPk1uWxBP2-FgwERmla4LMtdGKZkE4faQC-dDZpYWx7MYzMABI-5F_ALl04TF9wSRlMrVZmo8Jawd7BvtJn2zDj-m4jE-6oG_GwQVO4KfNzmuJH27HxCO5WeUinDsmB9UH9QC1jUydpbwsKjxPpl4MN1T5maB9sJ2EpXDUlAivwhcAKwdXxD7q9cm-NQo7PWjjN-sZxsWiznY7pQd4IFLrIWiU-WfffRXS1c0HLPbCrkVpYWo0pK_V7mfa54dbrWwYJOXiMekMjnnn1dhg Nov 01 20:27:01 volumio volumio[27159]: info: Spotify credentials grant success - running version from March 24, 2019 Nov 01 20:27:01 volumio sudo[27375]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 01 20:27:01 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 01 20:27:01 volumio sudo[27375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 20:27:01 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 01 20:27:01 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 01 20:27:01 volumio systemd[1]: shairport-sync.service: Consumed 1.881s CPU time. Nov 01 20:27:01 volumio go-librespot[27348]: time="2025-11-01T20:27:01Z" 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 01 20:27:01 volumio go-librespot[27348]: time="2025-11-01T20:27:01Z" 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 01 20:27:01 volumio go-librespot[27348]: time="2025-11-01T20:27:01Z" 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 01 20:27:01 volumio go-librespot[27348]: time="2025-11-01T20:27:01Z" level=info msg="zeroconf server listening on port 43023" Nov 01 20:27:01 volumio sudo[27378]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 01 20:27:01 volumio sudo[27378]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 20:27:01 volumio volumio[27159]: error: MPD error: The expression evaluated to a falsy value: Nov 01 20:27:01 volumio volumio[27159]: assert.ok(self.idling) Nov 01 20:27:01 volumio volumio[27159]: error: The expression evaluated to a falsy value: Nov 01 20:27:01 volumio volumio[27159]: assert.ok(self.idling) Nov 01 20:27:01 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 01 20:27:01 volumio volumio[27159]: info: MPD running with PID27324 Nov 01 20:27:01 volumio volumio[27159]: ,establishing connection Nov 01 20:27:01 volumio volumio[27159]: error: updateQueue error: null Nov 01 20:27:01 volumio sudo[27373]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:01 volumio volumio[27159]: info: Shairport-Sync Started Nov 01 20:27:01 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 01 20:27:01 volumio volumio[27159]: Error adding Membership: Error: addMembership EINVAL Nov 01 20:27:01 volumio volumio[27159]: error: updateQueue error: null Nov 01 20:27:01 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 01 20:27:01 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::volumioGetState Nov 01 20:27:01 volumio volumio[27159]: info: CorePlayQueue::getTrack 0 Nov 01 20:27:01 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 01 20:27:01 volumio sudo[27378]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:01 volumio sudo[27375]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:01 volumio volumio[27159]: info: Shairport-Sync Started Nov 01 20:27:01 volumio volumio[27159]: info: Shairport-Sync Started Nov 01 20:27:01 volumio go-librespot[27348]: time="2025-11-01T20:27:01Z" level=debug msg="obtained new client token: AABFp7WnSJfveN0fgrJ5Ogf8KweHKX3lgWKN3xEsH3YjzlP6ZDfS5OKtn0e9uxBTzbR4v4g+dNUkZIQsuKEFg4/lHjQe6kKpDvzl9yN2JuhF8lXi4ysSvX1CB7YhnvoNxRiiYZBt6uZCoIakjpZQrfDCLLm+Dcy6w7cN0dB3cVew8UXJfLT2xxodu+q5GduQPq3hIf+BLSFE5G1LGL8yaoGyfxitzg5CW+FYzRJTvS8yjaiV63X7IGs=" Nov 01 20:27:01 volumio go-librespot[27348]: time="2025-11-01T20:27:01Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:01 volumio volumio[27159]: SPOTIFY: User informations: {"country":"DE","display_name":"lapman","email":"ylm19961214@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31hyzsop5elyyfayaiyk5tmkxmky"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31hyzsop5elyyfayaiyk5tmkxmky","id":"31hyzsop5elyyfayaiyk5tmkxmky","images":[],"product":"free","type":"user","uri":"spotify:user:31hyzsop5elyyfayaiyk5tmkxmky"} Nov 01 20:27:01 volumio volumio[27159]: info: Spotify Successfully logged in Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 01 20:27:01 volumio volumio[27159]: info: [1762028821371] CoreMusicLibrary::Adding element Spotify Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 20:27:01 volumio volumio[27159]: Cannot find translation for source Spotify Nov 01 20:27:01 volumio go-librespot[27348]: time="2025-11-01T20:27:01Z" level=debug msg="completed keyexchange" Nov 01 20:27:01 volumio go-librespot[27348]: time="2025-11-01T20:27:01Z" level=debug msg="completed challenge" Nov 01 20:27:01 volumio go-librespot[27348]: time="2025-11-01T20:27:01Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 20:27:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:01 volumio volumio[27159]: info: [yt-cast-receiver] DIAL server listening on port 8098 Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::volumioRetrievevolume Nov 01 20:27:01 volumio volumio[27159]: info: VolumeController:: Volume=33 Mute =false Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::volumioGetState Nov 01 20:27:01 volumio volumio[27159]: info: CorePlayQueue::getTrack 0 Nov 01 20:27:01 volumio volumio[27159]: info: CoreStateMachine::pushState Nov 01 20:27:01 volumio volumio[27159]: info: CorePlayQueue::getTrack 0 Nov 01 20:27:01 volumio volumio[27159]: info: CoreCommandRouter::volumioPushState Nov 01 20:27:01 volumio volumio[27159]: info: Completed starting Core Plugins Nov 01 20:27:01 volumio volumio[27159]: info: ------------------------------------------- Nov 01 20:27:01 volumio volumio[27159]: info: ----- MyVolumio plugins startup ---- Nov 01 20:27:01 volumio volumio[27159]: info: ------------------------------------------- Nov 01 20:27:01 volumio volumio[27159]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 01 20:27:02 volumio volumio-remote-updater[874]: [2025-11-01 20:27:02] [connect] Successful connection Nov 01 20:27:02 volumio volumio-remote-updater[874]: [2025-11-01 20:27:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1762028822 101 Nov 01 20:27:02 volumio volumio[27159]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Nov 01 20:27:03 volumio volumio[27159]: info: Cannot mount NAS NAS at system boot, trial number 2 ,retrying in 5 seconds Nov 01 20:27:04 volumio volumio[27159]: info: go-librespot daemon successfully initialized Nov 01 20:27:04 volumio sudo[27409]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 01 20:27:04 volumio sudo[27409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 20:27:04 volumio sudo[27411]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 01 20:27:04 volumio sudo[27411]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 20:27:04 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Nov 01 20:27:04 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Nov 01 20:27:04 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Nov 01 20:27:04 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Nov 01 20:27:04 volumio mpd_monitor.sh[27414]: MPD Monitor Service: Starting MPD Monitor Service Nov 01 20:27:04 volumio sudo[27409]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:04 volumio sudo[27411]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:04 volumio volumio[27159]: info: Successfully started MPD Monitor Nov 01 20:27:04 volumio volumio[27159]: info: Successfully started MPD Monitor Nov 01 20:27:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 72. Nov 01 20:27:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:04 volumio go-librespot[27419]: go-librespot daemon starting... Nov 01 20:27:04 volumio go-librespot[27420]: time="2025-11-01T20:27:04Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:04 volumio go-librespot[27420]: time="2025-11-01T20:27:04Z" level=debug msg="app state loaded" Nov 01 20:27:04 volumio go-librespot[27420]: time="2025-11-01T20:27:04Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:04 volumio go-librespot[27420]: time="2025-11-01T20:27: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-gae2.spotify.com:80]" Nov 01 20:27:04 volumio go-librespot[27420]: time="2025-11-01T20:27:04Z" 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 01 20:27:04 volumio go-librespot[27420]: time="2025-11-01T20:27:04Z" 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 01 20:27:04 volumio go-librespot[27420]: time="2025-11-01T20:27:04Z" level=info msg="zeroconf server listening on port 37277" Nov 01 20:27:04 volumio go-librespot[27420]: time="2025-11-01T20:27:04Z" level=debug msg="obtained new client token: AADGQllnMDAqH8liHl8f+wI8MiEE04A9iPbwY/qDK9ujERAWxMBoLMVKyXtWcyARXKCITirj72BqJNT1XAo4iahmN4HkZgZvDR6fFAZtV61qoeIUgzjywrrUvZ+mDoidqc3zKBTjLWzWRBij4Zhs/a4p+cmz0pF/YYYscVEbekq/eT07naXDFPr8q/z4XZfa3g/b0S0WkX1ZjtGXHZpB9VzfQCg2vo37ucOOVq+Qo5vG/ALyZTlEnYw=" Nov 01 20:27:04 volumio go-librespot[27420]: time="2025-11-01T20:27:04Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:04 volumio go-librespot[27420]: time="2025-11-01T20:27:04Z" level=debug msg="completed keyexchange" Nov 01 20:27:04 volumio go-librespot[27420]: time="2025-11-01T20:27:04Z" level=debug msg="completed challenge" Nov 01 20:27:04 volumio go-librespot[27420]: time="2025-11-01T20:27: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 01 20:27:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:06 volumio volumio[27159]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Nov 01 20:27:07 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:07 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 73. Nov 01 20:27:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:08 volumio go-librespot[27428]: go-librespot daemon starting... Nov 01 20:27:08 volumio go-librespot[27429]: time="2025-11-01T20:27:08Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:08 volumio go-librespot[27429]: time="2025-11-01T20:27:08Z" level=debug msg="app state loaded" Nov 01 20:27:08 volumio go-librespot[27429]: time="2025-11-01T20:27:08Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:08 volumio go-librespot[27429]: time="2025-11-01T20:27:08Z" 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 01 20:27:08 volumio go-librespot[27429]: time="2025-11-01T20:27:08Z" 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 01 20:27:08 volumio go-librespot[27429]: time="2025-11-01T20:27:08Z" 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 01 20:27:08 volumio go-librespot[27429]: time="2025-11-01T20:27:08Z" level=info msg="zeroconf server listening on port 33037" Nov 01 20:27:08 volumio go-librespot[27429]: time="2025-11-01T20:27:08Z" level=debug msg="obtained new client token: AAA4hgIJ8JaNpVOiMq+CbMbIXeB34/VoBIMm+6KgPMi2bG5sdxVKGIcAh85B4fX0/kMt9Z6FmVImWtHHGswhgSLOcYYsNUnnvGtXpPOPEQqgwaoZfgUPbAMSR7NyPYGtLpvPMVxZ7lXz+uNQTeyDk+SS2vqwK/7zvhVG1NWd1KPL3WPMNhq/eP2z6EAgrXmBSiDAZoXDSh0xEaqi9qklnWssk8z/be1QO6pBZlppPOEDwNCzviey" Nov 01 20:27:08 volumio go-librespot[27429]: time="2025-11-01T20:27:08Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:08 volumio go-librespot[27429]: time="2025-11-01T20:27:08Z" level=debug msg="completed keyexchange" Nov 01 20:27:08 volumio go-librespot[27429]: time="2025-11-01T20:27:08Z" level=debug msg="completed challenge" Nov 01 20:27:08 volumio go-librespot[27429]: time="2025-11-01T20:27:08Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 20:27:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:08 volumio volumio[27159]: info: Cannot mount NAS NAS at system boot, trial number 3 ,retrying in 5 seconds Nov 01 20:27:08 volumio sudo[27452]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 01 20:27:08 volumio sudo[27452]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 20:27:08 volumio sudo[27454]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 01 20:27:08 volumio sudo[27454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 20:27:08 volumio sudo[27452]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:08 volumio sudo[27454]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:08 volumio sudo[27458]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 01 20:27:08 volumio sudo[27458]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 20:27:08 volumio sudo[27458]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:08 volumio volumio[27159]: info: Upmpdcli Daemon Started Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Nov 01 20:27:10 volumio volumio[27159]: info: Adding plugin bluetooth to MyMusic Plugins Nov 01 20:27:10 volumio volumio[27159]: info: Adding plugin multiroom to MyMusic Plugins Nov 01 20:27:10 volumio volumio[27159]: info: Adding plugin metavolumio to MyMusic Plugins Nov 01 20:27:10 volumio volumio[27159]: info: Adding plugin cd_controller to MyMusic Plugins Nov 01 20:27:10 volumio volumio[27159]: info: Adding plugin qobuzconnect to MyMusic Plugins Nov 01 20:27:10 volumio volumio[27159]: info: Adding plugin smart_inputs to MyMusic Plugins Nov 01 20:27:10 volumio volumio[27159]: info: Adding plugin tidalconnect to MyMusic Plugins Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 01 20:27:10 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:10 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:10 volumio volumio[27159]: info: Starting MyVolumio Remote Streaming Endpoints Nov 01 20:27:10 volumio volumio[27159]: info: MyVolumio login type: Token Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 01 20:27:10 volumio volumio[27159]: info: Streaming services startup Nov 01 20:27:10 volumio volumio[27159]: info: Starting Streaming Daemon Nov 01 20:27:10 volumio sudo[27461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 01 20:27:10 volumio sudo[27461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 20:27:10 volumio volumio[27159]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 01 20:27:10 volumio sudo[27461]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:10 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:10 volumio volumio[27159]: error: Cannot start Volumio Streaming Daemon Nov 01 20:27:10 volumio volumio[27159]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 01 20:27:10 volumio volumio[27159]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 01 20:27:10 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:10 volumio volumio[27159]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Nov 01 20:27:11 volumio volumio[27159]: info: MyVolumio token set successfully Nov 01 20:27:11 volumio volumio[27159]: info: MYVOLUMIO: Adding device Nov 01 20:27:11 volumio volumio[27159]: info: MYVOLUMIO: Evaluating Server Nov 01 20:27:11 volumio volumio[27159]: info: MyVolumio status changed Nov 01 20:27:11 volumio volumio[27159]: info: Streaming services startup Nov 01 20:27:11 volumio volumio[27159]: info: Starting Streaming Daemon Nov 01 20:27:11 volumio volumio[27159]: info: Removing browser output: myVolumio user plan is not superstar Nov 01 20:27:11 volumio volumio[27159]: info: Removing audio output: Nov 01 20:27:11 volumio volumio[27159]: info: Stoppping Tunnel 1 Nov 01 20:27:11 volumio sudo[27488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Nov 01 20:27:11 volumio sudo[27488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 20:27:11 volumio sudo[27486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 01 20:27:11 volumio sudo[27486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 01 20:27:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 74. Nov 01 20:27:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:11 volumio go-librespot[27491]: go-librespot daemon starting... Nov 01 20:27:11 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 01 20:27:11 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 01 20:27:11 volumio sudo[27486]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:11 volumio go-librespot[27492]: time="2025-11-01T20:27:11Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:11 volumio go-librespot[27492]: time="2025-11-01T20:27:11Z" level=debug msg="app state loaded" Nov 01 20:27:11 volumio volumio[27159]: error: Cannot start Volumio Streaming Daemon Nov 01 20:27:11 volumio go-librespot[27492]: time="2025-11-01T20:27:11Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:11 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 01 20:27:11 volumio volumio[27159]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 01 20:27:11 volumio volumio[27159]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 01 20:27:11 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 01 20:27:11 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 01 20:27:11 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 01 20:27:11 volumio sudo[27488]: pam_unix(sudo:session): session closed for user root Nov 01 20:27:11 volumio volumio[27159]: info: Remote SSH Stopped Nov 01 20:27:11 volumio go-librespot[27492]: time="2025-11-01T20:27:11Z" 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 01 20:27:11 volumio go-librespot[27492]: time="2025-11-01T20:27:11Z" 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 01 20:27:11 volumio go-librespot[27492]: time="2025-11-01T20:27:11Z" 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 01 20:27:11 volumio go-librespot[27492]: time="2025-11-01T20:27:11Z" level=info msg="zeroconf server listening on port 39099" Nov 01 20:27:11 volumio go-librespot[27492]: time="2025-11-01T20:27:11Z" level=debug msg="obtained new client token: AACJxenVY0ba2cbDZbkUxFhWVTvLwbx3iqKAG+nFKM3XW5cas6syQNNJ2LysOKdBmEnjjPxYH0WdxH2XmxaajaFHLrZ//kqpaXsNOXKhFvyTP+z+bz3omY5/6N0jlsvk0/bOgZC7OyrfzZyzEqEqQwxhIEe1EEGrQBR09TGvyKn64neJ3aY68jBGjfICy13GbGhmghTdbFwv9x/r/mey8pWmnI78vneLhA3YHGaoSseBz+ZVwX+vv5I=" Nov 01 20:27:11 volumio go-librespot[27492]: time="2025-11-01T20:27:11Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:11 volumio go-librespot[27492]: time="2025-11-01T20:27:11Z" level=debug msg="completed keyexchange" Nov 01 20:27:11 volumio go-librespot[27492]: time="2025-11-01T20:27:11Z" level=debug msg="completed challenge" Nov 01 20:27:11 volumio go-librespot[27492]: time="2025-11-01T20:27: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 01 20:27:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:11 volumio volumio[27159]: info: Setting Geolocation for MyVolumio to eu3 Nov 01 20:27:11 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:11 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:11 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:12 volumio volumio[27159]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 01 20:27:12 volumio volumio[27159]: info: Updating MyVolumio device info Nov 01 20:27:12 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:12 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:12 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:13 volumio volumio[27159]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 01 20:27:13 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:13 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:13 volumio volumio[27159]: info: Cannot mount NAS NAS at system boot, trial number 4 ,retrying in 5 seconds Nov 01 20:27:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 75. Nov 01 20:27:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:14 volumio go-librespot[27499]: go-librespot daemon starting... Nov 01 20:27:14 volumio go-librespot[27500]: time="2025-11-01T20:27:14Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:14 volumio go-librespot[27500]: time="2025-11-01T20:27:14Z" level=debug msg="app state loaded" Nov 01 20:27:14 volumio go-librespot[27500]: time="2025-11-01T20:27:14Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:14 volumio go-librespot[27500]: time="2025-11-01T20:27: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 20:27:14 volumio go-librespot[27500]: time="2025-11-01T20:27:14Z" 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 01 20:27:14 volumio go-librespot[27500]: time="2025-11-01T20:27:14Z" 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 01 20:27:14 volumio go-librespot[27500]: time="2025-11-01T20:27:14Z" level=info msg="zeroconf server listening on port 33979" Nov 01 20:27:14 volumio go-librespot[27500]: time="2025-11-01T20:27:14Z" level=debug msg="obtained new client token: AAA6u5hZMvGyQzvr1bxRIAHFzJQO67d0IKWZfo6mR8VyLZvr8+gyIQqDmmvqyWwnnLN9rAjSuajIJSpZ/9vSgmAU+lE4Ckc+gOwvw72GWEQo0MYpFQvBS5G7pInIhfz3SrpBykKAdum6fC9zyZK8ByMVRO2N5CR7g1FvL9+eu/dTenNk7U+cqTkPOxQlIb0jMFdsSxjwi495enOIlJCSG661Wu2Bo7eFz6wHqI9izGPhqW5TwjnLbog=" Nov 01 20:27:14 volumio go-librespot[27500]: time="2025-11-01T20:27:14Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:14 volumio go-librespot[27500]: time="2025-11-01T20:27:14Z" level=debug msg="completed keyexchange" Nov 01 20:27:14 volumio go-librespot[27500]: time="2025-11-01T20:27:14Z" level=debug msg="completed challenge" Nov 01 20:27:14 volumio go-librespot[27500]: time="2025-11-01T20:27: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 01 20:27:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:16 volumio volumio[27159]: info: MYVOLUMIO: Adding device Nov 01 20:27:16 volumio volumio[27159]: info: MYVOLUMIO: Evaluating Server Nov 01 20:27:16 volumio volumio[27159]: info: Setting Geolocation for MyVolumio to eu3 Nov 01 20:27:16 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:16 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:16 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:16 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:16 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:17 volumio volumio[27159]: info: Updating MyVolumio device info Nov 01 20:27:17 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:17 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:17 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:17 volumio volumio[27159]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 01 20:27:17 volumio volumio[27159]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 01 20:27:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 76. Nov 01 20:27:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:18 volumio go-librespot[27523]: go-librespot daemon starting... Nov 01 20:27:18 volumio go-librespot[27524]: time="2025-11-01T20:27:18Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:18 volumio go-librespot[27524]: time="2025-11-01T20:27:18Z" level=debug msg="app state loaded" Nov 01 20:27:18 volumio go-librespot[27524]: time="2025-11-01T20:27:18Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:18 volumio go-librespot[27524]: time="2025-11-01T20:27:18Z" 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 01 20:27:18 volumio go-librespot[27524]: time="2025-11-01T20:27:18Z" 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 01 20:27:18 volumio go-librespot[27524]: time="2025-11-01T20:27:18Z" 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 01 20:27:18 volumio go-librespot[27524]: time="2025-11-01T20:27:18Z" level=info msg="zeroconf server listening on port 40251" Nov 01 20:27:18 volumio go-librespot[27524]: time="2025-11-01T20:27:18Z" level=debug msg="obtained new client token: AAAYx2Z9a9onyTuxyn407UMfzZ5RZTvuFzGsbNqXL52GqHxKwiVOciAuvc73WCpWX/VPbYuSWeI0wIczNMsTzVJXiQXu/y9T+ZWHT5TAhZYHRLxVLdVpEerOsQmXGEiaXrmAuSdnYVe/4tyZWX9Oz76LBacsExurauF06okbSdRbvUaKVY6ybu6xs/JLH2aPh0hmwSEELK1L8JeI1l8SstnKk6jMZsVgeVhZtwWn7oe6FEQtRHp6" Nov 01 20:27:18 volumio go-librespot[27524]: time="2025-11-01T20:27:18Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:18 volumio go-librespot[27524]: time="2025-11-01T20:27:18Z" level=debug msg="completed keyexchange" Nov 01 20:27:18 volumio go-librespot[27524]: time="2025-11-01T20:27:18Z" level=debug msg="completed challenge" Nov 01 20:27:18 volumio go-librespot[27524]: time="2025-11-01T20:27: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 01 20:27:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:18 volumio volumio[27159]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Nov 01 20:27:19 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:19 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 77. Nov 01 20:27:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:21 volumio go-librespot[27545]: go-librespot daemon starting... Nov 01 20:27:21 volumio go-librespot[27546]: time="2025-11-01T20:27:21Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:21 volumio go-librespot[27546]: time="2025-11-01T20:27:21Z" level=debug msg="app state loaded" Nov 01 20:27:21 volumio go-librespot[27546]: time="2025-11-01T20:27:21Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:21 volumio go-librespot[27546]: time="2025-11-01T20:27: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 20:27:21 volumio go-librespot[27546]: time="2025-11-01T20:27:21Z" 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 01 20:27:21 volumio go-librespot[27546]: time="2025-11-01T20:27:21Z" 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 01 20:27:21 volumio go-librespot[27546]: time="2025-11-01T20:27:21Z" level=info msg="zeroconf server listening on port 33925" Nov 01 20:27:21 volumio go-librespot[27546]: time="2025-11-01T20:27:21Z" level=debug msg="obtained new client token: AAA/1Vn/UeX9CW2iiaB8uuQF59tdafowX/dXDSYvaRl+K3+ombi7GnV1BY3gtM2BCSzM/kl1QfY1nOm3tOh02oqYyb3vzUxeIySLLe6A0lBVYpMKWk1a/+B6x1V5LA+hg6PWPy3a6IcEHKJjfvvKq5oFBypPQFolAVMtDSAPQRuk6dTGpTnCZpcxr+CadFW0GW0vQFpuZf7F7YRIVqYH68Mjx6hu+97bugoBeLUzGZzl2CptkA9y49c=" Nov 01 20:27:21 volumio go-librespot[27546]: time="2025-11-01T20:27:21Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:21 volumio go-librespot[27546]: time="2025-11-01T20:27:21Z" level=debug msg="completed keyexchange" Nov 01 20:27:21 volumio go-librespot[27546]: time="2025-11-01T20:27:21Z" level=debug msg="completed challenge" Nov 01 20:27:21 volumio go-librespot[27546]: time="2025-11-01T20:27: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 01 20:27:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:22 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:22 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 78. Nov 01 20:27:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:25 volumio go-librespot[27557]: go-librespot daemon starting... Nov 01 20:27:25 volumio go-librespot[27558]: time="2025-11-01T20:27:25Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:25 volumio go-librespot[27558]: time="2025-11-01T20:27:25Z" level=debug msg="app state loaded" Nov 01 20:27:25 volumio go-librespot[27558]: time="2025-11-01T20:27:25Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:25 volumio go-librespot[27558]: time="2025-11-01T20:27: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-gew4.spotify.com:80]" Nov 01 20:27:25 volumio go-librespot[27558]: time="2025-11-01T20:27:25Z" 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 01 20:27:25 volumio go-librespot[27558]: time="2025-11-01T20:27:25Z" 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 01 20:27:25 volumio go-librespot[27558]: time="2025-11-01T20:27:25Z" level=info msg="zeroconf server listening on port 33415" Nov 01 20:27:25 volumio go-librespot[27558]: time="2025-11-01T20:27:25Z" level=debug msg="obtained new client token: AABjJM9W6JAyeWS3mrQWDsKT25N28yFO3V5KEiNclSHpPGiGgk1HjjpA5l0pxifA6UYsWViLyrXlRDvbkQcEe9PQD0Pd6fB/2FlhEv6aMSYn61FjgnwT2aGwmWOt94IewnE76MugP6wOKcyOo0N54NUWyNgdEhH9sNOiVkAYrubS72zDmOnAthc9/sUQw75sOTEe7p2IyYa8EKiLyxDIcwRYO3L6YkEUmAILhxTOCOwu0U29qjQP" Nov 01 20:27:25 volumio go-librespot[27558]: time="2025-11-01T20:27:25Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:25 volumio go-librespot[27558]: time="2025-11-01T20:27:25Z" level=debug msg="completed keyexchange" Nov 01 20:27:25 volumio go-librespot[27558]: time="2025-11-01T20:27:25Z" level=debug msg="completed challenge" Nov 01 20:27:25 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 01 20:27:25 volumio volumio[27159]: 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 01 20:27:25 volumio go-librespot[27558]: time="2025-11-01T20:27: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 01 20:27:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:25 volumio volumio[27159]: info: CoreCommandRouter::volumioGetState Nov 01 20:27:25 volumio volumio[27159]: info: CorePlayQueue::getTrack 0 Nov 01 20:27:25 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:25 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:28 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:28 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 79. Nov 01 20:27:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:28 volumio go-librespot[27566]: go-librespot daemon starting... Nov 01 20:27:28 volumio go-librespot[27567]: time="2025-11-01T20:27:28Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:28 volumio go-librespot[27567]: time="2025-11-01T20:27:28Z" level=debug msg="app state loaded" Nov 01 20:27:28 volumio go-librespot[27567]: time="2025-11-01T20:27:28Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:28 volumio go-librespot[27567]: time="2025-11-01T20:27: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-gae2.spotify.com:80]" Nov 01 20:27:28 volumio go-librespot[27567]: time="2025-11-01T20:27:28Z" 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 01 20:27:28 volumio go-librespot[27567]: time="2025-11-01T20:27:28Z" 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 01 20:27:28 volumio go-librespot[27567]: time="2025-11-01T20:27:28Z" level=info msg="zeroconf server listening on port 43163" Nov 01 20:27:28 volumio go-librespot[27567]: time="2025-11-01T20:27:28Z" level=debug msg="obtained new client token: AAC4qAMg53l6u68i+KB6TuWi2pfBX/FAeh/mHsRTYyrb8gTLPNFnoSbFMnxZmtsiW14seNjGNroQFfvFhy/AmqAkojTgVLy30xVzbK+as0f3BIMQ6k0ifoWg/ihoqyDFP7m6ozsMAI5PJE2+WzVcytx67FA1Y6F38/dYsgXCqxFyAgVFsR9lDRY5/21bssggR9Mt4NDXJm+n17AWHkHuI9F1RKESXHPk3e5xFHo2AK6bb5elC8XNNGA=" Nov 01 20:27:28 volumio go-librespot[27567]: time="2025-11-01T20:27:28Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:28 volumio go-librespot[27567]: time="2025-11-01T20:27:28Z" level=debug msg="completed keyexchange" Nov 01 20:27:28 volumio go-librespot[27567]: time="2025-11-01T20:27:28Z" level=debug msg="completed challenge" Nov 01 20:27:28 volumio go-librespot[27567]: time="2025-11-01T20:27: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 01 20:27:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::volumioGetBrowseSources Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 20:27:30 volumio volumio[27159]: error: MyVolumio Plugin failed to authenticate in a timely fashion Nov 01 20:27:30 volumio volumio[27159]: info: Completed starting MyVolumio Plugin Nov 01 20:27:30 volumio volumio[27159]: [Metrics] CommandRouter: 32s 55.06ms Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::volumiosetStartupVolume Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::Close All Modals sent Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::Close All Modals sent Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 01 20:27:30 volumio volumio-remote-updater[874]: Test mode disabled Nov 01 20:27:30 volumio volumio-remote-updater[874]: Alpha mode disabled Nov 01 20:27:30 volumio volumio-remote-updater[874]: Alpha legacy test mode disabled Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Nov 01 20:27:30 volumio volumio[27159]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 01 20:27:30 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 01 20:27:31 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 01 20:27:31 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 01 20:27:31 volumio volumio[27159]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 01 20:27:31 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:31 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 80. Nov 01 20:27:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:32 volumio go-librespot[27597]: go-librespot daemon starting... Nov 01 20:27:32 volumio go-librespot[27598]: time="2025-11-01T20:27:32Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:32 volumio go-librespot[27598]: time="2025-11-01T20:27:32Z" level=debug msg="app state loaded" Nov 01 20:27:32 volumio go-librespot[27598]: time="2025-11-01T20:27:32Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:32 volumio go-librespot[27598]: time="2025-11-01T20:27:32Z" 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 01 20:27:32 volumio go-librespot[27598]: time="2025-11-01T20:27:32Z" 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 01 20:27:32 volumio go-librespot[27598]: time="2025-11-01T20:27:32Z" 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 01 20:27:32 volumio go-librespot[27598]: time="2025-11-01T20:27:32Z" level=info msg="zeroconf server listening on port 44303" Nov 01 20:27:32 volumio go-librespot[27598]: time="2025-11-01T20:27:32Z" level=debug msg="obtained new client token: AACQhodtG2QiTdch8ssirpjIy784IJRr0cvGMCRvK2XU5fS3SV2QGxAwyz5VayHgk5sVXu2FZ3Lp98VfswDj4Vvthne3UbyU3dgzfuEp+cHa3EgDYBJICnAFmWAVlvtYzd5vAhvXAnhf5/yHJ1bBLBxNSHaFqJ1NAmvVBSR+jT2BkZ+LAlfr2EIsVkTYWLL/hAsFUR9WobkIgonbzYlUtGSmcnSr5OQ7wWu6Z4tdkDiTNGTMYs7S" Nov 01 20:27:32 volumio go-librespot[27598]: time="2025-11-01T20:27:32Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:32 volumio go-librespot[27598]: time="2025-11-01T20:27:32Z" level=debug msg="completed keyexchange" Nov 01 20:27:32 volumio go-librespot[27598]: time="2025-11-01T20:27:32Z" level=debug msg="completed challenge" Nov 01 20:27:32 volumio go-librespot[27598]: time="2025-11-01T20:27: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 01 20:27:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:34 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:34 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 81. Nov 01 20:27:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:35 volumio go-librespot[27605]: go-librespot daemon starting... Nov 01 20:27:35 volumio go-librespot[27606]: time="2025-11-01T20:27:35Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:35 volumio go-librespot[27606]: time="2025-11-01T20:27:35Z" level=debug msg="app state loaded" Nov 01 20:27:35 volumio go-librespot[27606]: time="2025-11-01T20:27:35Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:35 volumio go-librespot[27606]: time="2025-11-01T20:27: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 20:27:35 volumio go-librespot[27606]: time="2025-11-01T20:27:35Z" 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 01 20:27:35 volumio go-librespot[27606]: time="2025-11-01T20:27:35Z" 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 01 20:27:35 volumio go-librespot[27606]: time="2025-11-01T20:27:35Z" level=info msg="zeroconf server listening on port 33713" Nov 01 20:27:35 volumio go-librespot[27606]: time="2025-11-01T20:27:35Z" level=debug msg="obtained new client token: AAAjxUMAMV71gBnDPzh5oleT7u12LvU9tqpklsYkzcXqy0xN+/lShrfMItMzedVPuqkCnxWCorY6OPJhKol/d4/czC2L9rBXjYVDoJpFJMTqfJhfKt6DFWpmR3tnzBufhGgOmhbNqHbwghPkRxKbbv+f4VKpGVqwKIGoQqdYeef1Jp/5xUFNCOAXG0SMBdppY5Y9i5AIyIDuqD2rWhyvKmnTnIsJCfnT2/wvd4T0tUL0MqIbiqHm00I=" Nov 01 20:27:35 volumio go-librespot[27606]: time="2025-11-01T20:27:35Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:35 volumio go-librespot[27606]: time="2025-11-01T20:27:35Z" level=debug msg="completed keyexchange" Nov 01 20:27:35 volumio go-librespot[27606]: time="2025-11-01T20:27:35Z" level=debug msg="completed challenge" Nov 01 20:27:35 volumio go-librespot[27606]: time="2025-11-01T20:27: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 01 20:27:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:37 volumio volumio[27159]: info: BOOT COMPLETED Nov 01 20:27:37 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:37 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 82. Nov 01 20:27:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:39 volumio go-librespot[27627]: go-librespot daemon starting... Nov 01 20:27:39 volumio go-librespot[27628]: time="2025-11-01T20:27:39Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:39 volumio go-librespot[27628]: time="2025-11-01T20:27:39Z" level=debug msg="app state loaded" Nov 01 20:27:39 volumio go-librespot[27628]: time="2025-11-01T20:27:39Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:39 volumio go-librespot[27628]: time="2025-11-01T20:27: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 20:27:39 volumio go-librespot[27628]: time="2025-11-01T20:27:39Z" 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 01 20:27:39 volumio go-librespot[27628]: time="2025-11-01T20:27:39Z" 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 01 20:27:39 volumio go-librespot[27628]: time="2025-11-01T20:27:39Z" level=info msg="zeroconf server listening on port 38709" Nov 01 20:27:39 volumio go-librespot[27628]: time="2025-11-01T20:27:39Z" level=debug msg="obtained new client token: AAAeGrKkQ9YQvbkykPgUQbq30sJc/QOAKiTR1kQZZmbb8XrP6HX5nV5ufIpiUdAqUBLM1WjLVfO0hB96rIlTe/YSQGhi5uQJgnA9SfOl7u8y79n5Ekg8Vi5AzzdlacVs88aYnl5TjBDZhckTJy/m9VMIlP6i89iKDfIUcU9+mDrUVNRU2nNKo9gqGnANhDNNgAh7+0fkAsZXewVwgEDIJZiUffpOOnJhiInZ11xxiyoYzQuaP+kA" Nov 01 20:27:39 volumio go-librespot[27628]: time="2025-11-01T20:27:39Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:39 volumio go-librespot[27628]: time="2025-11-01T20:27:39Z" level=debug msg="completed keyexchange" Nov 01 20:27:39 volumio go-librespot[27628]: time="2025-11-01T20:27:39Z" level=debug msg="completed challenge" Nov 01 20:27:39 volumio go-librespot[27628]: time="2025-11-01T20:27: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 01 20:27:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:40 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:40 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 83. Nov 01 20:27:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:42 volumio go-librespot[27635]: go-librespot daemon starting... Nov 01 20:27:42 volumio go-librespot[27636]: time="2025-11-01T20:27:42Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:42 volumio go-librespot[27636]: time="2025-11-01T20:27:42Z" level=debug msg="app state loaded" Nov 01 20:27:42 volumio go-librespot[27636]: time="2025-11-01T20:27:42Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:42 volumio go-librespot[27636]: time="2025-11-01T20:27: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 20:27:42 volumio go-librespot[27636]: time="2025-11-01T20:27:42Z" 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 01 20:27:42 volumio go-librespot[27636]: time="2025-11-01T20:27:42Z" 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 01 20:27:42 volumio go-librespot[27636]: time="2025-11-01T20:27:42Z" level=info msg="zeroconf server listening on port 38735" Nov 01 20:27:42 volumio go-librespot[27636]: time="2025-11-01T20:27:42Z" level=debug msg="obtained new client token: AAAJqpbVhNMzBhRed8L+iQq/Lb1f9wGsR12xvmzybwr8mJxTEd8mCIzOxvZdCxH8MTDIR/KzmuxMmh9EnCiWwoI2C6t4u3FHTmn36lEFjSqAAajamh7U47gwj5lUXufRAVFRSFR6XOkDXYuIUXOq0+R/jrcJc8DuPaCBRqeDjATfctC1BOydP3x1RqAxUwsaNUKqJL4riZ327nhVc+L/0V06Im9UL2f1r+vZDUx6BGboPfUphjXqi8E=" Nov 01 20:27:42 volumio go-librespot[27636]: time="2025-11-01T20:27:42Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:42 volumio go-librespot[27636]: time="2025-11-01T20:27:42Z" level=debug msg="completed keyexchange" Nov 01 20:27:42 volumio go-librespot[27636]: time="2025-11-01T20:27:42Z" level=debug msg="completed challenge" Nov 01 20:27:42 volumio go-librespot[27636]: time="2025-11-01T20:27: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 01 20:27:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:43 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:43 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 84. Nov 01 20:27:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:46 volumio go-librespot[27647]: go-librespot daemon starting... Nov 01 20:27:46 volumio go-librespot[27648]: time="2025-11-01T20:27:46Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:46 volumio go-librespot[27648]: time="2025-11-01T20:27:46Z" level=debug msg="app state loaded" Nov 01 20:27:46 volumio go-librespot[27648]: time="2025-11-01T20:27:46Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:46 volumio go-librespot[27648]: time="2025-11-01T20:27: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 01 20:27:46 volumio go-librespot[27648]: time="2025-11-01T20:27: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 01 20:27:46 volumio go-librespot[27648]: time="2025-11-01T20:27: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 01 20:27:46 volumio go-librespot[27648]: time="2025-11-01T20:27:46Z" level=info msg="zeroconf server listening on port 33903" Nov 01 20:27:46 volumio go-librespot[27648]: time="2025-11-01T20:27:46Z" level=debug msg="obtained new client token: AACWrT0BXpXbGSC9K0FF4gQoApuj+z8uyRy025KIibjALaSKnzbpmV2F9WAz9zpGjmewsYYELFOg5few6WaP08Uu43vIm7wmscKKYfJBZY8oI5vuvOiZK48VKi5BWF6lZ0zbSod+2TsW2HuKISR5QudTS0zWgG9muJDJOEpy487/1hFvmWssxeguXftY1RMiJs1Ef9KZevXMLPaAUt9lKuuDlGIHNd5QyvgiqRlO0/KSPNVlpd4oa50=" Nov 01 20:27:46 volumio go-librespot[27648]: time="2025-11-01T20:27:46Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:46 volumio go-librespot[27648]: time="2025-11-01T20:27:46Z" level=debug msg="completed keyexchange" Nov 01 20:27:46 volumio go-librespot[27648]: time="2025-11-01T20:27:46Z" level=debug msg="completed challenge" Nov 01 20:27:46 volumio go-librespot[27648]: time="2025-11-01T20:27: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 01 20:27:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:46 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:46 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:49 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:49 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 85. Nov 01 20:27:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:49 volumio go-librespot[27669]: go-librespot daemon starting... Nov 01 20:27:49 volumio go-librespot[27670]: time="2025-11-01T20:27:49Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:49 volumio go-librespot[27670]: time="2025-11-01T20:27:49Z" level=debug msg="app state loaded" Nov 01 20:27:49 volumio go-librespot[27670]: time="2025-11-01T20:27:49Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:49 volumio go-librespot[27670]: time="2025-11-01T20:27:49Z" 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 01 20:27:49 volumio go-librespot[27670]: time="2025-11-01T20:27:49Z" 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 01 20:27:49 volumio go-librespot[27670]: time="2025-11-01T20:27:49Z" 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 01 20:27:49 volumio go-librespot[27670]: time="2025-11-01T20:27:49Z" level=info msg="zeroconf server listening on port 42661" Nov 01 20:27:49 volumio go-librespot[27670]: time="2025-11-01T20:27:49Z" level=debug msg="obtained new client token: AAAPugGtoD7tV5+8uAa0pLfhb2sJjMIlBphI2J0fObQrEV+KILjPEZW/pqI1WOZoN29G4CzVVN6pcNBs2Iyh4TcO9wFscjYfXkDwO4YvuwjU3EYpRBpH+jbAKxa81/AotvEXTLoFUKyTvLix123wBV/gQNEgXmW0+kz5e9UXRuSX+KSwrl8wxABZPptijW+YZ+3VdfWBdPXnozwUOXzSillBqLFeDKnG2euMu3oz3PPe2W8nLlisIFE=" Nov 01 20:27:49 volumio go-librespot[27670]: time="2025-11-01T20:27:49Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:49 volumio go-librespot[27670]: time="2025-11-01T20:27:49Z" level=debug msg="completed keyexchange" Nov 01 20:27:49 volumio go-librespot[27670]: time="2025-11-01T20:27:49Z" level=debug msg="completed challenge" Nov 01 20:27:49 volumio go-librespot[27670]: time="2025-11-01T20:27: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 01 20:27:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:52 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:52 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 86. Nov 01 20:27:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:53 volumio go-librespot[27677]: go-librespot daemon starting... Nov 01 20:27:53 volumio go-librespot[27678]: time="2025-11-01T20:27:53Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:53 volumio go-librespot[27678]: time="2025-11-01T20:27:53Z" level=debug msg="app state loaded" Nov 01 20:27:53 volumio go-librespot[27678]: time="2025-11-01T20:27:53Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:53 volumio go-librespot[27678]: time="2025-11-01T20:27:53Z" 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 01 20:27:53 volumio go-librespot[27678]: time="2025-11-01T20:27:53Z" 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 01 20:27:53 volumio go-librespot[27678]: time="2025-11-01T20:27:53Z" 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 01 20:27:53 volumio go-librespot[27678]: time="2025-11-01T20:27:53Z" level=info msg="zeroconf server listening on port 45771" Nov 01 20:27:53 volumio go-librespot[27678]: time="2025-11-01T20:27:53Z" level=debug msg="obtained new client token: AACSca+etDrCi99unRpiqM4Pd4vr68Q1FT41q5rMmRlsJH/lM7KZaMGPSGIfW+tx4KXNlN0q6HyO4cdnt3AG2wpZU3fX+Ht+i1v7/fP1VrB4aOs3bG3iEL20ydldcMRq2rMoTknjtm/THNML5ckRxox/abwB9xkXhYfCjcgtHWjopy7NW3mKW7NnOsRtcxzIGswomlPj3ahsZmftEZYg6Qy554pb4A35HrS8KU3XaWUsuQhGvamD" Nov 01 20:27:53 volumio go-librespot[27678]: time="2025-11-01T20:27:53Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:53 volumio go-librespot[27678]: time="2025-11-01T20:27:53Z" level=debug msg="completed keyexchange" Nov 01 20:27:53 volumio go-librespot[27678]: time="2025-11-01T20:27:53Z" level=debug msg="completed challenge" Nov 01 20:27:53 volumio go-librespot[27678]: time="2025-11-01T20:27: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 01 20:27:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:55 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:55 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:27:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 87. Nov 01 20:27:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:27:56 volumio go-librespot[27685]: go-librespot daemon starting... Nov 01 20:27:56 volumio go-librespot[27686]: time="2025-11-01T20:27:56Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:27:56 volumio go-librespot[27686]: time="2025-11-01T20:27:56Z" level=debug msg="app state loaded" Nov 01 20:27:56 volumio go-librespot[27686]: time="2025-11-01T20:27:56Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:27:56 volumio go-librespot[27686]: time="2025-11-01T20:27: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 20:27:56 volumio go-librespot[27686]: time="2025-11-01T20:27:56Z" 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 01 20:27:56 volumio go-librespot[27686]: time="2025-11-01T20:27:56Z" 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 01 20:27:56 volumio go-librespot[27686]: time="2025-11-01T20:27:56Z" level=info msg="zeroconf server listening on port 40027" Nov 01 20:27:56 volumio go-librespot[27686]: time="2025-11-01T20:27:56Z" level=debug msg="obtained new client token: AADMuGRA9t44xtRRQBZjQLoOjmWKXwQPMCGWSrL4Dn3eciCfqtk920+DeYI1ZhDyQ689rCCNdVIgppS5foCrOZM5Hsu4sgzqGlV5kb/G3gP8neIxbr9NOUqAmr5tvi9WrGmIB+3ejhVhGIhN4PdbG4rUvLIPjLblBEWpKXP9c1VfODw+1x+krrVZWw9IdNpEL0Mbj825HREZEPH9yxZ1wZvwoBt90pQe9MdRFeNpXym7MXdKAr8WX+o=" Nov 01 20:27:56 volumio go-librespot[27686]: time="2025-11-01T20:27:56Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:27:56 volumio go-librespot[27686]: time="2025-11-01T20:27:56Z" level=debug msg="completed keyexchange" Nov 01 20:27:56 volumio go-librespot[27686]: time="2025-11-01T20:27:56Z" level=debug msg="completed challenge" Nov 01 20:27:56 volumio go-librespot[27686]: time="2025-11-01T20:27: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 01 20:27:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:27:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:27:58 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:27:58 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 88. Nov 01 20:28:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:00 volumio go-librespot[27707]: go-librespot daemon starting... Nov 01 20:28:00 volumio go-librespot[27708]: time="2025-11-01T20:28:00Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:28:00 volumio go-librespot[27708]: time="2025-11-01T20:28:00Z" level=debug msg="app state loaded" Nov 01 20:28:00 volumio go-librespot[27708]: time="2025-11-01T20:28:00Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:28:00 volumio go-librespot[27708]: time="2025-11-01T20:28:00Z" 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 01 20:28:00 volumio go-librespot[27708]: time="2025-11-01T20:28:00Z" 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 01 20:28:00 volumio go-librespot[27708]: time="2025-11-01T20:28:00Z" 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 01 20:28:00 volumio go-librespot[27708]: time="2025-11-01T20:28:00Z" level=info msg="zeroconf server listening on port 39041" Nov 01 20:28:00 volumio go-librespot[27708]: time="2025-11-01T20:28:00Z" level=debug msg="obtained new client token: AACZ6Tvb6hNEDbhqVBmZlCEOT3FAwHF6rMMcSMvlmqQEt6bZYGMak0QvsAXAOvDttBfUsTftQc3ZdwDpltrSaO+v7fMGs1l2zXMrMyifRXkES42U420cdOwgCJyhf5IWiKj6gxI0pM/x5M5fVz7oUmir8EeCEIWwVV0JNTyVtiXetNkSVkWtSqdOlY/UAYILpjWNU/vk0S39eohh07QxdyH1lv7CFga30qa/X67MI36kPiS20a3R" Nov 01 20:28:00 volumio go-librespot[27708]: time="2025-11-01T20:28:00Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:28:00 volumio go-librespot[27708]: time="2025-11-01T20:28:00Z" level=debug msg="completed keyexchange" Nov 01 20:28:00 volumio go-librespot[27708]: time="2025-11-01T20:28:00Z" level=debug msg="completed challenge" Nov 01 20:28:00 volumio go-librespot[27708]: time="2025-11-01T20:28: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 01 20:28:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:28:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:28:01 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:01 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 89. Nov 01 20:28:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:03 volumio go-librespot[27716]: go-librespot daemon starting... Nov 01 20:28:03 volumio go-librespot[27717]: time="2025-11-01T20:28:03Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:28:03 volumio go-librespot[27717]: time="2025-11-01T20:28:03Z" level=debug msg="app state loaded" Nov 01 20:28:03 volumio go-librespot[27717]: time="2025-11-01T20:28:03Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:28:03 volumio go-librespot[27717]: time="2025-11-01T20:28:03Z" 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 01 20:28:03 volumio go-librespot[27717]: time="2025-11-01T20:28:03Z" 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 01 20:28:03 volumio go-librespot[27717]: time="2025-11-01T20:28:03Z" 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 01 20:28:03 volumio go-librespot[27717]: time="2025-11-01T20:28:03Z" level=info msg="zeroconf server listening on port 42911" Nov 01 20:28:03 volumio go-librespot[27717]: time="2025-11-01T20:28:03Z" level=debug msg="obtained new client token: AAAvqWYjLRAcMNYbMl4yx6dYhy2b2tWxql13kznSbO0O3xs/TqJYqhusAHdTa3m8Ivxn7g9bNZsfcCSotpAqL6W85zQ3IK7JxvBr1UCeL3SKDJwtB3Lcm+lWUMBvSixRpSlh3Qa/TGFmSLV0teg6AGEVjsJQdHE3h+ylwcbpoMnJrjrjfHvVo6IMPReJcQ9C+Yc8/3Q0LGz4svEKcnYJ2N/+2kacyjpRdF9sdWVq1EvttWz9aqVp/is=" Nov 01 20:28:03 volumio go-librespot[27717]: time="2025-11-01T20:28:03Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:28:03 volumio go-librespot[27717]: time="2025-11-01T20:28:03Z" level=debug msg="completed keyexchange" Nov 01 20:28:03 volumio go-librespot[27717]: time="2025-11-01T20:28:03Z" level=debug msg="completed challenge" Nov 01 20:28:03 volumio go-librespot[27717]: time="2025-11-01T20:28:03Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 20:28:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:28:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:28:04 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:04 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 90. Nov 01 20:28:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:07 volumio go-librespot[27727]: go-librespot daemon starting... Nov 01 20:28:07 volumio go-librespot[27728]: time="2025-11-01T20:28:07Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:28:07 volumio go-librespot[27728]: time="2025-11-01T20:28:07Z" level=debug msg="app state loaded" Nov 01 20:28:07 volumio go-librespot[27728]: time="2025-11-01T20:28:07Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:28:07 volumio go-librespot[27728]: time="2025-11-01T20:28: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 01 20:28:07 volumio go-librespot[27728]: time="2025-11-01T20:28: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 01 20:28:07 volumio go-librespot[27728]: time="2025-11-01T20:28: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 01 20:28:07 volumio go-librespot[27728]: time="2025-11-01T20:28:07Z" level=info msg="zeroconf server listening on port 36535" Nov 01 20:28:07 volumio go-librespot[27728]: time="2025-11-01T20:28:07Z" level=debug msg="obtained new client token: AADINoELOZf5uyCFHl/yREaNCovqMOAl8d1GrhAVQya0S2Zw/P/FL49qeWVwOrOdXPvJxEcKJEh8MYobzN8r+3hagOvnaK5S0i52VpxRPvFzrYLDOhhTxy4tLKHX5WPBwI6wycwyQzaFxt2Nyf8W5vQOn3r9P1ZbEqrHVjLqoFPXPKteb+YJo2vOq1GF9yBxgiqAdfcdumsva31o1wxDEtlJ2+bX43zw51ER3K2I747PGOEjrPHF" Nov 01 20:28:07 volumio go-librespot[27728]: time="2025-11-01T20:28:07Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:28:07 volumio go-librespot[27728]: time="2025-11-01T20:28:07Z" level=debug msg="completed keyexchange" Nov 01 20:28:07 volumio go-librespot[27728]: time="2025-11-01T20:28:07Z" level=debug msg="completed challenge" Nov 01 20:28:07 volumio go-librespot[27728]: time="2025-11-01T20:28: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 01 20:28:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:28:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:28:07 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:07 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:10 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:10 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 91. Nov 01 20:28:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:10 volumio go-librespot[27750]: go-librespot daemon starting... Nov 01 20:28:10 volumio go-librespot[27751]: time="2025-11-01T20:28:10Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:28:10 volumio go-librespot[27751]: time="2025-11-01T20:28:10Z" level=debug msg="app state loaded" Nov 01 20:28:10 volumio go-librespot[27751]: time="2025-11-01T20:28:10Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:28:10 volumio go-librespot[27751]: time="2025-11-01T20:28:10Z" 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 01 20:28:10 volumio go-librespot[27751]: time="2025-11-01T20:28:10Z" 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 01 20:28:10 volumio go-librespot[27751]: time="2025-11-01T20:28:10Z" 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 01 20:28:10 volumio go-librespot[27751]: time="2025-11-01T20:28:10Z" level=info msg="zeroconf server listening on port 44149" Nov 01 20:28:10 volumio go-librespot[27751]: time="2025-11-01T20:28:10Z" level=debug msg="obtained new client token: AADYSv0GaE+UXTQ+AGklqgtRsQdQR+CxdUBBVJUxyMZ83Z9Izhn11030IKKmz97C05q67+9FKJGeAwx3UuQepUYYZ4Q/KRa4KBc0rPg8aX5+zIUZczwm0+7joGXRnnvWaF1PPYW25S/Yc0Cq7+pJYpk4HP/K8kquQl8vK1vpvjRr78Fld5Hc34v/idVUGMl8dqWafiwX9BJvSb9Pylr6NU7Ywt2TOyyF/SZcYkgLEqURTxf0u7306CM=" Nov 01 20:28:10 volumio go-librespot[27751]: time="2025-11-01T20:28:10Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:28:10 volumio go-librespot[27751]: time="2025-11-01T20:28:10Z" level=debug msg="completed keyexchange" Nov 01 20:28:10 volumio go-librespot[27751]: time="2025-11-01T20:28:10Z" level=debug msg="completed challenge" Nov 01 20:28:10 volumio go-librespot[27751]: time="2025-11-01T20:28:10Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 20:28:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:28:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:28:13 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:13 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 92. Nov 01 20:28:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:14 volumio go-librespot[27759]: go-librespot daemon starting... Nov 01 20:28:14 volumio go-librespot[27760]: time="2025-11-01T20:28:14Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:28:14 volumio go-librespot[27760]: time="2025-11-01T20:28:14Z" level=debug msg="app state loaded" Nov 01 20:28:14 volumio go-librespot[27760]: time="2025-11-01T20:28:14Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:28:14 volumio go-librespot[27760]: time="2025-11-01T20:28: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 01 20:28:14 volumio go-librespot[27760]: time="2025-11-01T20:28: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 01 20:28:14 volumio go-librespot[27760]: time="2025-11-01T20:28: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 01 20:28:14 volumio go-librespot[27760]: time="2025-11-01T20:28:14Z" level=info msg="zeroconf server listening on port 35707" Nov 01 20:28:14 volumio go-librespot[27760]: time="2025-11-01T20:28:14Z" level=debug msg="obtained new client token: AABkWuKOww1yC2w2eX78w9/q+rYg1KxWbEtbYtArYQAIeWFRkcy0sEPjhwNflWkXGQLfK7I+2llIMvF+xkS6r3JQlKxTrX4J7FAzEFbISQnoI0h+sE0B2vGMcaSfU8frd/fj/kuFpeH5a45IVXqkpF3AU3i5dwR5Z/KwauJs0VYd7qR97NAT/clT3DC657DGFHOPpxyn1/j7m1AIzn5/nVKaojWm7/QFoJaxm8HhQW5MPRVyWMJR" Nov 01 20:28:14 volumio go-librespot[27760]: time="2025-11-01T20:28:14Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:28:14 volumio go-librespot[27760]: time="2025-11-01T20:28:14Z" level=debug msg="completed keyexchange" Nov 01 20:28:14 volumio go-librespot[27760]: time="2025-11-01T20:28:14Z" level=debug msg="completed challenge" Nov 01 20:28:14 volumio go-librespot[27760]: time="2025-11-01T20:28: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 01 20:28:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:28:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:28:16 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:16 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93. Nov 01 20:28:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:17 volumio go-librespot[27767]: go-librespot daemon starting... Nov 01 20:28:17 volumio go-librespot[27768]: time="2025-11-01T20:28:17Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:28:17 volumio go-librespot[27768]: time="2025-11-01T20:28:17Z" level=debug msg="app state loaded" Nov 01 20:28:17 volumio go-librespot[27768]: time="2025-11-01T20:28:17Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:28:17 volumio go-librespot[27768]: time="2025-11-01T20:28:17Z" 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 01 20:28:17 volumio go-librespot[27768]: time="2025-11-01T20:28:17Z" 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 01 20:28:17 volumio go-librespot[27768]: time="2025-11-01T20:28:17Z" 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 01 20:28:17 volumio go-librespot[27768]: time="2025-11-01T20:28:17Z" level=info msg="zeroconf server listening on port 38679" Nov 01 20:28:17 volumio go-librespot[27768]: time="2025-11-01T20:28:17Z" level=debug msg="obtained new client token: AABGO+8ZpAHnoyfxRBAYeO9xZCXNEGXvbf6SDd04sPPHir1j+HRW9ybFV9HZq0j7EWG5/e8GwQuszX8yev0SeORMBPyIzGYqgs0u9zXrxharUC+pNmynU5nPM9y8/WeUnokMdyGrhUVeEIslPJcLaKDQno6rvsNiYPJS/ZZyWeghOBow5P+4KVjb72N3yehqtfDq19G1fqTzAQMh0MmJEMq4WVNYMep09r3KFORv7Yaj1qMkmF4j0O8=" Nov 01 20:28:17 volumio go-librespot[27768]: time="2025-11-01T20:28:17Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:28:17 volumio go-librespot[27768]: time="2025-11-01T20:28:17Z" level=debug msg="completed keyexchange" Nov 01 20:28:17 volumio go-librespot[27768]: time="2025-11-01T20:28:17Z" level=debug msg="completed challenge" Nov 01 20:28:17 volumio go-librespot[27768]: time="2025-11-01T20:28:17Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 20:28:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:28:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:28:19 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:19 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 94. Nov 01 20:28:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:21 volumio go-librespot[27789]: go-librespot daemon starting... Nov 01 20:28:21 volumio go-librespot[27790]: time="2025-11-01T20:28:21Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:28:21 volumio go-librespot[27790]: time="2025-11-01T20:28:21Z" level=debug msg="app state loaded" Nov 01 20:28:21 volumio go-librespot[27790]: time="2025-11-01T20:28:21Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:28:21 volumio go-librespot[27790]: time="2025-11-01T20:28: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 20:28:21 volumio go-librespot[27790]: time="2025-11-01T20:28:21Z" 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 01 20:28:21 volumio go-librespot[27790]: time="2025-11-01T20:28:21Z" 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 01 20:28:21 volumio go-librespot[27790]: time="2025-11-01T20:28:21Z" level=info msg="zeroconf server listening on port 36897" Nov 01 20:28:21 volumio go-librespot[27790]: time="2025-11-01T20:28:21Z" level=debug msg="obtained new client token: AADCjc77N8jHo17/z693f2+MkACEVwJNBYmSnH60uhIWeHqqv3RMiJGoVX++57cBLdc0H63P5AA+TGBhOJu+V6F/KjmLsnEBbePAunrC3J8N7zvJ/vsBQECjFPYx5HFXJQvkOLnFdAv70Y+Nt90Qcs2TGcbPJW3OcgwZr5r6GFojT5TNXuHHCsHIHlbcS5VsdyAPFQ2yXPZUjTUSDKPqK8OngbP6d3HlIluQwnKA0SrdVRF7xtbS" Nov 01 20:28:21 volumio go-librespot[27790]: time="2025-11-01T20:28:21Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:28:21 volumio go-librespot[27790]: time="2025-11-01T20:28:21Z" level=debug msg="completed keyexchange" Nov 01 20:28:21 volumio go-librespot[27790]: time="2025-11-01T20:28:21Z" level=debug msg="completed challenge" Nov 01 20:28:21 volumio go-librespot[27790]: time="2025-11-01T20:28: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 01 20:28:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:28:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:28:22 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:22 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 95. Nov 01 20:28:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:24 volumio go-librespot[27800]: go-librespot daemon starting... Nov 01 20:28:24 volumio go-librespot[27801]: time="2025-11-01T20:28:24Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:28:24 volumio go-librespot[27801]: time="2025-11-01T20:28:24Z" level=debug msg="app state loaded" Nov 01 20:28:24 volumio go-librespot[27801]: time="2025-11-01T20:28:24Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:28:24 volumio go-librespot[27801]: time="2025-11-01T20:28:24Z" 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 01 20:28:24 volumio go-librespot[27801]: time="2025-11-01T20:28:24Z" 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 01 20:28:24 volumio go-librespot[27801]: time="2025-11-01T20:28:24Z" 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 01 20:28:24 volumio go-librespot[27801]: time="2025-11-01T20:28:24Z" level=info msg="zeroconf server listening on port 35173" Nov 01 20:28:24 volumio go-librespot[27801]: time="2025-11-01T20:28:24Z" level=debug msg="obtained new client token: AABWo3Y+Z+W+223FKus/mcfWK012pklgLYg8SiY5Bs/+HKAtDXq5AgV6cMhzR3ckaGnF6kneohkSAu60Bf4S/UxWqf5T1YAoG9nJ9BTj6sGzFiGdxqDfytNhDHcmxyOsH9j4qOEvCHF35djxpppABRfIIO4ISiqR359+3AO0wzvBNNSEYzY9wvkhsmcUaCzPYRw1vUUj3qVAEW6dy0ldiZ8vjy8spzteewGzFcYpSmiilVYhFAXEsHI=" Nov 01 20:28:24 volumio go-librespot[27801]: time="2025-11-01T20:28:24Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:28:24 volumio go-librespot[27801]: time="2025-11-01T20:28:24Z" level=debug msg="completed keyexchange" Nov 01 20:28:24 volumio go-librespot[27801]: time="2025-11-01T20:28:24Z" level=debug msg="completed challenge" Nov 01 20:28:24 volumio go-librespot[27801]: time="2025-11-01T20:28:24Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 20:28:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:28:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:28:25 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:25 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 96. Nov 01 20:28:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:28 volumio go-librespot[27809]: go-librespot daemon starting... Nov 01 20:28:28 volumio go-librespot[27810]: time="2025-11-01T20:28:28Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:28:28 volumio go-librespot[27810]: time="2025-11-01T20:28:28Z" level=debug msg="app state loaded" Nov 01 20:28:28 volumio go-librespot[27810]: time="2025-11-01T20:28:28Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:28:28 volumio go-librespot[27810]: time="2025-11-01T20:28: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-gae2.spotify.com:80]" Nov 01 20:28:28 volumio go-librespot[27810]: time="2025-11-01T20:28:28Z" 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 01 20:28:28 volumio go-librespot[27810]: time="2025-11-01T20:28:28Z" 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 01 20:28:28 volumio go-librespot[27810]: time="2025-11-01T20:28:28Z" level=info msg="zeroconf server listening on port 40647" Nov 01 20:28:28 volumio go-librespot[27810]: time="2025-11-01T20:28:28Z" level=debug msg="obtained new client token: AAAwF5EnYmj2P0ev2yWLN+p/1DQI8DSQo3TjH36/o0CQc7e4np3bMooALYNkwQ6chjM3ieaveIdsKv2AB7RqmawSJTYPAOi39RPN6ko/RZE22ELhqtPhA0F7Ln0b3UKGHgWeNymQHnuN0kYd7XZ7NPtpxM0UAuVyUd1wwING0PfkTkNvMlCptn692uLWXjtG6JWAh/XCyEeZtX9sz/IKmvYsdab4U7X0f4EWp5vscSib83saUziN" Nov 01 20:28:28 volumio go-librespot[27810]: time="2025-11-01T20:28:28Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:28:28 volumio go-librespot[27810]: time="2025-11-01T20:28:28Z" level=debug msg="completed keyexchange" Nov 01 20:28:28 volumio go-librespot[27810]: time="2025-11-01T20:28:28Z" level=debug msg="completed challenge" Nov 01 20:28:28 volumio go-librespot[27810]: time="2025-11-01T20:28: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 01 20:28:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:28:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:28:28 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:28 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 97. Nov 01 20:28:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:31 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:31 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:31 volumio go-librespot[27833]: go-librespot daemon starting... Nov 01 20:28:31 volumio go-librespot[27834]: time="2025-11-01T20:28:31Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:28:31 volumio go-librespot[27834]: time="2025-11-01T20:28:31Z" level=debug msg="app state loaded" Nov 01 20:28:31 volumio go-librespot[27834]: time="2025-11-01T20:28:31Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:28:31 volumio go-librespot[27834]: time="2025-11-01T20:28:31Z" 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 01 20:28:31 volumio go-librespot[27834]: time="2025-11-01T20:28:31Z" 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 01 20:28:31 volumio go-librespot[27834]: time="2025-11-01T20:28:31Z" 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 01 20:28:31 volumio go-librespot[27834]: time="2025-11-01T20:28:31Z" level=info msg="zeroconf server listening on port 36491" Nov 01 20:28:31 volumio go-librespot[27834]: time="2025-11-01T20:28:31Z" level=debug msg="obtained new client token: AADxZxtJ1dSxYqYgoEcTJPsTi+OwZ+SYftLxGfGvfNZcKPcjeQM+XloPtbVbeS5KI2KF0vVIMBvp831CD3lAh/jeMkWN0yZ/Q4v5nSxCMh4UYdXEsViguujelImycaYF83cJ3ioXAP0DJvesXSXQ9m8rwujNogf5VDB8gtGBg2n5YPUdOZAVgCrTc8ff5TXeWFUqL/eCToWpJ2O9i4tHiL9h2HDqvppUafbyKjYLJ0zzlFuTsw7/qmg=" Nov 01 20:28:31 volumio go-librespot[27834]: time="2025-11-01T20:28:31Z" 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 01 20:28:31 volumio go-librespot[27834]: time="2025-11-01T20:28:31Z" level=debug msg="connected to ap-gew1.spotify.com:443" Nov 01 20:28:31 volumio go-librespot[27834]: time="2025-11-01T20:28:31Z" level=debug msg="completed keyexchange" Nov 01 20:28:31 volumio go-librespot[27834]: time="2025-11-01T20:28:31Z" level=debug msg="completed challenge" Nov 01 20:28:31 volumio go-librespot[27834]: time="2025-11-01T20:28:31Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 20:28:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:28:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:28:34 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:34 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 98. Nov 01 20:28:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:35 volumio go-librespot[27841]: go-librespot daemon starting... Nov 01 20:28:35 volumio go-librespot[27842]: time="2025-11-01T20:28:35Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:28:35 volumio go-librespot[27842]: time="2025-11-01T20:28:35Z" level=debug msg="app state loaded" Nov 01 20:28:35 volumio go-librespot[27842]: time="2025-11-01T20:28:35Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:28:35 volumio go-librespot[27842]: time="2025-11-01T20:28: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-gae2.spotify.com:80]" Nov 01 20:28:35 volumio go-librespot[27842]: time="2025-11-01T20:28:35Z" 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 01 20:28:35 volumio go-librespot[27842]: time="2025-11-01T20:28:35Z" 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 01 20:28:35 volumio go-librespot[27842]: time="2025-11-01T20:28:35Z" level=info msg="zeroconf server listening on port 39515" Nov 01 20:28:35 volumio go-librespot[27842]: time="2025-11-01T20:28:35Z" level=debug msg="obtained new client token: AADlJ7DneZZpgXtksQ47FMQyEZRi0gJF+k4ZCa7Gixcp+QdDpCEP1sCQw8H5jly5I9vuHOqLEmyuc0tw1D5rmZRISrhaCBg1G0VoCRQVOmMAjG+FvAq8+cRZr7cn3N0InBUMRz0AA6+924ZXJEZ4lrImOVT3aWZHh3wwv9gge4JKxX7EfevsYvKE84B89UrZB4dSckXQWg9Ik5Vgs5ScU/MsZsoFHO4lqlBaWyEWo8GsXqn/5BSB" Nov 01 20:28:35 volumio go-librespot[27842]: time="2025-11-01T20:28:35Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:28:35 volumio go-librespot[27842]: time="2025-11-01T20:28:35Z" level=debug msg="completed keyexchange" Nov 01 20:28:35 volumio go-librespot[27842]: time="2025-11-01T20:28:35Z" level=debug msg="completed challenge" Nov 01 20:28:35 volumio go-librespot[27842]: time="2025-11-01T20:28: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 01 20:28:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:28:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:28:37 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:37 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 99. Nov 01 20:28:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:38 volumio go-librespot[27849]: go-librespot daemon starting... Nov 01 20:28:38 volumio go-librespot[27850]: time="2025-11-01T20:28:38Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:28:38 volumio go-librespot[27850]: time="2025-11-01T20:28:38Z" level=debug msg="app state loaded" Nov 01 20:28:38 volumio go-librespot[27850]: time="2025-11-01T20:28:38Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:28:38 volumio go-librespot[27850]: time="2025-11-01T20:28:38Z" 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 01 20:28:38 volumio go-librespot[27850]: time="2025-11-01T20:28:38Z" 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 01 20:28:38 volumio go-librespot[27850]: time="2025-11-01T20:28:38Z" 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 01 20:28:38 volumio go-librespot[27850]: time="2025-11-01T20:28:38Z" level=info msg="zeroconf server listening on port 46401" Nov 01 20:28:38 volumio go-librespot[27850]: time="2025-11-01T20:28:38Z" level=debug msg="obtained new client token: AADd3J/mheqcgc6BfG0/BdhFyFb3n9T3QbCyMaiQwsQgeSTBHE3ljfzHyduHm8oOArjU8ISAETC19QBd4nABix5oxKTw775OseND1/JanjM+7+2NkrCyOPCYUj/Z3ZZt+eHQXnNjPIMV8bEJrJAud1pHIgvikIMBPwGz1TA/+94qWKBbjCpz9j5036p/ytiH4b6OMS73Ulu1J98hvd3po1Smf+flYeFTbBMRns8z9pS3nP00cNZRSkE=" Nov 01 20:28:38 volumio go-librespot[27850]: time="2025-11-01T20:28:38Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:28:38 volumio go-librespot[27850]: time="2025-11-01T20:28:38Z" level=debug msg="completed keyexchange" Nov 01 20:28:38 volumio go-librespot[27850]: time="2025-11-01T20:28:38Z" level=debug msg="completed challenge" Nov 01 20:28:38 volumio go-librespot[27850]: time="2025-11-01T20:28:38Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 20:28:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:28:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:28:40 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:40 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 100. Nov 01 20:28:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:42 volumio go-librespot[27872]: go-librespot daemon starting... Nov 01 20:28:42 volumio go-librespot[27873]: time="2025-11-01T20:28:42Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:28:42 volumio go-librespot[27873]: time="2025-11-01T20:28:42Z" level=debug msg="app state loaded" Nov 01 20:28:42 volumio go-librespot[27873]: time="2025-11-01T20:28:42Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:28:42 volumio go-librespot[27873]: time="2025-11-01T20:28: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 01 20:28:42 volumio go-librespot[27873]: time="2025-11-01T20:28:42Z" 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 01 20:28:42 volumio go-librespot[27873]: time="2025-11-01T20:28:42Z" 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 01 20:28:42 volumio go-librespot[27873]: time="2025-11-01T20:28:42Z" level=info msg="zeroconf server listening on port 43951" Nov 01 20:28:42 volumio go-librespot[27873]: time="2025-11-01T20:28:42Z" level=debug msg="obtained new client token: AAD4o8qGJ+x8XFS4bHbltWg7lfTCAd4gh8AzL1AAhXkRkgTwEUCtGCGNDM/SbWjfvFclClliXBwThAIT1IJgsIsWkklTWup59K42ZO6GRZFmMUu0+Uo6jJiXOUvnSyRP+7NpWj3r8IwhjNqmrc1PH2yKYEjuRsbO37HnEOzBJ1SVhXWqCh/H6m0YL4F03rNqUbPLovhEGo/DTPlpxpZb+6lSxLfidx5c8RMjOmiRWHxeBwKWuisA" Nov 01 20:28:42 volumio go-librespot[27873]: time="2025-11-01T20:28:42Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:28:42 volumio go-librespot[27873]: time="2025-11-01T20:28:42Z" level=debug msg="completed keyexchange" Nov 01 20:28:42 volumio go-librespot[27873]: time="2025-11-01T20:28:42Z" level=debug msg="completed challenge" Nov 01 20:28:42 volumio go-librespot[27873]: time="2025-11-01T20:28: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 01 20:28:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:28:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:28:43 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:43 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 101. Nov 01 20:28:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:45 volumio go-librespot[27883]: go-librespot daemon starting... Nov 01 20:28:45 volumio go-librespot[27884]: time="2025-11-01T20:28:45Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:28:45 volumio go-librespot[27884]: time="2025-11-01T20:28:45Z" level=debug msg="app state loaded" Nov 01 20:28:45 volumio go-librespot[27884]: time="2025-11-01T20:28:45Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:28:45 volumio go-librespot[27884]: time="2025-11-01T20:28:45Z" 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 01 20:28:45 volumio go-librespot[27884]: time="2025-11-01T20:28:45Z" 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 01 20:28:45 volumio go-librespot[27884]: time="2025-11-01T20:28:45Z" 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 01 20:28:45 volumio go-librespot[27884]: time="2025-11-01T20:28:45Z" level=info msg="zeroconf server listening on port 42325" Nov 01 20:28:45 volumio go-librespot[27884]: time="2025-11-01T20:28:45Z" level=debug msg="obtained new client token: AACfZ5oij1WMwkXICZxlMRXl0YzhRI8wWQ5GUzw5h1zVz3kMxc32ksOHcaGLE9nW7selAKllgLNbdGltevjAFnriuaFSo9jhcJ3kVP7RoD+Ipw16+Lgp7ZefFhLYM4sQGVbpjKAUHbrDeqN3/mBifGQzKpI+v8GfLdHKeoFO4xs6cwi7Zy478FeW3+6n8lKAyJvF+B6sPpgxoAIt5UQzpfsA1eMRa+rhZGyXtqb5qoTPp6QZ4avfduA=" Nov 01 20:28:45 volumio go-librespot[27884]: time="2025-11-01T20:28:45Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:28:45 volumio go-librespot[27884]: time="2025-11-01T20:28:45Z" level=debug msg="completed keyexchange" Nov 01 20:28:45 volumio go-librespot[27884]: time="2025-11-01T20:28:45Z" level=debug msg="completed challenge" Nov 01 20:28:45 volumio go-librespot[27884]: time="2025-11-01T20:28:45Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 20:28:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:28:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:28:46 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:46 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 102. Nov 01 20:28:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:48 volumio go-librespot[27891]: go-librespot daemon starting... Nov 01 20:28:48 volumio go-librespot[27892]: time="2025-11-01T20:28:48Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:28:48 volumio go-librespot[27892]: time="2025-11-01T20:28:48Z" level=debug msg="app state loaded" Nov 01 20:28:48 volumio go-librespot[27892]: time="2025-11-01T20:28:48Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:28:48 volumio go-librespot[27892]: time="2025-11-01T20:28:48Z" 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 01 20:28:48 volumio go-librespot[27892]: time="2025-11-01T20:28:48Z" 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 01 20:28:48 volumio go-librespot[27892]: time="2025-11-01T20:28:48Z" 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 01 20:28:48 volumio go-librespot[27892]: time="2025-11-01T20:28:48Z" level=info msg="zeroconf server listening on port 46119" Nov 01 20:28:48 volumio go-librespot[27892]: time="2025-11-01T20:28:48Z" level=debug msg="obtained new client token: AADgLGTmoHNOyuTG+0UzEFHrACUyar8qGggFoT63XW/eSGJswwQzH6fP1U2NtBq0mZjTtR0YK/8Yh9Ny6OCGfPsGc5667BRQvT59wTp6195PApTEF1KLX718dQwXaIua8GP073vjz1xmh/adBiFzgAtPjP2P2hzzzF0qzp3vOdrFvWXFKXdn1NzI6rhP5jsnr+dBqY0TC0GUBaPS3XUQJIDcdBw25HgQKhwwQ2sMFY/XwGp/StZGz/k=" Nov 01 20:28:48 volumio go-librespot[27892]: time="2025-11-01T20:28:48Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:28:49 volumio go-librespot[27892]: time="2025-11-01T20:28:49Z" level=debug msg="completed keyexchange" Nov 01 20:28:49 volumio go-librespot[27892]: time="2025-11-01T20:28:49Z" level=debug msg="completed challenge" Nov 01 20:28:49 volumio go-librespot[27892]: time="2025-11-01T20:28: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 01 20:28:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:28:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:28:49 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:49 volumio volumio[27159]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 103. Nov 01 20:28:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 01 20:28:52 volumio go-librespot[27914]: go-librespot daemon starting... Nov 01 20:28:52 volumio go-librespot[27915]: time="2025-11-01T20:28:52Z" level=info msg="running go-librespot 0.4.0" Nov 01 20:28:52 volumio go-librespot[27915]: time="2025-11-01T20:28:52Z" level=debug msg="app state loaded" Nov 01 20:28:52 volumio go-librespot[27915]: time="2025-11-01T20:28:52Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 20:28:52 volumio go-librespot[27915]: time="2025-11-01T20:28:52Z" 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 01 20:28:52 volumio go-librespot[27915]: time="2025-11-01T20:28:52Z" 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 01 20:28:52 volumio go-librespot[27915]: time="2025-11-01T20:28:52Z" 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 01 20:28:52 volumio go-librespot[27915]: time="2025-11-01T20:28:52Z" level=info msg="zeroconf server listening on port 32883" Nov 01 20:28:52 volumio go-librespot[27915]: time="2025-11-01T20:28:52Z" level=debug msg="obtained new client token: AABHEOZeuJwGLYhkaXeTeouWe5YXoDt9J519B5IaQbSUFDJb40yCbTyv9p4HhEKLAk8okZEpsrZZbTCWCWGWDL+h9v3+Sfwsoslze+Qr/HsP4PyirwGSxJF2Bj5qAD8ScBE3bHCXSd4KkyhtFhkKafRy7MHtMXiYXolCqqLITyHiJVcKLCPr44P/McB0//zlb7VbtMwPFKFKjxliJZ6Lz36I/2XlNkqVLeEA8eaSeCgvusQi5k+VLAE=" Nov 01 20:28:52 volumio go-librespot[27915]: time="2025-11-01T20:28:52Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 01 20:28:52 volumio go-librespot[27915]: time="2025-11-01T20:28:52Z" level=debug msg="completed keyexchange" Nov 01 20:28:52 volumio go-librespot[27915]: time="2025-11-01T20:28:52Z" level=debug msg="completed challenge" Nov 01 20:28:52 volumio volumio[27159]: info: Initializing connection to go-librespot Websocket Nov 01 20:28:52 volumio volumio[27159]: info: Connection to go-librespot Websocket established Nov 01 20:28:52 volumio go-librespot[27915]: time="2025-11-01T20:28:52Z" level=debug msg="new websocket client" Nov 01 20:28:52 volumio go-librespot[27915]: time="2025-11-01T20:28:52Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 01 20:28:52 volumio volumio[27159]: info: Connection to go-librespot Websocket closed Nov 01 20:28:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 20:28:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 20:28:55 volumio volumio[27159]: info: Getting Spotify volume Nov 01 20:28:55 volumio volumio[27159]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 20:28:55 volumio volumio[27159]: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 20:28:55 volumio volumio[27159]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Nov 01 20:28:55 volumio volumio[27159]: errno: -111, Nov 01 20:28:55 volumio volumio[27159]: code: 'ECONNREFUSED', Nov 01 20:28:55 volumio volumio[27159]: syscall: 'connect', Nov 01 20:28:55 volumio volumio[27159]: address: '127.0.0.1', Nov 01 20:28:55 volumio volumio[27159]: port: 9879, Nov 01 20:28:55 volumio volumio[27159]: response: undefined Nov 01 20:28:55 volumio volumio[27159]: } Nov 01 20:28:55 volumio volumio[27159]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 20:28:55 volumio sudo[27936]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-11-01 20:27' Nov 01 20:28:55 volumio sudo[27936]: 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"