Nov 02 13:40:00 volumio volumio[18428]: info: ------------------------------------------- Nov 02 13:40:00 volumio volumio[18428]: info: ----- Volumio3 ---- Nov 02 13:40:00 volumio volumio[18428]: info: ------------------------------------------- Nov 02 13:40:00 volumio volumio[18428]: info: ----- System startup ---- Nov 02 13:40:00 volumio volumio[18428]: info: ------------------------------------------- Nov 02 13:40:00 volumio volumio[18428]: info: MYVOLUMIO Environment detected Nov 02 13:40:00 volumio volumio[18428]: info: Plugin folders cleanup Nov 02 13:40:00 volumio volumio[18428]: info: Scanning into folder /volumio/app/plugins/ Nov 02 13:40:00 volumio volumio[18428]: info: Scanning category audio_interface Nov 02 13:40:00 volumio volumio[18428]: info: Scanning category miscellanea Nov 02 13:40:00 volumio volumio[18428]: info: Scanning category music_service Nov 02 13:40:00 volumio volumio[18428]: info: Scanning category plugins.json Nov 02 13:40:00 volumio volumio[18428]: info: Scanning category system_controller Nov 02 13:40:00 volumio volumio[18428]: info: Scanning category user_interface Nov 02 13:40:00 volumio volumio[18428]: info: Scanning into folder /data/plugins/ Nov 02 13:40:00 volumio volumio[18428]: info: Scanning category music_service Nov 02 13:40:00 volumio volumio[18428]: info: Scanning category user_interface Nov 02 13:40:00 volumio volumio[18428]: info: Plugin folders cleanup completed Nov 02 13:40:00 volumio volumio[18428]: info: ------------------------------------------- Nov 02 13:40:00 volumio volumio[18428]: info: ----- Core plugins startup ---- Nov 02 13:40:00 volumio volumio[18428]: info: ------------------------------------------- Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugins from folder /volumio/app/plugins/ Nov 02 13:40:00 volumio volumio[18428]: info: Adding plugin upnp to MyMusic Plugins Nov 02 13:40:00 volumio volumio[18428]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 02 13:40:00 volumio volumio[18428]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugins from folder /data/plugins/ Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "system"... Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "appearance"... Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "network"... Nov 02 13:40:00 volumio volumio[18428]: info: Refreshing Cached IP Addresses Nov 02 13:40:00 volumio sudo[18453]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 02 13:40:00 volumio sudo[18453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:00 volumio sudo[18453]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:00 volumio sudo[18455]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "services"... Nov 02 13:40:00 volumio sudo[18455]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "alsa_controller"... Nov 02 13:40:00 volumio sudo[18455]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:00 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "wizard"... Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "networkfs"... Nov 02 13:40:00 volumio volumio[18428]: info: Cannot mount NAS NAS at system boot, trial number 1 ,retrying in 5 seconds Nov 02 13:40:00 volumio volumio[18428]: info: Starting Udev Watcher for removable devices Nov 02 13:40:00 volumio volumio[18428]: info: Ignoring mount for partition: boot Nov 02 13:40:00 volumio volumio[18428]: info: Ignoring mount for partition: volumio Nov 02 13:40:00 volumio volumio[18428]: info: Ignoring mount for partition: volumio_data Nov 02 13:40:00 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "volumio_command_line_client"... Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "upnp"... Nov 02 13:40:00 volumio volumio[18428]: info: [1762090800563] Starting Upmpd Daemon Nov 02 13:40:00 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "my_music"... Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "mpd"... Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "upnp_browser"... Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "alarm-clock"... Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "airplay_emulation"... Nov 02 13:40:00 volumio volumio[18428]: info: Starting Shairport Sync Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "last_100"... Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "webradio"... Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "i2s_dacs"... Nov 02 13:40:00 volumio volumio[18428]: info: I2S DAC not set, start Auto-detection Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "volumiodiscovery"... Nov 02 13:40:00 volumio volumio[18428]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 02 13:40:00 volumio volumio[18428]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 02 13:40:00 volumio volumio[18428]: *** WARNING *** For more information see Nov 02 13:40:00 volumio node[18428]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 02 13:40:00 volumio volumio[18428]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 02 13:40:00 volumio volumio[18428]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 02 13:40:00 volumio volumio[18428]: *** WARNING *** For more information see Nov 02 13:40:00 volumio node[18428]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 02 13:40:00 volumio node[18428]: *** WARNING *** For more information see Nov 02 13:40:00 volumio node[18428]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 02 13:40:00 volumio node[18428]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 02 13:40:00 volumio node[18428]: *** WARNING *** For more information see Nov 02 13:40:00 volumio volumio[18428]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 02 13:40:00 volumio volumio[18428]: info: Discovery: Started advertising with name: Volumio Nov 02 13:40:00 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 02 13:40:00 volumio volumio[18428]: info: Loading plugin "spop"... Nov 02 13:40:01 volumio volumio[18428]: info: Loading plugin "ytcr"... Nov 02 13:40:01 volumio volumio[18428]: info: Loading plugin "outputs"... Nov 02 13:40:01 volumio volumio[18428]: info: Loading plugin "albumart"... Nov 02 13:40:01 volumio volumio[18428]: info: Plugin example_plugin is not enabled Nov 02 13:40:01 volumio volumio[18428]: info: Loading plugin "inputs"... Nov 02 13:40:01 volumio volumio[18428]: info: Loading plugin "updater_comm"... Nov 02 13:40:01 volumio volumio[18428]: info: Plugin mpdemulation is not enabled Nov 02 13:40:01 volumio volumio[18428]: info: Loading plugin "rest_api"... Nov 02 13:40:01 volumio volumio[18428]: info: Loading plugin "websocket"... Nov 02 13:40:01 volumio volumio[18428]: info: Starting Socket.io Server version 1.7.4 Nov 02 13:40:01 volumio volumio[18428]: info: Loading plugin "Systeminfo"... Nov 02 13:40:01 volumio volumio[18428]: info: Loading i18n strings for locale en Nov 02 13:40:01 volumio volumio[18428]: Updating browse sources language Nov 02 13:40:01 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 02 13:40:01 volumio volumio[18485]: Forking 3 albumart workers Nov 02 13:40:01 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 02 13:40:01 volumio volumio[18428]: info: CoreCommandRouter::initPlayerControls Nov 02 13:40:01 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:01 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:01 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:01 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:01 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:01 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:01 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:01 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:01 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: Express server listening on port 3000 Nov 02 13:40:02 volumio volumio[18428]: [Metrics] WebUI: 1s 945.76ms Nov 02 13:40:02 volumio volumio[18428]: info: CoreStateMachine::resetVolumioState Nov 02 13:40:02 volumio volumio[18428]: info: CoreStateMachine::getcurrentVolume Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::volumioRetrievevolume Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: Cannot read play queue from file Nov 02 13:40:02 volumio volumio[18428]: info: Volumio Network Manager: Network status updated: 1 Nov 02 13:40:02 volumio volumio[18428]: info: VolumeController:: Volume=33 Mute =false Nov 02 13:40:02 volumio volumio[18428]: info: CoreStateMachine::pushState Nov 02 13:40:02 volumio volumio[18428]: info: CorePlayQueue::getTrack 0 Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::volumioPushState Nov 02 13:40:02 volumio volumio[18428]: info: CoreStateMachine::updateTrackBlock Nov 02 13:40:02 volumio volumio[18428]: info: CorePlayQueue::getTrackBlock Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::volumioRetrievevolume Nov 02 13:40:02 volumio volumio[18428]: info: CoreStateMachine::setRepeat null single undefined Nov 02 13:40:02 volumio volumio[18428]: info: CoreStateMachine::pushState Nov 02 13:40:02 volumio volumio[18428]: info: CorePlayQueue::getTrack 0 Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::volumioPushState Nov 02 13:40:02 volumio volumio[18428]: info: CoreStateMachine::setRandom null Nov 02 13:40:02 volumio volumio[18428]: info: CoreStateMachine::pushState Nov 02 13:40:02 volumio volumio[18428]: info: CorePlayQueue::getTrack 0 Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::volumioPushState Nov 02 13:40:02 volumio volumio[18428]: info: Setting Device type: Raspberry PI Nov 02 13:40:02 volumio volumio[18428]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Nov 02 13:40:02 volumio volumio[18428]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b04170 Nov 02 13:40:02 volumio volumio[18428]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Nov 02 13:40:02 volumio volumio[18428]: info: VolumeController:: Volume=33 Mute =false Nov 02 13:40:02 volumio volumio[18428]: info: CoreStateMachine::pushState Nov 02 13:40:02 volumio volumio[18428]: info: CorePlayQueue::getTrack 0 Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::volumioPushState Nov 02 13:40:02 volumio volumio[18428]: info: Completed loading Core Plugins Nov 02 13:40:02 volumio volumio[18428]: info: Preparing to generate the ALSA configuration file Nov 02 13:40:02 volumio volumio[18428]: info: Asound.conf file unchanged, so no further update is needed Nov 02 13:40:02 volumio volumio[18428]: info: Output device has changed, restarting MPD Nov 02 13:40:02 volumio volumio[18428]: info: Output device has changed, restarting Shairport Sync Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:02 volumio sudo[18543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 02 13:40:02 volumio sudo[18543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:02 volumio sudo[18542]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 02 13:40:02 volumio sudo[18542]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:02 volumio sudo[18542]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:02 volumio volumio[18428]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 02 13:40:02 volumio volumio[18428]: info: ___________ START PLUGINS ___________ Nov 02 13:40:02 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Nov 02 13:40:02 volumio volumio[18428]: info: ControllerMpd::onStart: Initializing MPD Nov 02 13:40:02 volumio volumio[18428]: info: Creating MPD Configuration file Nov 02 13:40:02 volumio systemd[1]: mpd.service: Deactivated successfully. Nov 02 13:40:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 02 13:40:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 118. Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 02 13:40:02 volumio volumio[18428]: info: [1762090802292] CoreMusicLibrary::Adding element Media Servers Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 02 13:40:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 02 13:40:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 02 13:40:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 02 13:40:02 volumio sudo[18553]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 02 13:40:02 volumio sudo[18553]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:02 volumio sudo[18551]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 02 13:40:02 volumio sudo[18551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:02 volumio sudo[18551]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:02 volumio volumio[18428]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 02 13:40:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 02 13:40:02 volumio go-librespot[18564]: go-librespot daemon starting... Nov 02 13:40:02 volumio volumio[18428]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 02 13:40:02 volumio go-librespot[18567]: time="2025-11-02T13:40:02Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:02 volumio go-librespot[18567]: time="2025-11-02T13:40:02Z" level=debug msg="app state loaded" Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 02 13:40:02 volumio volumio[18428]: info: [1762090802345] CoreMusicLibrary::Adding element Last_100 Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 02 13:40:02 volumio go-librespot[18567]: time="2025-11-02T13:40:02Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:02 volumio systemd[1]: mpd.service: Deactivated successfully. Nov 02 13:40:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 02 13:40:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 02 13:40:02 volumio volumio[18428]: info: [1762090802355] CoreMusicLibrary::Adding element Webradio Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 02 13:40:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 02 13:40:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 02 13:40:02 volumio volumio[18428]: info: Initializing BBC Radios Nov 02 13:40:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 02 13:40:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 02 13:40:02 volumio volumio[18497]: Starting albumart workers Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: Creating Spotify config file Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18496]: Starting albumart workers Nov 02 13:40:02 volumio sudo[18575]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 02 13:40:02 volumio sudo[18575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 02 13:40:02 volumio sudo[18575]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:02 volumio go-librespot[18567]: time="2025-11-02T13:40:02Z" 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 02 13:40:02 volumio go-librespot[18567]: time="2025-11-02T13:40:02Z" 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 02 13:40:02 volumio go-librespot[18567]: time="2025-11-02T13:40:02Z" 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 02 13:40:02 volumio go-librespot[18567]: time="2025-11-02T13:40:02Z" level=info msg="zeroconf server listening on port 39543" Nov 02 13:40:02 volumio go-librespot[18567]: time="2025-11-02T13:40:02Z" level=debug msg="obtained new client token: AACSdEme1TZbErkxTmFfD/v0JSeKLTan/WSrdCHgitlIV+6fcDZ7IF1YSv8dv2M4IEdOtyvQCVT8Y3ht7KTRm3gxJjyeySs1Dt9s1fDYadWTWyaCs3BeAUNu35Tvi2o801bKpjWjEHp5tK/hLdYKCMBJJ4JRQj7yq8AjrvdJTxjJQJ9oAUFox+pekx0qBGZo1zlrzeR53GMXq7LYzrqU9Nb/truW3xXVVQGfHkSIhwIQgFWh1HGGkBk=" Nov 02 13:40:02 volumio go-librespot[18567]: time="2025-11-02T13:40:02Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:40:02 volumio volumio[18495]: Starting albumart workers Nov 02 13:40:02 volumio volumio[18428]: info: Volumio Calling Home Nov 02 13:40:02 volumio go-librespot[18567]: time="2025-11-02T13:40:02Z" level=debug msg="completed keyexchange" Nov 02 13:40:02 volumio go-librespot[18567]: time="2025-11-02T13:40:02Z" level=debug msg="completed challenge" Nov 02 13:40:02 volumio go-librespot[18567]: time="2025-11-02T13:40:02Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:40:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:02 volumio volumio[18428]: info: Discovery: adding 70853f74-8210-4683-a3fa-e1217517bd40 Nov 02 13:40:02 volumio volumio[18428]: info: Discovery: Found device Volumio Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::volumioGetState Nov 02 13:40:02 volumio volumio[18428]: info: CorePlayQueue::getTrack 0 Nov 02 13:40:02 volumio volumio[18428]: info: Discovery: this is already registered, 70853f74-8210-4683-a3fa-e1217517bd40 Nov 02 13:40:02 volumio volumio[18428]: info: Discovery: Found device Volumio Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::volumioGetState Nov 02 13:40:02 volumio volumio[18428]: info: CorePlayQueue::getTrack 0 Nov 02 13:40:02 volumio volumio[18428]: info: MPD Permissions set Nov 02 13:40:02 volumio volumio[18428]: info: MPD Permissions set Nov 02 13:40:02 volumio volumio[18428]: 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 02 13:40:02 volumio volumio[18428]: info: Volumio called home Nov 02 13:40:02 volumio volumio[18428]: info: Spotify config file written Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio sudo[18608]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 02 13:40:02 volumio sudo[18608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:02 volumio volumio[18428]: info: No need to fix Spotify hosts Nov 02 13:40:02 volumio go-librespot[18615]: go-librespot daemon starting... Nov 02 13:40:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:02 volumio sudo[18608]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:02 volumio go-librespot[18621]: time="2025-11-02T13:40:02Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:02 volumio go-librespot[18621]: time="2025-11-02T13:40:02Z" level=debug msg="app state loaded" Nov 02 13:40:02 volumio go-librespot[18621]: time="2025-11-02T13:40:02Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:02 volumio volumio[18428]: info: Starting Shairport Sync Nov 02 13:40:02 volumio sudo[18634]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 02 13:40:02 volumio sudo[18634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 02 13:40:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 02 13:40:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 02 13:40:02 volumio systemd[1]: shairport-sync.service: Consumed 1.902s CPU time. Nov 02 13:40:02 volumio volumio[18428]: info: Starting Shairport Sync Nov 02 13:40:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 02 13:40:02 volumio sudo[18640]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 02 13:40:02 volumio sudo[18640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:02 volumio volumio[18428]: info: Starting Shairport Sync Nov 02 13:40:02 volumio sudo[18634]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 02 13:40:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 02 13:40:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 02 13:40:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 02 13:40:02 volumio go-librespot[18621]: time="2025-11-02T13:40:02Z" 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 02 13:40:02 volumio go-librespot[18621]: time="2025-11-02T13:40:02Z" 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 02 13:40:02 volumio go-librespot[18621]: time="2025-11-02T13:40:02Z" 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 02 13:40:02 volumio mpd[18591]: 2025-11-02T13:40:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 02 13:40:02 volumio sudo[18644]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 02 13:40:02 volumio sudo[18644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:02 volumio go-librespot[18621]: time="2025-11-02T13:40:02Z" level=info msg="zeroconf server listening on port 34147" Nov 02 13:40:02 volumio sudo[18640]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:02 volumio systemd[1]: Started mpd.service - Music Player Daemon. Nov 02 13:40:02 volumio sudo[18543]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:02 volumio sudo[18553]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 02 13:40:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 02 13:40:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 02 13:40:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 02 13:40:02 volumio sudo[18644]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:02 volumio volumio[18428]: info: Shairport-Sync Started Nov 02 13:40:02 volumio volumio[18428]: Error adding Membership: Error: addMembership EINVAL Nov 02 13:40:02 volumio volumio[18428]: info: Shairport-Sync Started Nov 02 13:40:03 volumio volumio[18428]: info: Shairport-Sync Started Nov 02 13:40:03 volumio volumio[18428]: info: CoreCommandRouter::volumioGetState Nov 02 13:40:03 volumio volumio[18428]: info: CorePlayQueue::getTrack 0 Nov 02 13:40:03 volumio volumio[18428]: error: MPD error: The expression evaluated to a falsy value: Nov 02 13:40:03 volumio volumio[18428]: assert.ok(self.idling) Nov 02 13:40:03 volumio volumio[18428]: error: The expression evaluated to a falsy value: Nov 02 13:40:03 volumio volumio[18428]: assert.ok(self.idling) Nov 02 13:40:03 volumio volumio[18428]: info: MPD running with PID18591 Nov 02 13:40:03 volumio volumio[18428]: ,establishing connection Nov 02 13:40:03 volumio go-librespot[18621]: time="2025-11-02T13:40:03Z" level=debug msg="obtained new client token: AABgK3XMhVXORVnoxsCZYE4lu+RsCCCcoTHARAJzLQn7Y3+LYmi7uagKfgUGe8XPng0jv/BX71tq0DIPYZpxUQbJo3BxZi0kTkG+ksJM/Fv6WGNucZgMwhRYzgpaXSz5IOoP+gzf7YqwIy0d6tcPYbgwmPzZCUfS+m/FZqYXw4ap4tr0bXsknZ6pBJmLuGVM/STEv9rZH8fNu3D9LRXXzMM2D+UWWvOdBNX53Grt2Dk14fhyku2C" Nov 02 13:40:03 volumio volumio[18428]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 02 13:40:03 volumio volumio[18428]: SPOTIFY: BQD7YNVJJW1tYW_02j6PsLvYIKIGCSdgUI5Y9Oumv5VG9fpqtxad66bl6LzRbO0rBrYOnKzdUTe1FsoYRUeIZfpdyGBOAkuvOa4tNKvblkcnqJCt94_21ey6M2isikxYn97dJ6xeOuiPG2as6y4jAE1zMDHHivYCnTq8hk9fHCtKTaTjvQpo874wmaIiM9MqebV8oIRM06yot9zal4AeEZ-Rlbcq3nRAuX5LsKckXmnHIbS9BZ51UBT2Q9bdgMyJgXVMGg1FgOTkg4E9N-9NEGYwDv1PG2PK3v2RQaYsRwBSJN-MdLk Nov 02 13:40:03 volumio volumio[18428]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 02 13:40:03 volumio volumio[18428]: info: New Spotify access token = BQD7YNVJJW1tYW_02j6PsLvYIKIGCSdgUI5Y9Oumv5VG9fpqtxad66bl6LzRbO0rBrYOnKzdUTe1FsoYRUeIZfpdyGBOAkuvOa4tNKvblkcnqJCt94_21ey6M2isikxYn97dJ6xeOuiPG2as6y4jAE1zMDHHivYCnTq8hk9fHCtKTaTjvQpo874wmaIiM9MqebV8oIRM06yot9zal4AeEZ-Rlbcq3nRAuX5LsKckXmnHIbS9BZ51UBT2Q9bdgMyJgXVMGg1FgOTkg4E9N-9NEGYwDv1PG2PK3v2RQaYsRwBSJN-MdLk Nov 02 13:40:03 volumio volumio[18428]: info: Spotify credentials grant success - running version from March 24, 2019 Nov 02 13:40:03 volumio volumio[18428]: error: updateQueue error: null Nov 02 13:40:03 volumio volumio[18428]: error: updateQueue error: null Nov 02 13:40:03 volumio go-librespot[18621]: time="2025-11-02T13:40:03Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:40:03 volumio go-librespot[18621]: time="2025-11-02T13:40:03Z" level=debug msg="completed keyexchange" Nov 02 13:40:03 volumio go-librespot[18621]: time="2025-11-02T13:40:03Z" level=debug msg="completed challenge" Nov 02 13:40:03 volumio go-librespot[18621]: time="2025-11-02T13:40: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 02 13:40:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:03 volumio volumio[18428]: 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 02 13:40:03 volumio volumio[18428]: info: Spotify Successfully logged in Nov 02 13:40:03 volumio volumio[18428]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 02 13:40:03 volumio volumio[18428]: info: [1762090803179] CoreMusicLibrary::Adding element Spotify Nov 02 13:40:03 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 02 13:40:03 volumio volumio[18428]: Cannot find translation for source Spotify Nov 02 13:40:03 volumio volumio[18428]: info: [yt-cast-receiver] DIAL server listening on port 8098 Nov 02 13:40:03 volumio volumio[18428]: info: CoreCommandRouter::volumioRetrievevolume Nov 02 13:40:03 volumio volumio[18428]: info: VolumeController:: Volume=33 Mute =false Nov 02 13:40:03 volumio volumio[18428]: info: CoreCommandRouter::volumioGetState Nov 02 13:40:03 volumio volumio[18428]: info: CorePlayQueue::getTrack 0 Nov 02 13:40:03 volumio volumio[18428]: info: CoreStateMachine::pushState Nov 02 13:40:03 volumio volumio[18428]: info: CorePlayQueue::getTrack 0 Nov 02 13:40:03 volumio volumio[18428]: info: CoreCommandRouter::volumioPushState Nov 02 13:40:03 volumio volumio[18428]: info: Completed starting Core Plugins Nov 02 13:40:03 volumio volumio[18428]: info: ------------------------------------------- Nov 02 13:40:03 volumio volumio[18428]: info: ----- MyVolumio plugins startup ---- Nov 02 13:40:03 volumio volumio[18428]: info: ------------------------------------------- Nov 02 13:40:03 volumio volumio[18428]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 02 13:40:04 volumio volumio-remote-updater[874]: [2025-11-02 13:40:04] [connect] Successful connection Nov 02 13:40:04 volumio volumio-remote-updater[874]: [2025-11-02 13:40:04] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1762090804 101 Nov 02 13:40:04 volumio volumio[18428]: 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 02 13:40:05 volumio volumio[18428]: info: Cannot mount NAS NAS at system boot, trial number 2 ,retrying in 5 seconds Nov 02 13:40:05 volumio volumio[18428]: info: go-librespot daemon successfully initialized Nov 02 13:40:06 volumio sudo[18694]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 02 13:40:06 volumio sudo[18694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:06 volumio sudo[18696]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 02 13:40:06 volumio sudo[18696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:06 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Nov 02 13:40:06 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Nov 02 13:40:06 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Nov 02 13:40:06 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Nov 02 13:40:06 volumio sudo[18694]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:06 volumio sudo[18696]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:06 volumio volumio[18428]: info: Successfully started MPD Monitor Nov 02 13:40:06 volumio mpd_monitor.sh[18699]: MPD Monitor Service: Starting MPD Monitor Service Nov 02 13:40:06 volumio volumio[18428]: info: Successfully started MPD Monitor Nov 02 13:40:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 119. Nov 02 13:40:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:06 volumio go-librespot[18703]: go-librespot daemon starting... Nov 02 13:40:06 volumio go-librespot[18704]: time="2025-11-02T13:40:06Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:06 volumio go-librespot[18704]: time="2025-11-02T13:40:06Z" level=debug msg="app state loaded" Nov 02 13:40:06 volumio go-librespot[18704]: time="2025-11-02T13:40:06Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:06 volumio go-librespot[18704]: time="2025-11-02T13:40:06Z" 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 02 13:40:06 volumio go-librespot[18704]: time="2025-11-02T13:40:06Z" 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 02 13:40:06 volumio go-librespot[18704]: time="2025-11-02T13:40:06Z" 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 02 13:40:06 volumio go-librespot[18704]: time="2025-11-02T13:40:06Z" level=info msg="zeroconf server listening on port 46055" Nov 02 13:40:06 volumio go-librespot[18704]: time="2025-11-02T13:40:06Z" level=debug msg="obtained new client token: AABCUEIMhrC3iLnSFnpwrZsvFUP5f9FH65wzjLR2tVPAOGjZ63AMskTw5wdvNow45G8xeM1DhI3T4+ziTEXbSp5I9mc+dmC95q3oQT4nt/pdZEZvidt5v9wcs2/cQBGkK0o8wly1Cftaz0YPR3a7drZNj38RIVqZADUTkg+b5HOeAchDs49lldY3HumvEWVquxmY0Z2wj61CAm1ndt+/cCQuB+L92KZswZ9B9eD2UGpf0MH7MklR5BY=" Nov 02 13:40:06 volumio go-librespot[18704]: time="2025-11-02T13:40:06Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:40:06 volumio go-librespot[18704]: time="2025-11-02T13:40:06Z" level=debug msg="completed keyexchange" Nov 02 13:40:06 volumio go-librespot[18704]: time="2025-11-02T13:40:06Z" level=debug msg="completed challenge" Nov 02 13:40:06 volumio go-librespot[18704]: time="2025-11-02T13:40:06Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:40:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:08 volumio volumio[18428]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Nov 02 13:40:08 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:08 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 120. Nov 02 13:40:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:09 volumio go-librespot[18711]: go-librespot daemon starting... Nov 02 13:40:09 volumio go-librespot[18712]: time="2025-11-02T13:40:09Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:09 volumio go-librespot[18712]: time="2025-11-02T13:40:09Z" level=debug msg="app state loaded" Nov 02 13:40:09 volumio go-librespot[18712]: time="2025-11-02T13:40:09Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:09 volumio go-librespot[18712]: time="2025-11-02T13:40:09Z" 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 02 13:40:09 volumio go-librespot[18712]: time="2025-11-02T13:40:09Z" 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 02 13:40:09 volumio go-librespot[18712]: time="2025-11-02T13:40:09Z" 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 02 13:40:09 volumio go-librespot[18712]: time="2025-11-02T13:40:09Z" level=info msg="zeroconf server listening on port 41911" Nov 02 13:40:09 volumio go-librespot[18712]: time="2025-11-02T13:40:09Z" level=debug msg="obtained new client token: AAADHFueTK4sjnSOh+0rlr5l91Lgr3EVUD6tGjDWMcP+C+KnLyjMpJ7EwDsiyMlrDUmGtNZf4+ibRJgT1xcHQFgkJzuMAkZxul2CvXHZZLDPqQPuHMZhU/+opf7/gA5JXkvY4QrRTev4bRL0OJJvq23mYtBEdMExNv3kK+TVFwWSfzlFkHoaee+ALjhG0EWywm7mr6LeaIE5QNsRla7MH8sCeORdFqyJ6BZTeXXu370Tj8SHFlwikoY=" Nov 02 13:40:09 volumio go-librespot[18712]: time="2025-11-02T13:40:09Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:40:10 volumio go-librespot[18712]: time="2025-11-02T13:40:10Z" level=debug msg="completed keyexchange" Nov 02 13:40:10 volumio go-librespot[18712]: time="2025-11-02T13:40:10Z" level=debug msg="completed challenge" Nov 02 13:40:10 volumio go-librespot[18712]: time="2025-11-02T13:40: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 02 13:40:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:10 volumio volumio[18428]: info: Cannot mount NAS NAS at system boot, trial number 3 ,retrying in 5 seconds Nov 02 13:40:10 volumio sudo[18734]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 02 13:40:10 volumio sudo[18734]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:10 volumio sudo[18736]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 02 13:40:10 volumio sudo[18736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:10 volumio sudo[18734]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:10 volumio sudo[18736]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:10 volumio sudo[18740]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 02 13:40:10 volumio sudo[18740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:10 volumio sudo[18740]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:10 volumio volumio[18428]: info: Upmpdcli Daemon Started Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Nov 02 13:40:11 volumio volumio[18428]: info: Adding plugin bluetooth to MyMusic Plugins Nov 02 13:40:11 volumio volumio[18428]: info: Adding plugin multiroom to MyMusic Plugins Nov 02 13:40:11 volumio volumio[18428]: info: Adding plugin metavolumio to MyMusic Plugins Nov 02 13:40:11 volumio volumio[18428]: info: Adding plugin cd_controller to MyMusic Plugins Nov 02 13:40:11 volumio volumio[18428]: info: Adding plugin qobuzconnect to MyMusic Plugins Nov 02 13:40:11 volumio volumio[18428]: info: Adding plugin smart_inputs to MyMusic Plugins Nov 02 13:40:11 volumio volumio[18428]: info: Adding plugin tidalconnect to MyMusic Plugins Nov 02 13:40:11 volumio volumio[18428]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Nov 02 13:40:12 volumio volumio[18428]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 02 13:40:12 volumio volumio[18428]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 02 13:40:12 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:12 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:12 volumio volumio[18428]: info: Starting MyVolumio Remote Streaming Endpoints Nov 02 13:40:12 volumio volumio[18428]: info: MyVolumio login type: Token Nov 02 13:40:12 volumio volumio[18428]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 02 13:40:12 volumio volumio[18428]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 02 13:40:12 volumio volumio[18428]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 02 13:40:12 volumio volumio[18428]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 02 13:40:12 volumio volumio[18428]: info: Streaming services startup Nov 02 13:40:12 volumio volumio[18428]: info: Starting Streaming Daemon Nov 02 13:40:12 volumio sudo[18743]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 02 13:40:12 volumio sudo[18743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:12 volumio volumio[18428]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 02 13:40:12 volumio sudo[18743]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:12 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:12 volumio volumio[18428]: error: Cannot start Volumio Streaming Daemon Nov 02 13:40:12 volumio volumio[18428]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 02 13:40:12 volumio volumio[18428]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 02 13:40:12 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:12 volumio volumio[18428]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Nov 02 13:40:13 volumio volumio[18428]: info: MyVolumio token set successfully Nov 02 13:40:13 volumio volumio[18428]: info: MYVOLUMIO: Adding device Nov 02 13:40:13 volumio volumio[18428]: info: MYVOLUMIO: Evaluating Server Nov 02 13:40:13 volumio volumio[18428]: info: MyVolumio status changed Nov 02 13:40:13 volumio volumio[18428]: info: Streaming services startup Nov 02 13:40:13 volumio volumio[18428]: info: Starting Streaming Daemon Nov 02 13:40:13 volumio volumio[18428]: info: Removing browser output: myVolumio user plan is not superstar Nov 02 13:40:13 volumio volumio[18428]: info: Removing audio output: Nov 02 13:40:13 volumio volumio[18428]: info: Stoppping Tunnel 1 Nov 02 13:40:13 volumio sudo[18769]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Nov 02 13:40:13 volumio sudo[18767]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 02 13:40:13 volumio sudo[18767]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:13 volumio sudo[18769]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 02 13:40:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 121. Nov 02 13:40:13 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 02 13:40:13 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 02 13:40:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:13 volumio sudo[18767]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:13 volumio volumio[18428]: error: Cannot start Volumio Streaming Daemon Nov 02 13:40:13 volumio volumio[18428]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 02 13:40:13 volumio volumio[18428]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 02 13:40:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:13 volumio go-librespot[18772]: go-librespot daemon starting... Nov 02 13:40:13 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 02 13:40:13 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 02 13:40:13 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 02 13:40:13 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 02 13:40:13 volumio sudo[18769]: pam_unix(sudo:session): session closed for user root Nov 02 13:40:13 volumio go-librespot[18773]: time="2025-11-02T13:40:13Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:13 volumio go-librespot[18773]: time="2025-11-02T13:40:13Z" level=debug msg="app state loaded" Nov 02 13:40:13 volumio go-librespot[18773]: time="2025-11-02T13:40:13Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:13 volumio volumio[18428]: info: Remote SSH Stopped Nov 02 13:40:13 volumio go-librespot[18773]: time="2025-11-02T13:40:13Z" 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 02 13:40:13 volumio go-librespot[18773]: time="2025-11-02T13:40:13Z" 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 02 13:40:13 volumio go-librespot[18773]: time="2025-11-02T13:40:13Z" 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 02 13:40:13 volumio go-librespot[18773]: time="2025-11-02T13:40:13Z" level=info msg="zeroconf server listening on port 46599" Nov 02 13:40:13 volumio go-librespot[18773]: time="2025-11-02T13:40:13Z" level=debug msg="obtained new client token: AACCBjyHq56WJmcZ/GKjKc7y0WfsUAWYMre0U59bk0rPyjVxlTruq1b25TVEVOxwcgIUry2+CXNxCeJ91kRWuQnFBSslzs0my4RKMArAQp+csow2VU5NY+DfWWrTMuoZPyJBNa/LJ4qmzT271clf9cEhoT4jKrApyp9tdD45G4m55mE/9Xtr73wO2KiDZiSXLqFURp0+6jDTOs8pooybOUhf++NXR308F7d9Ae2ZzbJNsSPayz4+u7Q=" Nov 02 13:40:13 volumio go-librespot[18773]: time="2025-11-02T13:40:13Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:40:13 volumio volumio[18428]: info: Setting Geolocation for MyVolumio to eu3 Nov 02 13:40:13 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:13 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:13 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:13 volumio go-librespot[18773]: time="2025-11-02T13:40:13Z" level=debug msg="completed keyexchange" Nov 02 13:40:13 volumio go-librespot[18773]: time="2025-11-02T13:40:13Z" level=debug msg="completed challenge" Nov 02 13:40:13 volumio go-librespot[18773]: time="2025-11-02T13:40:13Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:40:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:13 volumio volumio[18428]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 02 13:40:14 volumio volumio[18428]: info: Updating MyVolumio device info Nov 02 13:40:14 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:14 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:14 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:14 volumio volumio[18428]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 02 13:40:15 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:15 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:15 volumio volumio[18428]: info: Cannot mount NAS NAS at system boot, trial number 4 ,retrying in 5 seconds Nov 02 13:40:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 122. Nov 02 13:40:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:16 volumio go-librespot[18781]: go-librespot daemon starting... Nov 02 13:40:16 volumio go-librespot[18782]: time="2025-11-02T13:40:16Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:16 volumio go-librespot[18782]: time="2025-11-02T13:40:16Z" level=debug msg="app state loaded" Nov 02 13:40:16 volumio go-librespot[18782]: time="2025-11-02T13:40:16Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:16 volumio go-librespot[18782]: time="2025-11-02T13:40:16Z" 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 02 13:40:16 volumio go-librespot[18782]: time="2025-11-02T13:40:16Z" 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 02 13:40:16 volumio go-librespot[18782]: time="2025-11-02T13:40:16Z" 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 02 13:40:16 volumio go-librespot[18782]: time="2025-11-02T13:40:16Z" level=info msg="zeroconf server listening on port 45491" Nov 02 13:40:16 volumio go-librespot[18782]: time="2025-11-02T13:40:16Z" level=debug msg="obtained new client token: AABrMsElgeP1eT3dHaz7udGY1P1AodYdaf8eUUtxB0mnJTSplAdFReXVz0ghqNXgQM2kAAR8IpCCMeMKR6PiNWn2LJKCoMfj7YXTuYXMtTJaXL1DG+8LoDoeaefLgrL8KGJro9INPOtYSsaMKqXPCvU4Xhxgel3ososgDWYxEkYc20wFB4RI54yXUbY5z+GFArUEhvak7UIpCHWpDa7OQZFtKhdH744K2nBeMdcuLFTH2V6+7X9sSO8=" Nov 02 13:40:16 volumio go-librespot[18782]: time="2025-11-02T13:40:16Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:40:16 volumio go-librespot[18782]: time="2025-11-02T13:40:16Z" level=debug msg="completed keyexchange" Nov 02 13:40:16 volumio go-librespot[18782]: time="2025-11-02T13:40:16Z" level=debug msg="completed challenge" Nov 02 13:40:17 volumio go-librespot[18782]: time="2025-11-02T13:40: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 02 13:40:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:17 volumio volumio[18428]: info: MYVOLUMIO: Adding device Nov 02 13:40:17 volumio volumio[18428]: info: MYVOLUMIO: Evaluating Server Nov 02 13:40:18 volumio volumio[18428]: info: Setting Geolocation for MyVolumio to eu3 Nov 02 13:40:18 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:18 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:18 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:18 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:18 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:18 volumio volumio[18428]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 02 13:40:19 volumio volumio[18428]: info: Updating MyVolumio device info Nov 02 13:40:19 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:19 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:19 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:19 volumio volumio[18428]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 02 13:40:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 123. Nov 02 13:40:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:20 volumio go-librespot[18804]: go-librespot daemon starting... Nov 02 13:40:20 volumio go-librespot[18805]: time="2025-11-02T13:40:20Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:20 volumio go-librespot[18805]: time="2025-11-02T13:40:20Z" level=debug msg="app state loaded" Nov 02 13:40:20 volumio go-librespot[18805]: time="2025-11-02T13:40:20Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:20 volumio go-librespot[18805]: time="2025-11-02T13:40:20Z" 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 02 13:40:20 volumio go-librespot[18805]: time="2025-11-02T13:40:20Z" 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 02 13:40:20 volumio go-librespot[18805]: time="2025-11-02T13:40:20Z" 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 02 13:40:20 volumio go-librespot[18805]: time="2025-11-02T13:40:20Z" level=info msg="zeroconf server listening on port 38057" Nov 02 13:40:20 volumio go-librespot[18805]: time="2025-11-02T13:40:20Z" level=debug msg="obtained new client token: AABCeZ4enJAPKi18tpN07Yo18cECmom3cAHEWDBdAN5DE3YEJJ1mbCSnTz4mn4gCcOcVEUjMfm6A87mx9ihylqxh7X4Qi+aSxSE61Vah8LpP7sV/I9TaZKP3I82z0xHpk2TICAshYphpPQsLsNr7ujZQNxmLQNNMmPtxegah33U87FpAZqEFNWhF7OhvoH7nQ2xZ9sjS9TPMawX0sVDjoDAxFSNBr9btEkG/sHlkEOsdlrw+s2URWAg=" Nov 02 13:40:20 volumio go-librespot[18805]: time="2025-11-02T13:40:20Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:40:20 volumio go-librespot[18805]: time="2025-11-02T13:40:20Z" level=debug msg="completed keyexchange" Nov 02 13:40:20 volumio go-librespot[18805]: time="2025-11-02T13:40:20Z" level=debug msg="completed challenge" Nov 02 13:40:20 volumio volumio[18428]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Nov 02 13:40:20 volumio go-librespot[18805]: time="2025-11-02T13:40:20Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:40:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:21 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:21 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124. Nov 02 13:40:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:23 volumio go-librespot[18826]: go-librespot daemon starting... Nov 02 13:40:23 volumio go-librespot[18827]: time="2025-11-02T13:40:23Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:23 volumio go-librespot[18827]: time="2025-11-02T13:40:23Z" level=debug msg="app state loaded" Nov 02 13:40:23 volumio go-librespot[18827]: time="2025-11-02T13:40:23Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:23 volumio go-librespot[18827]: time="2025-11-02T13:40:23Z" 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 02 13:40:23 volumio go-librespot[18827]: time="2025-11-02T13:40:23Z" 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 02 13:40:23 volumio go-librespot[18827]: time="2025-11-02T13:40:23Z" 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 02 13:40:23 volumio go-librespot[18827]: time="2025-11-02T13:40:23Z" level=info msg="zeroconf server listening on port 35327" Nov 02 13:40:23 volumio go-librespot[18827]: time="2025-11-02T13:40:23Z" level=debug msg="obtained new client token: AAD1NCLfN0Mp6tBeQUUeuAV/j0WTaqPzJ2vg5Fyf2Tsgq8h8maSHcMob7VVA40yqy7Ey7HpbVx7TcXyY9Zw9RFst5MBdN3dP4u/2P7blGwRljaugpquHnXAXumqtprCDXOlHG3Mz7++57gnfbPuXgfOntCeIGFaFa3cW4AitnGIbRvUYjSycJL6GWBayWkXmgvmy5QFQjYfhwhW2fgGxO7y3VSWeCbxqxcjRlehxtzzfP8sDwqHRY8Q=" Nov 02 13:40:23 volumio go-librespot[18827]: time="2025-11-02T13:40:23Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:40:24 volumio go-librespot[18827]: time="2025-11-02T13:40:24Z" level=debug msg="completed keyexchange" Nov 02 13:40:24 volumio go-librespot[18827]: time="2025-11-02T13:40:24Z" level=debug msg="completed challenge" Nov 02 13:40:24 volumio go-librespot[18827]: time="2025-11-02T13:40: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 02 13:40:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:24 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:24 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:27 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 02 13:40:27 volumio volumio[18428]: 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 02 13:40:27 volumio volumio[18428]: info: CoreCommandRouter::volumioGetState Nov 02 13:40:27 volumio volumio[18428]: info: CorePlayQueue::getTrack 0 Nov 02 13:40:27 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:27 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 125. Nov 02 13:40:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:27 volumio go-librespot[18838]: go-librespot daemon starting... Nov 02 13:40:27 volumio go-librespot[18839]: time="2025-11-02T13:40:27Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:27 volumio go-librespot[18839]: time="2025-11-02T13:40:27Z" level=debug msg="app state loaded" Nov 02 13:40:27 volumio go-librespot[18839]: time="2025-11-02T13:40:27Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:27 volumio go-librespot[18839]: time="2025-11-02T13:40:27Z" 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 02 13:40:27 volumio go-librespot[18839]: time="2025-11-02T13:40:27Z" 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 02 13:40:27 volumio go-librespot[18839]: time="2025-11-02T13:40:27Z" 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 02 13:40:27 volumio go-librespot[18839]: time="2025-11-02T13:40:27Z" level=info msg="zeroconf server listening on port 46597" Nov 02 13:40:27 volumio go-librespot[18839]: time="2025-11-02T13:40:27Z" level=debug msg="obtained new client token: AAB5TufCMNsFzSx/sdMgJ15zanrb3KXgUOZxngp+lSjhyVTSLMnnGAw/WX2A90A1hRrXtf3KcPRHKs8gSWDXs1UVqj2aUW9c3HslOOp2zJnFvhuJEc0+/aAZ5FoewdEHI9LFERd6K+pzGLB/AcUdF2URI+eMD1NpR+n+F+CFIgHB3LunBv3d63hM0jtzf8nXalAWvDmaE/znyxt2UpbtjU8SHVQl4y922xcpcmCgASoyYojWVduhbkM=" Nov 02 13:40:27 volumio go-librespot[18839]: time="2025-11-02T13:40:27Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:40:27 volumio go-librespot[18839]: time="2025-11-02T13:40:27Z" level=debug msg="completed keyexchange" Nov 02 13:40:27 volumio go-librespot[18839]: time="2025-11-02T13:40:27Z" level=debug msg="completed challenge" Nov 02 13:40:27 volumio go-librespot[18839]: time="2025-11-02T13:40:27Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:40:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:30 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:30 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 126. Nov 02 13:40:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:30 volumio go-librespot[18860]: go-librespot daemon starting... Nov 02 13:40:30 volumio go-librespot[18861]: time="2025-11-02T13:40:30Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:30 volumio go-librespot[18861]: time="2025-11-02T13:40:30Z" level=debug msg="app state loaded" Nov 02 13:40:30 volumio go-librespot[18861]: time="2025-11-02T13:40:30Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:30 volumio go-librespot[18861]: time="2025-11-02T13:40:30Z" 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 02 13:40:30 volumio go-librespot[18861]: time="2025-11-02T13:40:30Z" 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 02 13:40:30 volumio go-librespot[18861]: time="2025-11-02T13:40:30Z" 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 02 13:40:30 volumio go-librespot[18861]: time="2025-11-02T13:40:30Z" level=info msg="zeroconf server listening on port 38439" Nov 02 13:40:30 volumio go-librespot[18861]: time="2025-11-02T13:40:30Z" level=debug msg="obtained new client token: AACO5T2ssIvRHS3vMbq6K1A57YBfvzPKd7HaoCd3trpULRFaIJ7PEbiNUj0AplBG4qhuQ1gIIN6Qvnkcf8J1C9McAQONE2kc4tnWB4oWjPVAWvOTD3ftikULaY02LxO7iZZIY3HF68SNKN6V+nkVlcQRYtU7caSArjWgxacxwDUAHJgpkaq3wL5XxD2J69URma/AQt39FO0Sx6fe9gPIvYs2kZ9cM4OrwRJRFc3DX9LfBXCE+t4Mo+U=" Nov 02 13:40:30 volumio go-librespot[18861]: time="2025-11-02T13:40:30Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:40:31 volumio go-librespot[18861]: time="2025-11-02T13:40:31Z" level=debug msg="completed keyexchange" Nov 02 13:40:31 volumio go-librespot[18861]: time="2025-11-02T13:40:31Z" level=debug msg="completed challenge" Nov 02 13:40:31 volumio go-librespot[18861]: time="2025-11-02T13:40: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 02 13:40:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::volumioGetBrowseSources Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 02 13:40:32 volumio volumio[18428]: error: MyVolumio Plugin failed to authenticate in a timely fashion Nov 02 13:40:32 volumio volumio[18428]: info: Completed starting MyVolumio Plugin Nov 02 13:40:32 volumio volumio[18428]: [Metrics] CommandRouter: 32s 79.95ms Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::volumiosetStartupVolume Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::Close All Modals sent Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::Close All Modals sent Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 02 13:40:32 volumio volumio-remote-updater[874]: Test mode disabled Nov 02 13:40:32 volumio volumio-remote-updater[874]: Alpha mode disabled Nov 02 13:40:32 volumio volumio-remote-updater[874]: Alpha legacy test mode disabled Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Nov 02 13:40:32 volumio volumio[18428]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 02 13:40:32 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 02 13:40:33 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 02 13:40:33 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 02 13:40:33 volumio volumio[18428]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 02 13:40:33 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:33 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 127. Nov 02 13:40:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:34 volumio go-librespot[18879]: go-librespot daemon starting... Nov 02 13:40:34 volumio go-librespot[18880]: time="2025-11-02T13:40:34Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:34 volumio go-librespot[18880]: time="2025-11-02T13:40:34Z" level=debug msg="app state loaded" Nov 02 13:40:34 volumio go-librespot[18880]: time="2025-11-02T13:40:34Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:34 volumio go-librespot[18880]: time="2025-11-02T13:40:34Z" 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 02 13:40:34 volumio go-librespot[18880]: time="2025-11-02T13:40:34Z" 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 02 13:40:34 volumio go-librespot[18880]: time="2025-11-02T13:40:34Z" 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 02 13:40:34 volumio go-librespot[18880]: time="2025-11-02T13:40:34Z" level=info msg="zeroconf server listening on port 33921" Nov 02 13:40:34 volumio go-librespot[18880]: time="2025-11-02T13:40:34Z" level=debug msg="obtained new client token: AADawHQhPSxcdsddHr3TX/YvWp0GrPq5wvTlDdo9UWOJmUgYDLOxi4YujVKUqlgnXI9O2JaFKQoi+uIQTS/mNgXLE427Q3pTtpAxLnw/zZu0dOYj0eLDGHDBIRrWFG/+ubKNJlCrLnP6VFKAiu+NQKfFt9j7HqxvV8PGhErtkrGPn3As7nfGD+OJXqlBLVFr77vTtw7BZjf8Rxe6KpEzlPXFPQe4p5auqostIpaAChY3MwGrdSsiDCg=" Nov 02 13:40:34 volumio go-librespot[18880]: time="2025-11-02T13:40:34Z" 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 02 13:40:34 volumio go-librespot[18880]: time="2025-11-02T13:40:34Z" level=debug msg="connected to ap-gew1.spotify.com:443" Nov 02 13:40:34 volumio go-librespot[18880]: time="2025-11-02T13:40:34Z" level=debug msg="completed keyexchange" Nov 02 13:40:34 volumio go-librespot[18880]: time="2025-11-02T13:40:34Z" level=debug msg="completed challenge" Nov 02 13:40:34 volumio go-librespot[18880]: time="2025-11-02T13:40:34Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:40:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:36 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:36 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 128. Nov 02 13:40:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:37 volumio go-librespot[18887]: go-librespot daemon starting... Nov 02 13:40:37 volumio go-librespot[18888]: time="2025-11-02T13:40:37Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:37 volumio go-librespot[18888]: time="2025-11-02T13:40:37Z" level=debug msg="app state loaded" Nov 02 13:40:37 volumio go-librespot[18888]: time="2025-11-02T13:40:37Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:37 volumio go-librespot[18888]: time="2025-11-02T13:40:37Z" 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 02 13:40:37 volumio go-librespot[18888]: time="2025-11-02T13:40:37Z" 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 02 13:40:37 volumio go-librespot[18888]: time="2025-11-02T13:40:37Z" 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 02 13:40:37 volumio go-librespot[18888]: time="2025-11-02T13:40:37Z" level=info msg="zeroconf server listening on port 33299" Nov 02 13:40:37 volumio go-librespot[18888]: time="2025-11-02T13:40:37Z" level=debug msg="obtained new client token: AAAeIgpaf/ko1BxCUiZWOVtWt9NFI5XDkPMzs4CiBHcCaUsZshiJAjWP6sZ+pKI8kAaR6gPB/3qum37NwfH6cKbQdqKpRtNbrO6rG+1mZ0rFySOPFW/KoVSX0LBFDZiFYZq1yYI/YTOGveDz/Fm7iqhsDXKKWL4J2FRYXCXf1RPp2nl2IpxyHzc1K/bYnE2qpVlz7vgNKgd6BIT62TaWOGrOWckQj9fGYzxUgNY0HWRIV7+dRhAyqCY=" Nov 02 13:40:38 volumio go-librespot[18888]: time="2025-11-02T13:40:37Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:40:38 volumio go-librespot[18888]: time="2025-11-02T13:40:38Z" level=debug msg="completed keyexchange" Nov 02 13:40:38 volumio go-librespot[18888]: time="2025-11-02T13:40:38Z" level=debug msg="completed challenge" Nov 02 13:40:38 volumio go-librespot[18888]: time="2025-11-02T13:40: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 02 13:40:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:39 volumio volumio[18428]: info: BOOT COMPLETED Nov 02 13:40:39 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:39 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 129. Nov 02 13:40:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:41 volumio go-librespot[18910]: go-librespot daemon starting... Nov 02 13:40:41 volumio go-librespot[18911]: time="2025-11-02T13:40:41Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:41 volumio go-librespot[18911]: time="2025-11-02T13:40:41Z" level=debug msg="app state loaded" Nov 02 13:40:41 volumio go-librespot[18911]: time="2025-11-02T13:40:41Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:41 volumio go-librespot[18911]: time="2025-11-02T13:40:41Z" 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 02 13:40:41 volumio go-librespot[18911]: time="2025-11-02T13:40:41Z" 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 02 13:40:41 volumio go-librespot[18911]: time="2025-11-02T13:40:41Z" 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 02 13:40:41 volumio go-librespot[18911]: time="2025-11-02T13:40:41Z" level=info msg="zeroconf server listening on port 32795" Nov 02 13:40:41 volumio go-librespot[18911]: time="2025-11-02T13:40:41Z" level=debug msg="obtained new client token: AABgqk+ed+tZQgNpGYWg+w22NitjooE2xukBM7ReT4drVLgVaCDtMVsJBGjAh0txJy/n08yhxDxt989rpVu/RCEH440q1WH7P2Tf9KVyTezewp7EtOxTqXVMVBBxM8WKKEER8sgVcon6VJee4Zajo3fnmU3q6HWpZWt2dCE3GfkJmXEM1+C5LWNWBUm3OuDZE5Pl1RIDizfjS6ntqwEKC/hrOdSuoVTyZUm4knphOcRmN0bk/4nhYEQ=" Nov 02 13:40:41 volumio go-librespot[18911]: time="2025-11-02T13:40:41Z" 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 02 13:40:41 volumio go-librespot[18911]: time="2025-11-02T13:40:41Z" level=debug msg="connected to ap-gew1.spotify.com:443" Nov 02 13:40:41 volumio go-librespot[18911]: time="2025-11-02T13:40:41Z" level=debug msg="completed keyexchange" Nov 02 13:40:41 volumio go-librespot[18911]: time="2025-11-02T13:40:41Z" level=debug msg="completed challenge" Nov 02 13:40:41 volumio go-librespot[18911]: time="2025-11-02T13:40:41Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:40:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:42 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:42 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 130. Nov 02 13:40:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:44 volumio go-librespot[18919]: go-librespot daemon starting... Nov 02 13:40:44 volumio go-librespot[18920]: time="2025-11-02T13:40:44Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:44 volumio go-librespot[18920]: time="2025-11-02T13:40:44Z" level=debug msg="app state loaded" Nov 02 13:40:44 volumio go-librespot[18920]: time="2025-11-02T13:40:44Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:44 volumio go-librespot[18920]: time="2025-11-02T13:40:44Z" 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 02 13:40:44 volumio go-librespot[18920]: time="2025-11-02T13:40:44Z" 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 02 13:40:44 volumio go-librespot[18920]: time="2025-11-02T13:40:44Z" 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 02 13:40:44 volumio go-librespot[18920]: time="2025-11-02T13:40:44Z" level=info msg="zeroconf server listening on port 37485" Nov 02 13:40:44 volumio go-librespot[18920]: time="2025-11-02T13:40:44Z" level=debug msg="obtained new client token: AAAoR/QJQBo9864jUGB5OqI96Fa8twREs789hCtQ1WfSkNJnBKnNhUGN3kKOGXA5hh30QWeleST6myiKdE+5wpesiUC3fM9vPlRD9g2oo0GI9DJyHTFbb6HF7SzulfRAoPpJHPwzSOygHf3y/WYvBkbfKdCH5zridgU7SEUo0LgK2rbyrVnqDvh9E/rHdE8wZNy285JXyhInm0RZVg+mLid7j1yUBhtWwZ+xp49ReGkCAWg5i83O0KE=" Nov 02 13:40:44 volumio go-librespot[18920]: time="2025-11-02T13:40:44Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:40:45 volumio go-librespot[18920]: time="2025-11-02T13:40:45Z" level=debug msg="completed keyexchange" Nov 02 13:40:45 volumio go-librespot[18920]: time="2025-11-02T13:40:45Z" level=debug msg="completed challenge" Nov 02 13:40:45 volumio go-librespot[18920]: time="2025-11-02T13:40: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 02 13:40:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:45 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:45 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 131. Nov 02 13:40:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:48 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:48 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:48 volumio go-librespot[18931]: go-librespot daemon starting... Nov 02 13:40:48 volumio go-librespot[18932]: time="2025-11-02T13:40:48Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:48 volumio go-librespot[18932]: time="2025-11-02T13:40:48Z" level=debug msg="app state loaded" Nov 02 13:40:48 volumio go-librespot[18932]: time="2025-11-02T13:40:48Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:48 volumio go-librespot[18932]: time="2025-11-02T13:40:48Z" 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 02 13:40:48 volumio go-librespot[18932]: time="2025-11-02T13:40:48Z" 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 02 13:40:48 volumio go-librespot[18932]: time="2025-11-02T13:40:48Z" 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 02 13:40:48 volumio go-librespot[18932]: time="2025-11-02T13:40:48Z" level=info msg="zeroconf server listening on port 34965" Nov 02 13:40:48 volumio go-librespot[18932]: time="2025-11-02T13:40:48Z" level=debug msg="obtained new client token: AAA4HD13ETqOV0fXrFaOJ4si9kRL8xW1qLhVdWGtq4BnJscfyN6VVrgNja8Jvp8Pfo0cqEkmu1hl+XK/8EzHRokUkZyJ7QcOGGNSOfzHFXnGC1RZZMvPG2PHvxqBFlZdVXWY5O7u5iOk5YP8TE3qdDhq9icfrvHZ/g77aXk7Z5HrRyyYeMYivCZ7A9Nmb2SJi5IEFaDMA6h7Nkd+bAXZKNQwEH677RBK3OP9XnLIrVwbmxYRHltXwqQ=" Nov 02 13:40:48 volumio go-librespot[18932]: time="2025-11-02T13:40:48Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:40:48 volumio go-librespot[18932]: time="2025-11-02T13:40:48Z" level=debug msg="completed keyexchange" Nov 02 13:40:48 volumio go-librespot[18932]: time="2025-11-02T13:40:48Z" level=debug msg="completed challenge" Nov 02 13:40:48 volumio go-librespot[18932]: time="2025-11-02T13:40:48Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:40:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:51 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:51 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 132. Nov 02 13:40:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:51 volumio go-librespot[18953]: go-librespot daemon starting... Nov 02 13:40:51 volumio go-librespot[18954]: time="2025-11-02T13:40:51Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:51 volumio go-librespot[18954]: time="2025-11-02T13:40:51Z" level=debug msg="app state loaded" Nov 02 13:40:51 volumio go-librespot[18954]: time="2025-11-02T13:40:51Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:51 volumio go-librespot[18954]: time="2025-11-02T13:40:51Z" 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 02 13:40:51 volumio go-librespot[18954]: time="2025-11-02T13:40:51Z" 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 02 13:40:51 volumio go-librespot[18954]: time="2025-11-02T13:40:51Z" 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 02 13:40:51 volumio go-librespot[18954]: time="2025-11-02T13:40:51Z" level=info msg="zeroconf server listening on port 45305" Nov 02 13:40:51 volumio go-librespot[18954]: time="2025-11-02T13:40:51Z" level=debug msg="obtained new client token: AAALWXYSSOoQD1D1huOFQakuWud8TodecTuxb3Hw/mXJNWoXXSPMdAE3fOfSTrBVIMT/wXxY+OBegybSO2XP9xk3tt0Ud53PyOhDPywtBFimwxJyL+H2M8aRw0LzzW3IrGpFwItqtrVhhGFLGc96m6K3aYQn6W11q5mmsxDExlAwqMHYzz3znmqNy2u9Yc9McfvSFnEtcNgfCIx81kC6Cpy+SppqVqFl+A301xWBdzTM2f82B6kp5+Q=" Nov 02 13:40:51 volumio go-librespot[18954]: time="2025-11-02T13:40:51Z" 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 02 13:40:51 volumio go-librespot[18954]: time="2025-11-02T13:40:51Z" level=debug msg="connected to ap-gew1.spotify.com:443" Nov 02 13:40:52 volumio go-librespot[18954]: time="2025-11-02T13:40:52Z" level=debug msg="completed keyexchange" Nov 02 13:40:52 volumio go-librespot[18954]: time="2025-11-02T13:40:52Z" level=debug msg="completed challenge" Nov 02 13:40:52 volumio go-librespot[18954]: time="2025-11-02T13:40: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 02 13:40:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:54 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:54 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 133. Nov 02 13:40:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:55 volumio go-librespot[18961]: go-librespot daemon starting... Nov 02 13:40:55 volumio go-librespot[18962]: time="2025-11-02T13:40:55Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:55 volumio go-librespot[18962]: time="2025-11-02T13:40:55Z" level=debug msg="app state loaded" Nov 02 13:40:55 volumio go-librespot[18962]: time="2025-11-02T13:40:55Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:55 volumio go-librespot[18962]: time="2025-11-02T13:40:55Z" 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 02 13:40:55 volumio go-librespot[18962]: time="2025-11-02T13:40:55Z" 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 02 13:40:55 volumio go-librespot[18962]: time="2025-11-02T13:40:55Z" 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 02 13:40:55 volumio go-librespot[18962]: time="2025-11-02T13:40:55Z" level=info msg="zeroconf server listening on port 40907" Nov 02 13:40:55 volumio go-librespot[18962]: time="2025-11-02T13:40:55Z" level=debug msg="obtained new client token: AACxiM5aaaHgC8APziKEGXpMgzttppnin7UXP8R4sfKj12vByZFNaMp+jzR75iwk6EdtML9mCW2/zrdZ9+Ev5JczADkaCv6Ms3Bu28peo05XaDfZ/AX57x4fMubyH1uBwh9T6Q6k2vWxQv3/TJtvaQ73Sc5rtNK3WhjRuqLrJ3WAHvX4P21md+BkrLCN9aDmO7cfogt2K9FzOAYkgz+EaC+4zlXLtv7LG0Zrv2g93c5+nUcJzTfjDco=" Nov 02 13:40:55 volumio go-librespot[18962]: time="2025-11-02T13:40:55Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:40:55 volumio go-librespot[18962]: time="2025-11-02T13:40:55Z" level=debug msg="completed keyexchange" Nov 02 13:40:55 volumio go-librespot[18962]: time="2025-11-02T13:40:55Z" level=debug msg="completed challenge" Nov 02 13:40:55 volumio go-librespot[18962]: time="2025-11-02T13:40:55Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:40:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:40:57 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:40:57 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:40:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 134. Nov 02 13:40:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:40:58 volumio go-librespot[18969]: go-librespot daemon starting... Nov 02 13:40:58 volumio go-librespot[18970]: time="2025-11-02T13:40:58Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:40:58 volumio go-librespot[18970]: time="2025-11-02T13:40:58Z" level=debug msg="app state loaded" Nov 02 13:40:58 volumio go-librespot[18970]: time="2025-11-02T13:40:58Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:40:58 volumio go-librespot[18970]: time="2025-11-02T13:40:58Z" 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 02 13:40:58 volumio go-librespot[18970]: time="2025-11-02T13:40:58Z" 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 02 13:40:58 volumio go-librespot[18970]: time="2025-11-02T13:40:58Z" 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 02 13:40:58 volumio go-librespot[18970]: time="2025-11-02T13:40:58Z" level=info msg="zeroconf server listening on port 39835" Nov 02 13:40:58 volumio go-librespot[18970]: time="2025-11-02T13:40:58Z" level=debug msg="obtained new client token: AAC0R9Xc31IUu/BkIPHylUELA91W5AurISMUgMkpoI2qoayNLeq3fN/K1owzAR2Xwz7Bd5RM9JQbFRFnc0JKy7tDG2gjVEOFpk9aCn5Dt8V0oNKws9aG2z1CR3kMJD3xCQmJ0jUtRXXmz+JIJIft5HrvkGcxXHUcRJjsxHJVNZc14iRCRFjOUOL7aFJRF9lb9Sib0cwI7+JHonvQ47/NqLHuZ4Ej/9/EUhCzajA/Ly2X/TD72WJxYhU=" Nov 02 13:40:58 volumio go-librespot[18970]: time="2025-11-02T13:40:58Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:40:59 volumio go-librespot[18970]: time="2025-11-02T13:40:59Z" level=debug msg="completed keyexchange" Nov 02 13:40:59 volumio go-librespot[18970]: time="2025-11-02T13:40:59Z" level=debug msg="completed challenge" Nov 02 13:40:59 volumio go-librespot[18970]: time="2025-11-02T13:40:59Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:40:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:40:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:41:00 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:00 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 135. Nov 02 13:41:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:02 volumio go-librespot[18992]: go-librespot daemon starting... Nov 02 13:41:02 volumio go-librespot[18993]: time="2025-11-02T13:41:02Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:41:02 volumio go-librespot[18993]: time="2025-11-02T13:41:02Z" level=debug msg="app state loaded" Nov 02 13:41:02 volumio go-librespot[18993]: time="2025-11-02T13:41:02Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:41:02 volumio go-librespot[18993]: time="2025-11-02T13:41:02Z" 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 02 13:41:02 volumio go-librespot[18993]: time="2025-11-02T13:41:02Z" 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 02 13:41:02 volumio go-librespot[18993]: time="2025-11-02T13:41:02Z" 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 02 13:41:02 volumio go-librespot[18993]: time="2025-11-02T13:41:02Z" level=info msg="zeroconf server listening on port 38657" Nov 02 13:41:02 volumio go-librespot[18993]: time="2025-11-02T13:41:02Z" level=debug msg="obtained new client token: AAAgLwl3St/TdXwYo1LVSvBudU/FuFc8aOUPUhI9lX0NnI8/FAwEB4mtSMVk+J4yfM0k7UYfmNUfNNdgYbiakG5al5dOrDZAb2z9oVt6LPi6KKeKzb2zM2Ef9v2aG5FfcRCsidUevxZMj4zm+2CoS4czZFjrXuqaTvnn1m+2eDh1q7jz96IQShBz31t56SUdgsf2avkKS7WL+iZccYThTHUSk3M+21kEIg190h3BObbREPiMVg5KIlE=" Nov 02 13:41:02 volumio go-librespot[18993]: time="2025-11-02T13:41:02Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:41:02 volumio go-librespot[18993]: time="2025-11-02T13:41:02Z" level=debug msg="completed keyexchange" Nov 02 13:41:02 volumio go-librespot[18993]: time="2025-11-02T13:41:02Z" level=debug msg="completed challenge" Nov 02 13:41:02 volumio go-librespot[18993]: time="2025-11-02T13:41:02Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:41:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:41:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:41:03 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:03 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 136. Nov 02 13:41:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:05 volumio go-librespot[19000]: go-librespot daemon starting... Nov 02 13:41:05 volumio go-librespot[19001]: time="2025-11-02T13:41:05Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:41:05 volumio go-librespot[19001]: time="2025-11-02T13:41:05Z" level=debug msg="app state loaded" Nov 02 13:41:05 volumio go-librespot[19001]: time="2025-11-02T13:41:05Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:41:05 volumio go-librespot[19001]: time="2025-11-02T13:41:05Z" 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 02 13:41:05 volumio go-librespot[19001]: time="2025-11-02T13:41:05Z" 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 02 13:41:05 volumio go-librespot[19001]: time="2025-11-02T13:41:05Z" 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 02 13:41:05 volumio go-librespot[19001]: time="2025-11-02T13:41:05Z" level=info msg="zeroconf server listening on port 34587" Nov 02 13:41:05 volumio go-librespot[19001]: time="2025-11-02T13:41:05Z" level=debug msg="obtained new client token: AAC4eTjesMJbI2OjaMi/QgCXEJFsjaTGKFQs+Ap5YpYSa9Eykq5DE1AMaL/bpbh2kQNARVv+bUDzGehdtdYH2GpjcZV93vBMywrOYcvAUHHlqIUfVr7rHcQ5fzFY/CqoKAKFHYmAMfMzpSNVa2ZEUT4tAKn+Y1lnD62u2ZtKGGdygWUxFXLMzqQQu5b1P4Ynhb06iA7uQJmI7OxC+kNL0iRs90mcGUwm93tboXE0xyQ//sIp1391HJ8=" Nov 02 13:41:05 volumio go-librespot[19001]: time="2025-11-02T13:41:05Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:41:05 volumio go-librespot[19001]: time="2025-11-02T13:41:05Z" level=debug msg="completed keyexchange" Nov 02 13:41:05 volumio go-librespot[19001]: time="2025-11-02T13:41:05Z" level=debug msg="completed challenge" Nov 02 13:41:06 volumio go-librespot[19001]: time="2025-11-02T13:41:06Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:41:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:41:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:41:06 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:06 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 137. Nov 02 13:41:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:09 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:09 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:09 volumio go-librespot[19011]: go-librespot daemon starting... Nov 02 13:41:09 volumio go-librespot[19012]: time="2025-11-02T13:41:09Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:41:09 volumio go-librespot[19012]: time="2025-11-02T13:41:09Z" level=debug msg="app state loaded" Nov 02 13:41:09 volumio go-librespot[19012]: time="2025-11-02T13:41:09Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:41:09 volumio go-librespot[19012]: time="2025-11-02T13:41:09Z" 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 02 13:41:09 volumio go-librespot[19012]: time="2025-11-02T13:41:09Z" 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 02 13:41:09 volumio go-librespot[19012]: time="2025-11-02T13:41:09Z" 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 02 13:41:09 volumio go-librespot[19012]: time="2025-11-02T13:41:09Z" level=info msg="zeroconf server listening on port 44529" Nov 02 13:41:09 volumio go-librespot[19012]: time="2025-11-02T13:41:09Z" level=debug msg="obtained new client token: AAClM10bHkkZeshfparyhHV4mr4ltbF9CdpMPvQfaPcCVmBD/mynTU93qLsfstk5zGtQzexC/WLTTc91QmJ0ni6OkXOh0KY6V3mRP/wH3NMp3cc61DT+BFfx3jzzByWlXO9voU74HZz2qYVUy0V8VOhtRxZYvtJYXDMBA94Ft7gSzdZ0nthHgkwHVSUSywvgxyi8hyBz6XMCn029UsAvfUcK2VQlEz+rMYN7Y/Bo0UizomKnnpjV+uo=" Nov 02 13:41:09 volumio go-librespot[19012]: time="2025-11-02T13:41:09Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:41:09 volumio go-librespot[19012]: time="2025-11-02T13:41:09Z" level=debug msg="completed keyexchange" Nov 02 13:41:09 volumio go-librespot[19012]: time="2025-11-02T13:41:09Z" level=debug msg="completed challenge" Nov 02 13:41:09 volumio go-librespot[19012]: time="2025-11-02T13:41:09Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:41:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:41:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:41:12 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:12 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 138. Nov 02 13:41:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:12 volumio go-librespot[19033]: go-librespot daemon starting... Nov 02 13:41:12 volumio go-librespot[19034]: time="2025-11-02T13:41:12Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:41:12 volumio go-librespot[19034]: time="2025-11-02T13:41:12Z" level=debug msg="app state loaded" Nov 02 13:41:12 volumio go-librespot[19034]: time="2025-11-02T13:41:12Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:41:12 volumio go-librespot[19034]: time="2025-11-02T13:41:12Z" 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 02 13:41:12 volumio go-librespot[19034]: time="2025-11-02T13:41:12Z" 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 02 13:41:12 volumio go-librespot[19034]: time="2025-11-02T13:41:12Z" 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 02 13:41:12 volumio go-librespot[19034]: time="2025-11-02T13:41:12Z" level=info msg="zeroconf server listening on port 39039" Nov 02 13:41:12 volumio go-librespot[19034]: time="2025-11-02T13:41:12Z" level=debug msg="obtained new client token: AABtN+xxGcuzOMbYrAZlfPYpf2yeorbDhLYWUj+qvlRpOXy5zQNJaprrd9wS6Eeuf0e6dHfes5+CxKzFDE+JuS6S4haDjl/iGoYqx0z3sNn1ofneMHndvCuZLAfRmSDwoMB7e+Y1fQIZIbWdKHHY0nSpw1/jbjrp981Wg9+cVb9WLbk9fIfM5gpZ+ttTxBFdYtaeam5sy6uYKR9UEU9uU+AYoIoXuFN7Z7WBvni9nfqFY+nhcdu/xqo=" Nov 02 13:41:12 volumio go-librespot[19034]: time="2025-11-02T13:41:12Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:41:13 volumio go-librespot[19034]: time="2025-11-02T13:41:13Z" level=debug msg="completed keyexchange" Nov 02 13:41:13 volumio go-librespot[19034]: time="2025-11-02T13:41:13Z" level=debug msg="completed challenge" Nov 02 13:41:13 volumio go-librespot[19034]: time="2025-11-02T13:41:13Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:41:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:41:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:41:15 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:15 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 139. Nov 02 13:41:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:16 volumio go-librespot[19041]: go-librespot daemon starting... Nov 02 13:41:16 volumio go-librespot[19042]: time="2025-11-02T13:41:16Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:41:16 volumio go-librespot[19042]: time="2025-11-02T13:41:16Z" level=debug msg="app state loaded" Nov 02 13:41:16 volumio go-librespot[19042]: time="2025-11-02T13:41:16Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:41:16 volumio go-librespot[19042]: time="2025-11-02T13:41:16Z" 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 02 13:41:16 volumio go-librespot[19042]: time="2025-11-02T13:41:16Z" 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 02 13:41:16 volumio go-librespot[19042]: time="2025-11-02T13:41:16Z" 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 02 13:41:16 volumio go-librespot[19042]: time="2025-11-02T13:41:16Z" level=info msg="zeroconf server listening on port 41833" Nov 02 13:41:16 volumio go-librespot[19042]: time="2025-11-02T13:41:16Z" level=debug msg="obtained new client token: AAB1dmB5SRmvBmp3WxEailtG/rgckAexND5eBmh4hk9C5M2MkfrcmWPmKak70luggdVdfMVm6Z6JuN4BOw5rVxDB6b1S+8leH0Rnl5VapLAt6nICl56xEr3zEBLOAKo7VzPi9AJ430Fkm49fvIHjEFQ7AIrYDAJdO0gcur5y5NuKuV6Bt4M5s/hIu3Jt91bpJltvOiz8V50UWvB9PXw46+VU7gI/YmVhLQy67H9SgrdFdtYFjfqumwc=" Nov 02 13:41:16 volumio go-librespot[19042]: time="2025-11-02T13:41:16Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:41:16 volumio go-librespot[19042]: time="2025-11-02T13:41:16Z" level=debug msg="completed keyexchange" Nov 02 13:41:16 volumio go-librespot[19042]: time="2025-11-02T13:41:16Z" level=debug msg="completed challenge" Nov 02 13:41:16 volumio go-librespot[19042]: time="2025-11-02T13:41:16Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:41:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:41:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:41:18 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:18 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 140. Nov 02 13:41:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:19 volumio go-librespot[19050]: go-librespot daemon starting... Nov 02 13:41:19 volumio go-librespot[19051]: time="2025-11-02T13:41:19Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:41:19 volumio go-librespot[19051]: time="2025-11-02T13:41:19Z" level=debug msg="app state loaded" Nov 02 13:41:19 volumio go-librespot[19051]: time="2025-11-02T13:41:19Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:41:19 volumio go-librespot[19051]: time="2025-11-02T13:41:19Z" 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 02 13:41:19 volumio go-librespot[19051]: time="2025-11-02T13:41:19Z" 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 02 13:41:19 volumio go-librespot[19051]: time="2025-11-02T13:41:19Z" 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 02 13:41:19 volumio go-librespot[19051]: time="2025-11-02T13:41:19Z" level=info msg="zeroconf server listening on port 39751" Nov 02 13:41:19 volumio go-librespot[19051]: time="2025-11-02T13:41:19Z" level=debug msg="obtained new client token: AAB0Tw6b2R1Sy8Rt5+56wGN5aypHjbFXG4vBizp3DIFOAiuJ/wIpdb+P42bO48Gis/fZxFUhjc66aOvU5v4ObqBYWtu12puVTK9MISQCppbau1BiRPZwFt28Nckyuzj8X5kDyljdDvxJPp9gryL4sKIx9XtdSFLfwpmyMEzgv7rBYH4pHiERR49XN06XOUpqVl8XG9/3XgdzlVusb5TDuYF74mJ3n8AqWYT53tjQRLjswYiQB2Ops1g=" Nov 02 13:41:19 volumio go-librespot[19051]: time="2025-11-02T13:41:19Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:41:19 volumio go-librespot[19051]: time="2025-11-02T13:41:19Z" level=debug msg="completed keyexchange" Nov 02 13:41:19 volumio go-librespot[19051]: time="2025-11-02T13:41:19Z" level=debug msg="completed challenge" Nov 02 13:41:20 volumio go-librespot[19051]: time="2025-11-02T13:41:20Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:41:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:41:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:41:21 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:21 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 141. Nov 02 13:41:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:23 volumio go-librespot[19074]: go-librespot daemon starting... Nov 02 13:41:23 volumio go-librespot[19075]: time="2025-11-02T13:41:23Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:41:23 volumio go-librespot[19075]: time="2025-11-02T13:41:23Z" level=debug msg="app state loaded" Nov 02 13:41:23 volumio go-librespot[19075]: time="2025-11-02T13:41:23Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:41:23 volumio go-librespot[19075]: time="2025-11-02T13:41:23Z" 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 02 13:41:23 volumio go-librespot[19075]: time="2025-11-02T13:41:23Z" 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 02 13:41:23 volumio go-librespot[19075]: time="2025-11-02T13:41:23Z" 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 02 13:41:23 volumio go-librespot[19075]: time="2025-11-02T13:41:23Z" level=info msg="zeroconf server listening on port 35715" Nov 02 13:41:23 volumio go-librespot[19075]: time="2025-11-02T13:41:23Z" level=debug msg="obtained new client token: AAAsObRawkO7PlY86i0ZBV5vFextGzSmMlKupOPBwqKPW333mfd41T63leTTXUhmyUr4gkgBzOCsgLrZUjxeBKlI11hbpcRCmFFfUwjConHvdf2pvaaohqU9IxaeRxTJZewINu0HMuqlBQFMOh/+2rkoSi/AYuVXFxeJtpF6jXOyZMv6rekDjEMBW2eTsUzd+RmiGpnZt7m0h1IhroAab+RGwIHg09mwJFjxd1kib/Q9dlp0CZBd3dc=" Nov 02 13:41:23 volumio go-librespot[19075]: time="2025-11-02T13:41:23Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:41:23 volumio go-librespot[19075]: time="2025-11-02T13:41:23Z" level=debug msg="completed keyexchange" Nov 02 13:41:23 volumio go-librespot[19075]: time="2025-11-02T13:41:23Z" level=debug msg="completed challenge" Nov 02 13:41:23 volumio go-librespot[19075]: time="2025-11-02T13:41:23Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:41:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:41:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:41:24 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:24 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 142. Nov 02 13:41:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:26 volumio go-librespot[19085]: go-librespot daemon starting... Nov 02 13:41:26 volumio go-librespot[19086]: time="2025-11-02T13:41:26Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:41:26 volumio go-librespot[19086]: time="2025-11-02T13:41:26Z" level=debug msg="app state loaded" Nov 02 13:41:26 volumio go-librespot[19086]: time="2025-11-02T13:41:26Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:41:26 volumio go-librespot[19086]: time="2025-11-02T13:41:26Z" 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 02 13:41:26 volumio go-librespot[19086]: time="2025-11-02T13:41:26Z" 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 02 13:41:26 volumio go-librespot[19086]: time="2025-11-02T13:41:26Z" 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 02 13:41:26 volumio go-librespot[19086]: time="2025-11-02T13:41:26Z" level=info msg="zeroconf server listening on port 38307" Nov 02 13:41:26 volumio go-librespot[19086]: time="2025-11-02T13:41:26Z" level=debug msg="obtained new client token: AACehC6Dq+RoC7PfqgJkT2B+K4pmfnUGAr6RRi14pfwEilmacU687EuFo395Lvl1xqlWI5QLhg5DiG7a0rqMN2SmMJQ2aW7ndCKNfVUn1mEKA5milwdiHHA24KgfMJqw+vorYu+67TPVcHrZc72yy9+f/HUVYxaPKFuEzOO4D1Kk274p8Z5D6dT/ljVlh04wQ0dYzj00r9nTLiw5h8y9haeVtOPOZZQqf6tDVqaS3qiiz1qQPNC4Dt4=" Nov 02 13:41:26 volumio go-librespot[19086]: time="2025-11-02T13:41:26Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:41:27 volumio go-librespot[19086]: time="2025-11-02T13:41:27Z" level=debug msg="completed keyexchange" Nov 02 13:41:27 volumio go-librespot[19086]: time="2025-11-02T13:41:27Z" level=debug msg="completed challenge" Nov 02 13:41:27 volumio go-librespot[19086]: time="2025-11-02T13:41:27Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:41:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:41:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:41:27 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:27 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 143. Nov 02 13:41:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:30 volumio go-librespot[19093]: go-librespot daemon starting... Nov 02 13:41:30 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:30 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:30 volumio go-librespot[19094]: time="2025-11-02T13:41:30Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:41:30 volumio go-librespot[19094]: time="2025-11-02T13:41:30Z" level=debug msg="app state loaded" Nov 02 13:41:30 volumio go-librespot[19094]: time="2025-11-02T13:41:30Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:41:30 volumio go-librespot[19094]: time="2025-11-02T13:41:30Z" 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 02 13:41:30 volumio go-librespot[19094]: time="2025-11-02T13:41:30Z" 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 02 13:41:30 volumio go-librespot[19094]: time="2025-11-02T13:41:30Z" 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 02 13:41:30 volumio go-librespot[19094]: time="2025-11-02T13:41:30Z" level=info msg="zeroconf server listening on port 32973" Nov 02 13:41:30 volumio go-librespot[19094]: time="2025-11-02T13:41:30Z" level=debug msg="obtained new client token: AAAgzrsARYlYOaiceQJ992hK6Wv36pTASWJmxTr1BoFjj9/vXNTkRGoKO0RFTTmEOGPRe/SUyYVNNUrHuu1+3SB1Ik8q7WyhhyacZXnW2QURqj0Cmh1dqOoyv09u4gK48nokdBq8FN+RUK5x7B5FTy8phtDu+LY6WgjtZe8LQu7gUBKVwQRHMkSTjs5iWXCwadtHJ+VTZ3kNTANs+g+VOamJQ4CqqNHNyFB1o/MFch1olxyetWp21A4=" Nov 02 13:41:30 volumio go-librespot[19094]: time="2025-11-02T13:41:30Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:41:30 volumio go-librespot[19094]: time="2025-11-02T13:41:30Z" level=debug msg="completed keyexchange" Nov 02 13:41:30 volumio go-librespot[19094]: time="2025-11-02T13:41:30Z" level=debug msg="completed challenge" Nov 02 13:41:30 volumio go-librespot[19094]: time="2025-11-02T13:41:30Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:41:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:41:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:41:33 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:33 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 144. Nov 02 13:41:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:33 volumio go-librespot[19115]: go-librespot daemon starting... Nov 02 13:41:33 volumio go-librespot[19116]: time="2025-11-02T13:41:33Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:41:33 volumio go-librespot[19116]: time="2025-11-02T13:41:33Z" level=debug msg="app state loaded" Nov 02 13:41:33 volumio go-librespot[19116]: time="2025-11-02T13:41:33Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:41:33 volumio go-librespot[19116]: time="2025-11-02T13:41:33Z" 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 02 13:41:33 volumio go-librespot[19116]: time="2025-11-02T13:41:33Z" 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 02 13:41:33 volumio go-librespot[19116]: time="2025-11-02T13:41:33Z" 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 02 13:41:33 volumio go-librespot[19116]: time="2025-11-02T13:41:33Z" level=info msg="zeroconf server listening on port 41115" Nov 02 13:41:33 volumio go-librespot[19116]: time="2025-11-02T13:41:33Z" level=debug msg="obtained new client token: AAChih05fBYC0ICsFuBDhiFbZgPar7ucHauMp62MQeL8o+p58yU5aqAIEnp4FhAPNH3/pvw4tpNmsZ53ZYHyoSnfojplH/dR5zx6sGlhx1cWome6r/oU1yi2qd6O2jZkOGm7sd7bxkjAOVJ8+2J2CDOQMf3m+CL2hSyl+tBRzt6vwzuMJ+IDHD59ULMaSY2Y/Mgzl3XZm9IKr2OQH634dFgeDvC5raLcMgGe+aMD3za4sSHotRmJ3vg=" Nov 02 13:41:33 volumio go-librespot[19116]: time="2025-11-02T13:41:33Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:41:34 volumio go-librespot[19116]: time="2025-11-02T13:41:34Z" level=debug msg="completed keyexchange" Nov 02 13:41:34 volumio go-librespot[19116]: time="2025-11-02T13:41:34Z" level=debug msg="completed challenge" Nov 02 13:41:34 volumio go-librespot[19116]: time="2025-11-02T13:41:34Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:41:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:41:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:41:36 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:36 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 145. Nov 02 13:41:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:37 volumio go-librespot[19123]: go-librespot daemon starting... Nov 02 13:41:37 volumio go-librespot[19124]: time="2025-11-02T13:41:37Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:41:37 volumio go-librespot[19124]: time="2025-11-02T13:41:37Z" level=debug msg="app state loaded" Nov 02 13:41:37 volumio go-librespot[19124]: time="2025-11-02T13:41:37Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:41:37 volumio go-librespot[19124]: time="2025-11-02T13:41:37Z" 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 02 13:41:37 volumio go-librespot[19124]: time="2025-11-02T13:41:37Z" 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 02 13:41:37 volumio go-librespot[19124]: time="2025-11-02T13:41:37Z" 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 02 13:41:37 volumio go-librespot[19124]: time="2025-11-02T13:41:37Z" level=info msg="zeroconf server listening on port 44559" Nov 02 13:41:37 volumio go-librespot[19124]: time="2025-11-02T13:41:37Z" level=debug msg="obtained new client token: AAAIyBRr58vb612jlDYOk0C6gXu+lCOs5g5ng9C0+bZm6alVWirc3VsoVtVpycz7DYMNi2kxpYmYDtg669FQDPcv3Xl0cDVIp6+jnnCJsTaXiRLlRfFRDlPJmbNpD/1vetXBfcA1B8ocWElvfyHkO6X/X5F50Cm1Yc2+imQxESI0XhxoOESZS80Tatq6UKo/RXnfQPpYXSYL1zU3/o9PgGzod2oll4rRkfbFrmuEEfHxkl97OyT6GmU=" Nov 02 13:41:37 volumio go-librespot[19124]: time="2025-11-02T13:41:37Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:41:37 volumio go-librespot[19124]: time="2025-11-02T13:41:37Z" level=debug msg="completed keyexchange" Nov 02 13:41:37 volumio go-librespot[19124]: time="2025-11-02T13:41:37Z" level=debug msg="completed challenge" Nov 02 13:41:37 volumio go-librespot[19124]: time="2025-11-02T13:41:37Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:41:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:41:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:41:39 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:39 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 146. Nov 02 13:41:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:40 volumio go-librespot[19145]: go-librespot daemon starting... Nov 02 13:41:40 volumio go-librespot[19146]: time="2025-11-02T13:41:40Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:41:40 volumio go-librespot[19146]: time="2025-11-02T13:41:40Z" level=debug msg="app state loaded" Nov 02 13:41:40 volumio go-librespot[19146]: time="2025-11-02T13:41:40Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:41:40 volumio go-librespot[19146]: time="2025-11-02T13:41:40Z" 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 02 13:41:40 volumio go-librespot[19146]: time="2025-11-02T13:41:40Z" 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 02 13:41:40 volumio go-librespot[19146]: time="2025-11-02T13:41:40Z" 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 02 13:41:40 volumio go-librespot[19146]: time="2025-11-02T13:41:40Z" level=info msg="zeroconf server listening on port 43787" Nov 02 13:41:40 volumio go-librespot[19146]: time="2025-11-02T13:41:40Z" level=debug msg="obtained new client token: AABCGLJczDSGKOja5du2JTMs/Ap3Nckju0hJBX4GvxdZMsiDj9Q28XKJYoKy0lmGTdOlA3MZiQiFnJZRaQeCOATEE091EZid8GSBpFkgMC1sry7qort/88O05eEJ+hmX+gjY3K2zyj3YBFRMO+hzHGq9d8d1fEJbU6kIT8e3VphKyUxXUJnxM18cq8E5VUgSsXF3semft1oKfLHKDhtbQmUtvU7W2b78v4NhiB9cma1HJuL+p711LZc=" Nov 02 13:41:40 volumio go-librespot[19146]: time="2025-11-02T13:41:40Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:41:41 volumio go-librespot[19146]: time="2025-11-02T13:41:41Z" level=debug msg="completed keyexchange" Nov 02 13:41:41 volumio go-librespot[19146]: time="2025-11-02T13:41:41Z" level=debug msg="completed challenge" Nov 02 13:41:41 volumio go-librespot[19146]: time="2025-11-02T13:41:41Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:41:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:41:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:41:42 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:42 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 147. Nov 02 13:41:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:44 volumio go-librespot[19155]: go-librespot daemon starting... Nov 02 13:41:44 volumio go-librespot[19156]: time="2025-11-02T13:41:44Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:41:44 volumio go-librespot[19156]: time="2025-11-02T13:41:44Z" level=debug msg="app state loaded" Nov 02 13:41:44 volumio go-librespot[19156]: time="2025-11-02T13:41:44Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:41:44 volumio go-librespot[19156]: time="2025-11-02T13:41:44Z" 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 02 13:41:44 volumio go-librespot[19156]: time="2025-11-02T13:41:44Z" 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 02 13:41:44 volumio go-librespot[19156]: time="2025-11-02T13:41:44Z" 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 02 13:41:44 volumio go-librespot[19156]: time="2025-11-02T13:41:44Z" level=info msg="zeroconf server listening on port 35831" Nov 02 13:41:44 volumio go-librespot[19156]: time="2025-11-02T13:41:44Z" level=debug msg="obtained new client token: AAC/5rnqUyS8Y1OhfRavwBbKP+KDVQJd/eYBQJGiFM8x1uOXDOgistHsLUUIpfBUVPkKyFL9b7yYySJ7WR2Gk7PT5hyrFBOCZdErDZ69TR28CAid/rZ8Kww51cl68b19bEKDYL4bS8I5f8cJKMCNYNfsQ2pyFpASCqN6jE2XoA97sQV/Okk8bRu6hqGrUSOSecvAWAVCi1xs/Mxw/vSbRKFbBkl9a+W6GqUl5wi52NXHYfUWzgTMS5I=" Nov 02 13:41:44 volumio go-librespot[19156]: time="2025-11-02T13:41:44Z" 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 02 13:41:44 volumio go-librespot[19156]: time="2025-11-02T13:41:44Z" level=debug msg="connected to ap-gew1.spotify.com:443" Nov 02 13:41:44 volumio go-librespot[19156]: time="2025-11-02T13:41:44Z" level=debug msg="completed keyexchange" Nov 02 13:41:44 volumio go-librespot[19156]: time="2025-11-02T13:41:44Z" level=debug msg="completed challenge" Nov 02 13:41:44 volumio go-librespot[19156]: time="2025-11-02T13:41:44Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:41:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:41:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:41:45 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:45 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 148. Nov 02 13:41:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:47 volumio go-librespot[19166]: go-librespot daemon starting... Nov 02 13:41:47 volumio go-librespot[19167]: time="2025-11-02T13:41:47Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:41:47 volumio go-librespot[19167]: time="2025-11-02T13:41:47Z" level=debug msg="app state loaded" Nov 02 13:41:47 volumio go-librespot[19167]: time="2025-11-02T13:41:47Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:41:47 volumio go-librespot[19167]: time="2025-11-02T13:41:47Z" 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 02 13:41:47 volumio go-librespot[19167]: time="2025-11-02T13:41:47Z" 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 02 13:41:47 volumio go-librespot[19167]: time="2025-11-02T13:41:47Z" 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 02 13:41:47 volumio go-librespot[19167]: time="2025-11-02T13:41:47Z" level=info msg="zeroconf server listening on port 35681" Nov 02 13:41:47 volumio go-librespot[19167]: time="2025-11-02T13:41:47Z" level=debug msg="obtained new client token: AADrH+1OmGtakGdbgN82QfJqWs+NuxoAVnCtUGRe08xAw4yJ0Si3gZqFmdIk8/uaAxXPxxN24DTRoOLCG2xs+aBzGlE/A/DTub0S4QtiCOCBpYJpWOkUk/Nff4E8WO12fOV33Jl07chmnuWRWjaCd0qMSNFstz3VRBrMhbpASn5zWVaf/IJGGOMw1PqmPodbHP9a2tqBsZDpQCsimWZUB31jP2Md8UprR4RmOIzz8R3x2KWjHLCdgw0=" Nov 02 13:41:47 volumio go-librespot[19167]: time="2025-11-02T13:41:47Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:41:48 volumio go-librespot[19167]: time="2025-11-02T13:41:48Z" level=debug msg="completed keyexchange" Nov 02 13:41:48 volumio go-librespot[19167]: time="2025-11-02T13:41:48Z" level=debug msg="completed challenge" Nov 02 13:41:48 volumio go-librespot[19167]: time="2025-11-02T13:41:48Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:41:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:41:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:41:48 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:48 volumio volumio[18428]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 149. Nov 02 13:41:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 02 13:41:51 volumio go-librespot[19188]: go-librespot daemon starting... Nov 02 13:41:51 volumio go-librespot[19189]: time="2025-11-02T13:41:51Z" level=info msg="running go-librespot 0.4.0" Nov 02 13:41:51 volumio go-librespot[19189]: time="2025-11-02T13:41:51Z" level=debug msg="app state loaded" Nov 02 13:41:51 volumio go-librespot[19189]: time="2025-11-02T13:41:51Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 02 13:41:51 volumio volumio[18428]: info: Initializing connection to go-librespot Websocket Nov 02 13:41:51 volumio go-librespot[19189]: time="2025-11-02T13:41:51Z" level=debug msg="new websocket client" Nov 02 13:41:51 volumio volumio[18428]: info: Connection to go-librespot Websocket established Nov 02 13:41:51 volumio go-librespot[19189]: time="2025-11-02T13:41:51Z" 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 02 13:41:51 volumio go-librespot[19189]: time="2025-11-02T13:41:51Z" 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 02 13:41:51 volumio go-librespot[19189]: time="2025-11-02T13:41:51Z" 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 02 13:41:51 volumio go-librespot[19189]: time="2025-11-02T13:41:51Z" level=info msg="zeroconf server listening on port 39883" Nov 02 13:41:51 volumio go-librespot[19189]: time="2025-11-02T13:41:51Z" level=debug msg="obtained new client token: AAD+qHTNk7ZlAaJO0QcAEAY8vMMd7mXnwVWxMGEgNiX+DRfVb34R4fdj1dagGDPN4tI1oXzfFgW64gcAUJuWs0pQo1B9VxvAi04/vSf0E/NAFTMBJOUiCampdwa+QrE97zaBCx/rPsy9f7iQfE9++tJberjXJHgZlm8uQlTlj/5dmQUIDVYi79rGjkgm4jJkmXTHbJQr+Rofmit+FwVBPOo3FGoDadON7GbsX2L9auyfiTBstAVQDZo=" Nov 02 13:41:51 volumio go-librespot[19189]: time="2025-11-02T13:41:51Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 02 13:41:51 volumio go-librespot[19189]: time="2025-11-02T13:41:51Z" level=debug msg="completed keyexchange" Nov 02 13:41:51 volumio go-librespot[19189]: time="2025-11-02T13:41:51Z" level=debug msg="completed challenge" Nov 02 13:41:51 volumio go-librespot[19189]: time="2025-11-02T13:41:51Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 02 13:41:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 02 13:41:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 02 13:41:51 volumio volumio[18428]: info: Connection to go-librespot Websocket closed Nov 02 13:41:54 volumio volumio[18428]: info: Getting Spotify volume Nov 02 13:41:54 volumio volumio[18428]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 02 13:41:54 volumio volumio[18428]: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 02 13:41:54 volumio volumio[18428]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Nov 02 13:41:54 volumio volumio[18428]: errno: -111, Nov 02 13:41:54 volumio volumio[18428]: code: 'ECONNREFUSED', Nov 02 13:41:54 volumio volumio[18428]: syscall: 'connect', Nov 02 13:41:54 volumio volumio[18428]: address: '127.0.0.1', Nov 02 13:41:54 volumio volumio[18428]: port: 9879, Nov 02 13:41:54 volumio volumio[18428]: response: undefined Nov 02 13:41:54 volumio volumio[18428]: } Nov 02 13:41:54 volumio volumio[18428]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 02 13:41:54 volumio sudo[19211]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-11-02 13:40' Nov 02 13:41:54 volumio sudo[19211]: 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"