Oct 31 18:21:04 volumio go-librespot[10765]: time="2025-10-31T18:21:04Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Oct 31 18:21:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:04 volumio volumio[10078]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Oct 31 18:21:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:04 volumio volumio[10078]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 31 18:21:04 volumio volumio[10078]: Error: socket hang up Oct 31 18:21:04 volumio volumio[10078]: at connResetException (node:internal/errors:720:14) Oct 31 18:21:04 volumio volumio[10078]: at Socket.socketOnEnd (node:_http_client:519:23) Oct 31 18:21:04 volumio volumio[10078]: at Socket.emit (node:events:526:35) Oct 31 18:21:04 volumio volumio[10078]: at endReadableNT (node:internal/streams/readable:1376:12) Oct 31 18:21:04 volumio volumio[10078]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Oct 31 18:21:04 volumio volumio[10078]: code: 'ECONNRESET', Oct 31 18:21:04 volumio volumio[10078]: response: undefined Oct 31 18:21:04 volumio volumio[10078]: } Oct 31 18:21:04 volumio volumio[10078]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 31 18:21:04 volumio sudo[11776]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-10-31 18:20' Oct 31 18:21:04 volumio sudo[11776]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:04 volumio sudo[11776]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:04 volumio volumio-remote-updater[874]: [2025-10-31 18:21:04] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 31 18:21:04 volumio volumio-remote-updater[874]: [2025-10-31 18:21:04] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 31 18:21:04 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:04 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 31 18:21:04 volumio systemd[1]: volumio.service: Consumed 8.849s CPU time. Oct 31 18:21:04 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 31 18:21:04 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Oct 31 18:21:04 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4015. Oct 31 18:21:04 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 31 18:21:04 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Oct 31 18:21:04 volumio systemd[1]: volumio.service: Consumed 8.849s CPU time. Oct 31 18:21:04 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Oct 31 18:21:04 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Oct 31 18:21:05 volumio volumio[11815]: info: ------------------------------------------- Oct 31 18:21:05 volumio volumio[11815]: info: ----- Volumio3 ---- Oct 31 18:21:05 volumio volumio[11815]: info: ------------------------------------------- Oct 31 18:21:05 volumio volumio[11815]: info: ----- System startup ---- Oct 31 18:21:05 volumio volumio[11815]: info: ------------------------------------------- Oct 31 18:21:05 volumio volumio[11815]: info: MYVOLUMIO Environment detected Oct 31 18:21:05 volumio volumio[11815]: info: Plugin folders cleanup Oct 31 18:21:05 volumio volumio[11815]: info: Scanning into folder /volumio/app/plugins/ Oct 31 18:21:05 volumio volumio[11815]: info: Scanning category audio_interface Oct 31 18:21:05 volumio volumio[11815]: info: Scanning category miscellanea Oct 31 18:21:05 volumio volumio[11815]: info: Scanning category music_service Oct 31 18:21:05 volumio volumio[11815]: info: Scanning category plugins.json Oct 31 18:21:05 volumio volumio[11815]: info: Scanning category system_controller Oct 31 18:21:05 volumio volumio[11815]: info: Scanning category user_interface Oct 31 18:21:05 volumio volumio[11815]: info: Scanning into folder /data/plugins/ Oct 31 18:21:05 volumio volumio[11815]: info: Scanning category music_service Oct 31 18:21:05 volumio volumio[11815]: info: Scanning category user_interface Oct 31 18:21:05 volumio volumio[11815]: info: Plugin folders cleanup completed Oct 31 18:21:05 volumio volumio[11815]: info: ------------------------------------------- Oct 31 18:21:05 volumio volumio[11815]: info: ----- Core plugins startup ---- Oct 31 18:21:05 volumio volumio[11815]: info: ------------------------------------------- Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugins from folder /volumio/app/plugins/ Oct 31 18:21:05 volumio volumio[11815]: info: Adding plugin upnp to MyMusic Plugins Oct 31 18:21:05 volumio volumio[11815]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 31 18:21:05 volumio volumio[11815]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugins from folder /data/plugins/ Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "system"... Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "appearance"... Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "network"... Oct 31 18:21:05 volumio volumio[11815]: info: Refreshing Cached IP Addresses Oct 31 18:21:05 volumio sudo[11840]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 31 18:21:05 volumio sudo[11840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:05 volumio sudo[11840]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "services"... Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "alsa_controller"... Oct 31 18:21:05 volumio sudo[11842]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 31 18:21:05 volumio sudo[11842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:05 volumio sudo[11842]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:05 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "wizard"... Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "networkfs"... Oct 31 18:21:05 volumio volumio[11815]: info: Cannot mount NAS NAS at system boot, trial number 1 ,retrying in 5 seconds Oct 31 18:21:05 volumio volumio[11815]: info: Starting Udev Watcher for removable devices Oct 31 18:21:05 volumio volumio[11815]: info: Ignoring mount for partition: boot Oct 31 18:21:05 volumio volumio[11815]: info: Ignoring mount for partition: volumio Oct 31 18:21:05 volumio volumio[11815]: info: Ignoring mount for partition: volumio_data Oct 31 18:21:05 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "volumio_command_line_client"... Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "upnp"... Oct 31 18:21:05 volumio volumio[11815]: info: [1761934865543] Starting Upmpd Daemon Oct 31 18:21:05 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "my_music"... Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "mpd"... Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "upnp_browser"... Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "alarm-clock"... Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "airplay_emulation"... Oct 31 18:21:05 volumio volumio[11815]: info: Starting Shairport Sync Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "last_100"... Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "webradio"... Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "i2s_dacs"... Oct 31 18:21:05 volumio volumio[11815]: info: I2S DAC not set, start Auto-detection Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "volumiodiscovery"... Oct 31 18:21:05 volumio volumio[11815]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 31 18:21:05 volumio node[11815]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 31 18:21:05 volumio volumio[11815]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 31 18:21:05 volumio node[11815]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 31 18:21:05 volumio volumio[11815]: *** WARNING *** For more information see Oct 31 18:21:05 volumio node[11815]: *** WARNING *** For more information see Oct 31 18:21:05 volumio volumio[11815]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 31 18:21:05 volumio node[11815]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 31 18:21:05 volumio volumio[11815]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 31 18:21:05 volumio node[11815]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 31 18:21:05 volumio volumio[11815]: *** WARNING *** For more information see Oct 31 18:21:05 volumio node[11815]: *** WARNING *** For more information see Oct 31 18:21:05 volumio volumio[11815]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 31 18:21:05 volumio volumio[11815]: info: Discovery: Started advertising with name: Volumio Oct 31 18:21:05 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 31 18:21:05 volumio volumio[11815]: info: Loading plugin "spop"... Oct 31 18:21:06 volumio volumio[11815]: info: Loading plugin "ytcr"... Oct 31 18:21:06 volumio volumio[11815]: info: Loading plugin "outputs"... Oct 31 18:21:06 volumio volumio[11815]: info: Loading plugin "albumart"... Oct 31 18:21:06 volumio volumio[11815]: info: Plugin example_plugin is not enabled Oct 31 18:21:06 volumio volumio[11815]: info: Loading plugin "inputs"... Oct 31 18:21:06 volumio volumio[11815]: info: Loading plugin "updater_comm"... Oct 31 18:21:06 volumio volumio[11815]: info: Plugin mpdemulation is not enabled Oct 31 18:21:06 volumio volumio[11815]: info: Loading plugin "rest_api"... Oct 31 18:21:06 volumio volumio[11815]: info: Loading plugin "websocket"... Oct 31 18:21:06 volumio volumio[11815]: info: Starting Socket.io Server version 1.7.4 Oct 31 18:21:06 volumio volumio[11815]: info: Loading plugin "Systeminfo"... Oct 31 18:21:06 volumio volumio[11815]: info: Loading i18n strings for locale en Oct 31 18:21:06 volumio volumio[11815]: Updating browse sources language Oct 31 18:21:06 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 18:21:06 volumio volumio[11873]: Forking 3 albumart workers Oct 31 18:21:06 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 31 18:21:06 volumio volumio[11815]: info: CoreCommandRouter::initPlayerControls Oct 31 18:21:06 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:06 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:06 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:06 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:06 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:06 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:06 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:06 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:06 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 31 18:21:06 volumio volumio[11815]: Express server listening on port 3000 Oct 31 18:21:06 volumio volumio[11815]: [Metrics] WebUI: 1s 948.16ms Oct 31 18:21:07 volumio volumio[11815]: info: CoreStateMachine::resetVolumioState Oct 31 18:21:07 volumio volumio[11815]: info: CoreStateMachine::getcurrentVolume Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::volumioRetrievevolume Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: Cannot read play queue from file Oct 31 18:21:07 volumio volumio[11815]: info: Volumio Network Manager: Network status updated: 1 Oct 31 18:21:07 volumio volumio[11815]: info: VolumeController:: Volume=33 Mute =false Oct 31 18:21:07 volumio volumio[11815]: info: CoreStateMachine::pushState Oct 31 18:21:07 volumio volumio[11815]: info: CorePlayQueue::getTrack 0 Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::volumioPushState Oct 31 18:21:07 volumio volumio[11815]: info: CoreStateMachine::updateTrackBlock Oct 31 18:21:07 volumio volumio[11815]: info: CorePlayQueue::getTrackBlock Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::volumioRetrievevolume Oct 31 18:21:07 volumio volumio[11815]: info: CoreStateMachine::setRepeat null single undefined Oct 31 18:21:07 volumio volumio[11815]: info: CoreStateMachine::pushState Oct 31 18:21:07 volumio volumio[11815]: info: CorePlayQueue::getTrack 0 Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::volumioPushState Oct 31 18:21:07 volumio volumio[11815]: info: CoreStateMachine::setRandom null Oct 31 18:21:07 volumio volumio[11815]: info: CoreStateMachine::pushState Oct 31 18:21:07 volumio volumio[11815]: info: CorePlayQueue::getTrack 0 Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::volumioPushState Oct 31 18:21:07 volumio volumio[11815]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 31 18:21:07 volumio volumio[11815]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b04170 Oct 31 18:21:07 volumio volumio[11815]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 31 18:21:07 volumio volumio[11815]: info: Setting Device type: Raspberry PI Oct 31 18:21:07 volumio volumio[11815]: info: VolumeController:: Volume=33 Mute =false Oct 31 18:21:07 volumio volumio[11815]: info: CoreStateMachine::pushState Oct 31 18:21:07 volumio volumio[11815]: info: CorePlayQueue::getTrack 0 Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::volumioPushState Oct 31 18:21:07 volumio volumio[11815]: info: Completed loading Core Plugins Oct 31 18:21:07 volumio volumio[11815]: info: Preparing to generate the ALSA configuration file Oct 31 18:21:07 volumio volumio[11815]: info: Discovery: adding 70853f74-8210-4683-a3fa-e1217517bd40 Oct 31 18:21:07 volumio volumio[11815]: info: Discovery: Found device Volumio Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::volumioGetState Oct 31 18:21:07 volumio volumio[11815]: info: CorePlayQueue::getTrack 0 Oct 31 18:21:07 volumio volumio[11815]: info: Discovery: this is already registered, 70853f74-8210-4683-a3fa-e1217517bd40 Oct 31 18:21:07 volumio volumio[11815]: info: Discovery: Found device Volumio Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::volumioGetState Oct 31 18:21:07 volumio volumio[11815]: info: CorePlayQueue::getTrack 0 Oct 31 18:21:07 volumio volumio[11815]: info: Asound.conf file unchanged, so no further update is needed Oct 31 18:21:07 volumio volumio[11815]: info: Output device has changed, restarting MPD Oct 31 18:21:07 volumio volumio[11815]: info: Output device has changed, restarting Shairport Sync Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:07 volumio sudo[11929]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 31 18:21:07 volumio sudo[11929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:07 volumio sudo[11929]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:07 volumio sudo[11931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 31 18:21:07 volumio volumio[11815]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 31 18:21:07 volumio volumio[11815]: info: ___________ START PLUGINS ___________ Oct 31 18:21:07 volumio volumio[11815]: info: ControllerMpd::onStart: Initializing MPD Oct 31 18:21:07 volumio volumio[11815]: info: Creating MPD Configuration file Oct 31 18:21:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 204. Oct 31 18:21:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:07 volumio volumio[11885]: Starting albumart workers Oct 31 18:21:07 volumio sudo[11931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:07 volumio go-librespot[11938]: go-librespot daemon starting... Oct 31 18:21:07 volumio sudo[11939]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 31 18:21:07 volumio sudo[11939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:07 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 31 18:21:07 volumio go-librespot[11942]: time="2025-10-31T18:21:07Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:21:07 volumio go-librespot[11942]: time="2025-10-31T18:21:07Z" level=debug msg="app state loaded" Oct 31 18:21:07 volumio go-librespot[11942]: time="2025-10-31T18:21:07Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 31 18:21:07 volumio volumio[11815]: info: [1761934867290] CoreMusicLibrary::Adding element Media Servers Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 18:21:07 volumio sudo[11939]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:07 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 31 18:21:07 volumio volumio[11815]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 31 18:21:07 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 31 18:21:07 volumio systemd[1]: mpd.socket: Deactivated successfully. Oct 31 18:21:07 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 31 18:21:07 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:07 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 31 18:21:07 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 31 18:21:07 volumio sudo[11949]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 31 18:21:07 volumio volumio[11815]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 31 18:21:07 volumio volumio[11815]: info: [1761934867335] CoreMusicLibrary::Adding element Last_100 Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 31 18:21:07 volumio volumio[11815]: info: [1761934867336] CoreMusicLibrary::Adding element Webradio Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 18:21:07 volumio sudo[11949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 31 18:21:07 volumio volumio[11815]: info: Initializing BBC Radios Oct 31 18:21:07 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 31 18:21:07 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 31 18:21:07 volumio systemd[1]: mpd.socket: Deactivated successfully. Oct 31 18:21:07 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 31 18:21:07 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 31 18:21:07 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 31 18:21:07 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 31 18:21:07 volumio sudo[11966]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 31 18:21:07 volumio sudo[11966]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 31 18:21:07 volumio sudo[11966]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:07 volumio volumio[11884]: Starting albumart workers Oct 31 18:21:07 volumio go-librespot[11942]: time="2025-10-31T18:21:07Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 31 18:21:07 volumio go-librespot[11942]: time="2025-10-31T18:21:07Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 31 18:21:07 volumio go-librespot[11942]: time="2025-10-31T18:21:07Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: Creating Spotify config file Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio go-librespot[11942]: time="2025-10-31T18:21:07Z" level=info msg="zeroconf server listening on port 42485" Oct 31 18:21:07 volumio go-librespot[11942]: time="2025-10-31T18:21:07Z" level=debug msg="obtained new client token: AADUpjJk05FqobaBlej8oP9ykNe3GV6A1dI7B3t4LJSOsYondnNVP1BeE5UYAeXtmMCxJmek6LEn8fa5MeX3rCYZumzeU74dfClFrM+EBkT2Pz2GUuh1eeEQpb1DQKD5D3DfprNiZ3PhSAmRRTxHQFRS0bCSonLGd7gOlXUimyzaitsfrjk3N2Ph+8dR2mpU4UuoZn9HFsWtd+SwSiIcRG7UVS3+NMdCynW3mouWoadu0WqN+38F0AU=" Oct 31 18:21:07 volumio volumio[11883]: Starting albumart workers Oct 31 18:21:07 volumio go-librespot[11942]: time="2025-10-31T18:21:07Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:21:07 volumio volumio[11815]: info: Volumio Calling Home Oct 31 18:21:07 volumio go-librespot[11942]: time="2025-10-31T18:21:07Z" level=debug msg="completed keyexchange" Oct 31 18:21:07 volumio go-librespot[11942]: time="2025-10-31T18:21:07Z" level=debug msg="completed challenge" Oct 31 18:21:07 volumio go-librespot[11942]: time="2025-10-31T18:21:07Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:21:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:07 volumio volumio[11815]: info: MPD Permissions set Oct 31 18:21:07 volumio volumio[11815]: info: MPD Permissions set Oct 31 18:21:07 volumio volumio[11815]: info: Spotify config file written Oct 31 18:21:07 volumio sudo[11995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 31 18:21:07 volumio sudo[11995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:07 volumio volumio[11815]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:07 volumio volumio[11815]: info: No need to fix Spotify hosts Oct 31 18:21:07 volumio volumio[11815]: info: Volumio called home Oct 31 18:21:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:07 volumio go-librespot[12002]: go-librespot daemon starting... Oct 31 18:21:07 volumio go-librespot[12010]: time="2025-10-31T18:21:07Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:21:07 volumio go-librespot[12010]: time="2025-10-31T18:21:07Z" level=debug msg="app state loaded" Oct 31 18:21:07 volumio go-librespot[12010]: time="2025-10-31T18:21:07Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:21:07 volumio volumio[11815]: info: Starting Shairport Sync Oct 31 18:21:07 volumio volumio[11815]: info: Starting Shairport Sync Oct 31 18:21:07 volumio sudo[11995]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:07 volumio volumio[11815]: info: Starting Shairport Sync Oct 31 18:21:07 volumio sudo[12025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 31 18:21:07 volumio sudo[12025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:07 volumio sudo[12027]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 31 18:21:07 volumio sudo[12027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:07 volumio sudo[12023]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 31 18:21:07 volumio sudo[12023]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:07 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 31 18:21:07 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Oct 31 18:21:07 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 31 18:21:07 volumio systemd[1]: shairport-sync.service: Consumed 1.919s CPU time. Oct 31 18:21:07 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 31 18:21:07 volumio sudo[12027]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:07 volumio sudo[12025]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:07 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 31 18:21:07 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Oct 31 18:21:07 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 31 18:21:07 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 31 18:21:07 volumio sudo[12023]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:07 volumio go-librespot[12010]: time="2025-10-31T18:21:07Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 31 18:21:07 volumio go-librespot[12010]: time="2025-10-31T18:21:07Z" 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]" Oct 31 18:21:07 volumio go-librespot[12010]: time="2025-10-31T18:21:07Z" 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]" Oct 31 18:21:07 volumio go-librespot[12010]: time="2025-10-31T18:21:07Z" level=info msg="zeroconf server listening on port 34133" Oct 31 18:21:07 volumio volumio[11815]: info: Shairport-Sync Started Oct 31 18:21:07 volumio volumio[11815]: Error adding Membership: Error: addMembership EINVAL Oct 31 18:21:07 volumio volumio[11815]: info: Shairport-Sync Started Oct 31 18:21:07 volumio volumio[11815]: info: Shairport-Sync Started Oct 31 18:21:07 volumio volumio[11815]: info: CoreCommandRouter::volumioGetState Oct 31 18:21:07 volumio volumio[11815]: info: CorePlayQueue::getTrack 0 Oct 31 18:21:07 volumio volumio[11815]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 31 18:21:07 volumio volumio[11815]: SPOTIFY: BQDMu4Qmq_W4sCSVHl6wx7-zNISmv6ri5Q-r8zDav5r0tX8QtTrQFBZanR1CRe5UZm5LGMhLfU_ucMNx2IMN8gpmg09uB39ePrJpJA5EUyzb05RNMr4LsN-4xW3maCZ0U_ZCT6Tik7JMDffCIvXiXPuoFjABTIqqs3wTmMZSwK3ApqBtV6Au25kh23i2J448xoBe2wEAeeTM__xL1HRHkwlsYpwsEG7DqejZvmntiQ7iE203yMwyaf-HCxqiNx0uUmCQrXnL6z6lYhmVV-jR9vol4HsNJ7-g4BMOuj3yKgxUiSvr4P8 Oct 31 18:21:07 volumio volumio[11815]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 31 18:21:07 volumio volumio[11815]: info: New Spotify access token = BQDMu4Qmq_W4sCSVHl6wx7-zNISmv6ri5Q-r8zDav5r0tX8QtTrQFBZanR1CRe5UZm5LGMhLfU_ucMNx2IMN8gpmg09uB39ePrJpJA5EUyzb05RNMr4LsN-4xW3maCZ0U_ZCT6Tik7JMDffCIvXiXPuoFjABTIqqs3wTmMZSwK3ApqBtV6Au25kh23i2J448xoBe2wEAeeTM__xL1HRHkwlsYpwsEG7DqejZvmntiQ7iE203yMwyaf-HCxqiNx0uUmCQrXnL6z6lYhmVV-jR9vol4HsNJ7-g4BMOuj3yKgxUiSvr4P8 Oct 31 18:21:07 volumio volumio[11815]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 31 18:21:07 volumio mpd[11975]: 2025-10-31T18:21:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 31 18:21:07 volumio systemd[1]: Started mpd.service - Music Player Daemon. Oct 31 18:21:07 volumio sudo[11949]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:07 volumio sudo[11931]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:08 volumio go-librespot[12010]: time="2025-10-31T18:21:08Z" level=debug msg="obtained new client token: AABy2EUP+wy2TynG4h1dayztdALD48Kpa7Ywgyp7veT4of3JPlPTpk7ITaMD4WcVdui4Y0XHClg6WaIqJwxf0QWHXRAMU/QbyLeoiYdqpqatFpLeyCxDwolv6v/8zT2T8pTXkKKkWN6Ol44uesQ5ztoqv2ngs6iIGbUbTxA8nUDg9W/R1RJrr9LQF3yx1CzF0IeS/v6mXF+aTr1BvALg4ZLd5trky+yZkNVdxS+tGUzgTR2hOg5ok6g=" Oct 31 18:21:08 volumio volumio[11815]: error: MPD error: The expression evaluated to a falsy value: Oct 31 18:21:08 volumio volumio[11815]: assert.ok(self.idling) Oct 31 18:21:08 volumio volumio[11815]: error: The expression evaluated to a falsy value: Oct 31 18:21:08 volumio volumio[11815]: assert.ok(self.idling) Oct 31 18:21:08 volumio volumio[11815]: error: updateQueue error: null Oct 31 18:21:08 volumio volumio[11815]: info: MPD running with PID11975 Oct 31 18:21:08 volumio volumio[11815]: ,establishing connection Oct 31 18:21:08 volumio volumio[11815]: error: updateQueue error: null Oct 31 18:21:08 volumio go-librespot[12010]: time="2025-10-31T18:21:08Z" 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" Oct 31 18:21:08 volumio go-librespot[12010]: time="2025-10-31T18:21:08Z" level=debug msg="connected to ap-gew1.spotify.com:443" Oct 31 18:21:08 volumio go-librespot[12010]: time="2025-10-31T18:21:08Z" level=debug msg="completed keyexchange" Oct 31 18:21:08 volumio go-librespot[12010]: time="2025-10-31T18:21:08Z" level=debug msg="completed challenge" Oct 31 18:21:08 volumio go-librespot[12010]: time="2025-10-31T18:21:08Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:21:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:08 volumio volumio[11815]: 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"} Oct 31 18:21:08 volumio volumio[11815]: info: Spotify Successfully logged in Oct 31 18:21:08 volumio volumio[11815]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 31 18:21:08 volumio volumio[11815]: info: [1761934868157] CoreMusicLibrary::Adding element Spotify Oct 31 18:21:08 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 18:21:08 volumio volumio[11815]: Cannot find translation for source Spotify Oct 31 18:21:08 volumio volumio[11815]: info: [yt-cast-receiver] DIAL server listening on port 8098 Oct 31 18:21:08 volumio volumio[11815]: info: CoreCommandRouter::volumioRetrievevolume Oct 31 18:21:08 volumio volumio[11815]: info: VolumeController:: Volume=33 Mute =false Oct 31 18:21:08 volumio volumio[11815]: info: CoreCommandRouter::volumioGetState Oct 31 18:21:08 volumio volumio[11815]: info: CorePlayQueue::getTrack 0 Oct 31 18:21:08 volumio volumio[11815]: info: CoreStateMachine::pushState Oct 31 18:21:08 volumio volumio[11815]: info: CorePlayQueue::getTrack 0 Oct 31 18:21:08 volumio volumio[11815]: info: CoreCommandRouter::volumioPushState Oct 31 18:21:08 volumio volumio[11815]: info: Completed starting Core Plugins Oct 31 18:21:08 volumio volumio[11815]: info: ------------------------------------------- Oct 31 18:21:08 volumio volumio[11815]: info: ----- MyVolumio plugins startup ---- Oct 31 18:21:08 volumio volumio[11815]: info: ------------------------------------------- Oct 31 18:21:08 volumio volumio[11815]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 31 18:21:09 volumio volumio-remote-updater[874]: [2025-10-31 18:21:09] [connect] Successful connection Oct 31 18:21:09 volumio volumio-remote-updater[874]: [2025-10-31 18:21:09] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1761934869 101 Oct 31 18:21:09 volumio volumio[11815]: 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 Oct 31 18:21:10 volumio volumio[11815]: info: Cannot mount NAS NAS at system boot, trial number 2 ,retrying in 5 seconds Oct 31 18:21:10 volumio volumio[11815]: info: go-librespot daemon successfully initialized Oct 31 18:21:11 volumio sudo[12060]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Oct 31 18:21:11 volumio sudo[12060]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:11 volumio sudo[12062]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Oct 31 18:21:11 volumio sudo[12062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:11 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Oct 31 18:21:11 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Oct 31 18:21:11 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Oct 31 18:21:11 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Oct 31 18:21:11 volumio sudo[12062]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:11 volumio sudo[12060]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:11 volumio mpd_monitor.sh[12065]: MPD Monitor Service: Starting MPD Monitor Service Oct 31 18:21:11 volumio volumio[11815]: info: Successfully started MPD Monitor Oct 31 18:21:11 volumio volumio[11815]: info: Successfully started MPD Monitor Oct 31 18:21:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 205. Oct 31 18:21:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:11 volumio go-librespot[12070]: go-librespot daemon starting... Oct 31 18:21:11 volumio go-librespot[12071]: time="2025-10-31T18:21:11Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:21:11 volumio go-librespot[12071]: time="2025-10-31T18:21:11Z" level=debug msg="app state loaded" Oct 31 18:21:11 volumio go-librespot[12071]: time="2025-10-31T18:21:11Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:21:11 volumio go-librespot[12071]: time="2025-10-31T18:21:11Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 31 18:21:11 volumio go-librespot[12071]: time="2025-10-31T18:21:11Z" 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]" Oct 31 18:21:11 volumio go-librespot[12071]: time="2025-10-31T18:21:11Z" 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]" Oct 31 18:21:11 volumio go-librespot[12071]: time="2025-10-31T18:21:11Z" level=info msg="zeroconf server listening on port 45257" Oct 31 18:21:11 volumio go-librespot[12071]: time="2025-10-31T18:21:11Z" level=debug msg="obtained new client token: AABMx2cV4+vPalhQ47eveI9FGCTyhZZ9mvnILxQdQ3GlMqy9Jwp+O/xN5MnRYUu+P0qQpXEJcx9LCi5WbdEzjXm8KtZ4DBWi/E+M4Sab7FUNgMHeADU2kohAwB4ix1wwUsj1XCzCpr7+6J/dGp2qtZrchaotG9XdGukutgaHpJhHLX5o9M9MhNtZOSY2SlOYFVGjFMUcPfCISY81kztm4ba+e0N8qMl9KebAVT11Dd/Hk3/CZRyJ8f8=" Oct 31 18:21:11 volumio go-librespot[12071]: time="2025-10-31T18:21:11Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:21:12 volumio go-librespot[12071]: time="2025-10-31T18:21:12Z" level=debug msg="completed keyexchange" Oct 31 18:21:12 volumio go-librespot[12071]: time="2025-10-31T18:21:12Z" level=debug msg="completed challenge" Oct 31 18:21:12 volumio go-librespot[12071]: time="2025-10-31T18:21:12Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:21:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:13 volumio volumio[11815]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 31 18:21:13 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:21:13 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:21:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 206. Oct 31 18:21:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:15 volumio volumio[11815]: info: Cannot mount NAS NAS at system boot, trial number 3 ,retrying in 5 seconds Oct 31 18:21:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:15 volumio go-librespot[12078]: go-librespot daemon starting... Oct 31 18:21:15 volumio go-librespot[12093]: time="2025-10-31T18:21:15Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:21:15 volumio go-librespot[12093]: time="2025-10-31T18:21:15Z" level=debug msg="app state loaded" Oct 31 18:21:15 volumio go-librespot[12093]: time="2025-10-31T18:21:15Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:21:15 volumio sudo[12100]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 31 18:21:15 volumio sudo[12102]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 31 18:21:15 volumio sudo[12102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:15 volumio sudo[12100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:15 volumio sudo[12104]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 31 18:21:15 volumio sudo[12104]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:15 volumio sudo[12100]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:15 volumio sudo[12102]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:15 volumio sudo[12104]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:15 volumio volumio[11815]: info: Upmpdcli Daemon Started Oct 31 18:21:15 volumio go-librespot[12093]: time="2025-10-31T18:21:15Z" 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]" Oct 31 18:21:15 volumio go-librespot[12093]: time="2025-10-31T18:21:15Z" 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]" Oct 31 18:21:15 volumio go-librespot[12093]: time="2025-10-31T18:21:15Z" 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]" Oct 31 18:21:15 volumio go-librespot[12093]: time="2025-10-31T18:21:15Z" level=info msg="zeroconf server listening on port 44603" Oct 31 18:21:15 volumio go-librespot[12093]: time="2025-10-31T18:21:15Z" level=debug msg="obtained new client token: AABTm+JhvgoZnZ1H0tSSsy5QYXJXcJDmb2HddJzyBcTlJLZ1H0Q2gmj4jdMVcpvoNd4iQLXCa8PFiH2yjlIkuhfq2YOMGCK3vQ2XNNdaOGhB92qSc+v+MRYf6BRhOVf/M78pe/Gmp+cH6TF9jIGjtGyEck1YINv8UCrsbaPu0EaeojB8wmhcuNKnB1n2954JsHNSbhoeGQGrf+GUZUU6kG98blqRc6PCZdyaT5DegkrDZW59svWhXMQ=" Oct 31 18:21:15 volumio go-librespot[12093]: time="2025-10-31T18:21:15Z" 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" Oct 31 18:21:15 volumio go-librespot[12093]: time="2025-10-31T18:21:15Z" level=debug msg="connected to ap-gew1.spotify.com:443" Oct 31 18:21:15 volumio go-librespot[12093]: time="2025-10-31T18:21:15Z" level=debug msg="completed keyexchange" Oct 31 18:21:15 volumio go-librespot[12093]: time="2025-10-31T18:21:15Z" level=debug msg="completed challenge" Oct 31 18:21:15 volumio go-librespot[12093]: time="2025-10-31T18:21:15Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:21:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:16 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:21:16 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 31 18:21:16 volumio volumio[11815]: info: Adding plugin bluetooth to MyMusic Plugins Oct 31 18:21:16 volumio volumio[11815]: info: Adding plugin multiroom to MyMusic Plugins Oct 31 18:21:16 volumio volumio[11815]: info: Adding plugin metavolumio to MyMusic Plugins Oct 31 18:21:16 volumio volumio[11815]: info: Adding plugin cd_controller to MyMusic Plugins Oct 31 18:21:16 volumio volumio[11815]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 31 18:21:16 volumio volumio[11815]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 31 18:21:16 volumio volumio[11815]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 31 18:21:16 volumio volumio[11815]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 31 18:21:17 volumio volumio[11815]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 31 18:21:17 volumio volumio[11815]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 31 18:21:17 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:17 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:17 volumio volumio[11815]: info: Starting MyVolumio Remote Streaming Endpoints Oct 31 18:21:17 volumio volumio[11815]: info: MyVolumio login type: Token Oct 31 18:21:17 volumio volumio[11815]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 31 18:21:17 volumio volumio[11815]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 31 18:21:17 volumio volumio[11815]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 31 18:21:17 volumio volumio[11815]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 31 18:21:17 volumio volumio[11815]: info: Streaming services startup Oct 31 18:21:17 volumio volumio[11815]: info: Starting Streaming Daemon Oct 31 18:21:17 volumio sudo[12111]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 31 18:21:17 volumio sudo[12111]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:17 volumio sudo[12111]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:17 volumio volumio[11815]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 31 18:21:17 volumio volumio[11815]: error: Cannot start Volumio Streaming Daemon Oct 31 18:21:17 volumio volumio[11815]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 31 18:21:17 volumio volumio[11815]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 31 18:21:17 volumio volumio[11815]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 31 18:21:18 volumio volumio[11815]: info: MyVolumio token set successfully Oct 31 18:21:18 volumio volumio[11815]: info: MYVOLUMIO: Adding device Oct 31 18:21:18 volumio volumio[11815]: info: MYVOLUMIO: Evaluating Server Oct 31 18:21:18 volumio volumio[11815]: info: MyVolumio status changed Oct 31 18:21:18 volumio volumio[11815]: info: Streaming services startup Oct 31 18:21:18 volumio volumio[11815]: info: Starting Streaming Daemon Oct 31 18:21:18 volumio volumio[11815]: info: Removing browser output: myVolumio user plan is not superstar Oct 31 18:21:18 volumio volumio[11815]: info: Removing audio output: Oct 31 18:21:18 volumio volumio[11815]: info: Stoppping Tunnel 1 Oct 31 18:21:18 volumio sudo[12120]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 31 18:21:18 volumio sudo[12120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:18 volumio sudo[12122]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 31 18:21:18 volumio sudo[12122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 31 18:21:18 volumio sudo[12120]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:18 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. Oct 31 18:21:18 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. Oct 31 18:21:18 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. Oct 31 18:21:18 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. Oct 31 18:21:18 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. Oct 31 18:21:18 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. Oct 31 18:21:18 volumio sudo[12122]: pam_unix(sudo:session): session closed for user root Oct 31 18:21:18 volumio volumio[11815]: info: Remote SSH Stopped Oct 31 18:21:18 volumio volumio[11815]: error: Cannot start Volumio Streaming Daemon Oct 31 18:21:18 volumio volumio[11815]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 31 18:21:18 volumio volumio[11815]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 31 18:21:18 volumio volumio[11815]: info: Setting Geolocation for MyVolumio to eu3 Oct 31 18:21:18 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:18 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:18 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:18 volumio volumio[11815]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 31 18:21:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 207. Oct 31 18:21:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:19 volumio go-librespot[12140]: go-librespot daemon starting... Oct 31 18:21:19 volumio go-librespot[12141]: time="2025-10-31T18:21:19Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:21:19 volumio go-librespot[12141]: time="2025-10-31T18:21:19Z" level=debug msg="app state loaded" Oct 31 18:21:19 volumio go-librespot[12141]: time="2025-10-31T18:21:19Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:21:19 volumio go-librespot[12141]: time="2025-10-31T18:21:19Z" 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]" Oct 31 18:21:19 volumio go-librespot[12141]: time="2025-10-31T18:21:19Z" 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]" Oct 31 18:21:19 volumio go-librespot[12141]: time="2025-10-31T18:21:19Z" 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]" Oct 31 18:21:19 volumio go-librespot[12141]: time="2025-10-31T18:21:19Z" level=info msg="zeroconf server listening on port 45813" Oct 31 18:21:19 volumio go-librespot[12141]: time="2025-10-31T18:21:19Z" level=debug msg="obtained new client token: AACEESz46Z0AZEzq1skuAjQsw8Zzft6q8XMg9RxrtLPuNz6yzg8j2bY86OEnhnaH8fIAM0S4iY1M/rGFQkPSu0S/OPXu5Lqa0QjmvQbrmmyywdfv5QTJRDJSLo8N8qI6yEwF56uu37QtOuYLNhLPYLPnLgLwq0AKeyP8Vpz+Fmp1Q13NmgviPqvuv0B5lpjKj1j9BrTjHLdzsLtCnkHKAx357YiHGA15FybKq/7zrosRJjbFriUH" Oct 31 18:21:19 volumio go-librespot[12141]: time="2025-10-31T18:21:19Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:21:19 volumio go-librespot[12141]: time="2025-10-31T18:21:19Z" level=debug msg="completed keyexchange" Oct 31 18:21:19 volumio go-librespot[12141]: time="2025-10-31T18:21:19Z" level=debug msg="completed challenge" Oct 31 18:21:19 volumio go-librespot[12141]: time="2025-10-31T18:21:19Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:21:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:19 volumio volumio[11815]: info: Updating MyVolumio device info Oct 31 18:21:19 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:19 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:19 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:19 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:21:19 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:21:19 volumio volumio[11815]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 31 18:21:20 volumio volumio[11815]: info: Cannot mount NAS NAS at system boot, trial number 4 ,retrying in 5 seconds Oct 31 18:21:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 208. Oct 31 18:21:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:22 volumio go-librespot[12148]: go-librespot daemon starting... Oct 31 18:21:22 volumio go-librespot[12149]: time="2025-10-31T18:21:22Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:21:22 volumio go-librespot[12149]: time="2025-10-31T18:21:22Z" level=debug msg="app state loaded" Oct 31 18:21:22 volumio go-librespot[12149]: time="2025-10-31T18:21:22Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:21:22 volumio go-librespot[12149]: time="2025-10-31T18:21:22Z" 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]" Oct 31 18:21:22 volumio go-librespot[12149]: time="2025-10-31T18:21:22Z" 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]" Oct 31 18:21:22 volumio go-librespot[12149]: time="2025-10-31T18:21:22Z" 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]" Oct 31 18:21:22 volumio go-librespot[12149]: time="2025-10-31T18:21:22Z" level=info msg="zeroconf server listening on port 34001" Oct 31 18:21:22 volumio go-librespot[12149]: time="2025-10-31T18:21:22Z" level=debug msg="obtained new client token: AAD79VUeuo0gBEF+OPZ1LaL5LObGJfobktOXLbI5bD6FFxTUZCzf07ji48mmah1aJTpGdxR9D0byRBJ+Rye/+ZHkIJ3lX9QsNBlqZvkH5IHY5gQplhbWheZqpTW4i3H5uo7WynmzKbPToJDV7rsx9fHdbM5gmMhvZukDYW+znLnEjvnW6YPe7IvkIszrScIjUh0zNbidpUEda7/WyzHcu2bxvMCOJRskK26C6Y6s4Y0vLf32nSRbdFg=" Oct 31 18:21:22 volumio go-librespot[12149]: time="2025-10-31T18:21:22Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:21:22 volumio go-librespot[12149]: time="2025-10-31T18:21:22Z" level=debug msg="completed keyexchange" Oct 31 18:21:22 volumio go-librespot[12149]: time="2025-10-31T18:21:22Z" level=debug msg="completed challenge" Oct 31 18:21:22 volumio go-librespot[12149]: time="2025-10-31T18:21:22Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:21:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:22 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:21:22 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:21:22 volumio volumio[11815]: info: MYVOLUMIO: Adding device Oct 31 18:21:22 volumio volumio[11815]: info: MYVOLUMIO: Evaluating Server Oct 31 18:21:23 volumio volumio[11815]: info: Setting Geolocation for MyVolumio to eu3 Oct 31 18:21:23 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:23 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:23 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:23 volumio volumio[11815]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 31 18:21:24 volumio volumio[11815]: info: Updating MyVolumio device info Oct 31 18:21:24 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:24 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:24 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:24 volumio volumio[11815]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 31 18:21:25 volumio volumio[11815]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Oct 31 18:21:25 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:21:25 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:21:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 209. Oct 31 18:21:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:26 volumio go-librespot[12185]: go-librespot daemon starting... Oct 31 18:21:26 volumio go-librespot[12186]: time="2025-10-31T18:21:26Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:21:26 volumio go-librespot[12186]: time="2025-10-31T18:21:26Z" level=debug msg="app state loaded" Oct 31 18:21:26 volumio go-librespot[12186]: time="2025-10-31T18:21:26Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:21:26 volumio go-librespot[12186]: time="2025-10-31T18:21: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 31 18:21:26 volumio go-librespot[12186]: time="2025-10-31T18:21:26Z" 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]" Oct 31 18:21:26 volumio go-librespot[12186]: time="2025-10-31T18:21:26Z" 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]" Oct 31 18:21:26 volumio go-librespot[12186]: time="2025-10-31T18:21:26Z" level=info msg="zeroconf server listening on port 40283" Oct 31 18:21:26 volumio go-librespot[12186]: time="2025-10-31T18:21:26Z" level=debug msg="obtained new client token: AABEKiCMigN27EJeMmsUCS5MEIjK3IqxtAWzNsqNoDRn+LxLpRQCnbKO3ssqI/xcrVvLgHJOeU8AP+w975WgYA7M7qGElNorcSdaW4tZ3SouS4wLB/ZnGr1HHyj1FD5qDONJzx5fr2vbD/Y+uieMU/pxfrFCrg+4XYb1RC7pwF42wS1omlr2XQAcyXjN3NPwhhQz8dkKcdrO+ETGG7YAxrmB1kY+GtwzU5XGr35dqLzRTR5TOVXW" Oct 31 18:21:26 volumio go-librespot[12186]: time="2025-10-31T18:21:26Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:21:26 volumio go-librespot[12186]: time="2025-10-31T18:21:26Z" level=debug msg="completed keyexchange" Oct 31 18:21:26 volumio go-librespot[12186]: time="2025-10-31T18:21:26Z" level=debug msg="completed challenge" Oct 31 18:21:26 volumio go-librespot[12186]: time="2025-10-31T18:21:26Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:21:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:28 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:21:28 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:21:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 210. Oct 31 18:21:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:29 volumio go-librespot[12194]: go-librespot daemon starting... Oct 31 18:21:29 volumio go-librespot[12195]: time="2025-10-31T18:21:29Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:21:29 volumio go-librespot[12195]: time="2025-10-31T18:21:29Z" level=debug msg="app state loaded" Oct 31 18:21:29 volumio go-librespot[12195]: time="2025-10-31T18:21:29Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:21:29 volumio go-librespot[12195]: time="2025-10-31T18:21:29Z" 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]" Oct 31 18:21:29 volumio go-librespot[12195]: time="2025-10-31T18:21:29Z" 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]" Oct 31 18:21:29 volumio go-librespot[12195]: time="2025-10-31T18:21:29Z" 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]" Oct 31 18:21:29 volumio go-librespot[12195]: time="2025-10-31T18:21:29Z" level=info msg="zeroconf server listening on port 44919" Oct 31 18:21:29 volumio go-librespot[12195]: time="2025-10-31T18:21:29Z" level=debug msg="obtained new client token: AADOLZa4zgDGuIiajhI3149MbY0jzr9/wzzWTrQ/NpUmyloshNvue8aNq2v6oilrV++UnIgWutNP/RtBoIISVV4P7u+6r1Vr3/vKUToZsl7KcNQlICDuzaHUR8JdV3YKTtHqaEPNeO89fNWzsDP/9DtQ/JxhhYQlPlGCBpKkwKFM+iSdKukghU1xnaQnUzYSnEMhlj3a7m64gOarQtFX+bYhnGh4PXQXD1iaymhvU2/cL3bkNt5j5kc=" Oct 31 18:21:29 volumio go-librespot[12195]: time="2025-10-31T18:21:29Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:21:29 volumio go-librespot[12195]: time="2025-10-31T18:21:29Z" level=debug msg="completed keyexchange" Oct 31 18:21:29 volumio go-librespot[12195]: time="2025-10-31T18:21:29Z" level=debug msg="completed challenge" Oct 31 18:21:29 volumio go-librespot[12195]: time="2025-10-31T18:21:29Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:21:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:31 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:21:31 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:21:32 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 31 18:21:32 volumio volumio[11815]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Oct 31 18:21:32 volumio volumio[11815]: info: CoreCommandRouter::volumioGetState Oct 31 18:21:32 volumio volumio[11815]: info: CorePlayQueue::getTrack 0 Oct 31 18:21:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 211. Oct 31 18:21:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:33 volumio go-librespot[12205]: go-librespot daemon starting... Oct 31 18:21:33 volumio go-librespot[12206]: time="2025-10-31T18:21:33Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:21:33 volumio go-librespot[12206]: time="2025-10-31T18:21:33Z" level=debug msg="app state loaded" Oct 31 18:21:33 volumio go-librespot[12206]: time="2025-10-31T18:21:33Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:21:33 volumio go-librespot[12206]: time="2025-10-31T18:21: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]" Oct 31 18:21:33 volumio go-librespot[12206]: time="2025-10-31T18:21: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]" Oct 31 18:21:33 volumio go-librespot[12206]: time="2025-10-31T18:21: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]" Oct 31 18:21:33 volumio go-librespot[12206]: time="2025-10-31T18:21:33Z" level=info msg="zeroconf server listening on port 38125" Oct 31 18:21:33 volumio go-librespot[12206]: time="2025-10-31T18:21:33Z" level=debug msg="obtained new client token: AACXJSesS5IHcyZ2tj2JhcKeP60d9dWjYeLoHOMdnutM8x9nyQidB+9BEx0PMyse0NMDdxBh+PkYjYQuN5AeEAAvrEDUymjBnzN7wXunqowd+U3EK8NaHHXJUd/jheeUh34/JA6YENLuvI6CDKDH/DnI05i+Ku4ZZRHt8IEoPGkktDFb9Wqi5wupIafIf8jbERmB33mL3GcZxNogvt+6nPG5gYsvtmKjD3v24c2EUGMkKhl2RuKL" Oct 31 18:21:33 volumio go-librespot[12206]: time="2025-10-31T18:21:33Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:21:33 volumio go-librespot[12206]: time="2025-10-31T18:21:33Z" level=debug msg="completed keyexchange" Oct 31 18:21:33 volumio go-librespot[12206]: time="2025-10-31T18:21:33Z" level=debug msg="completed challenge" Oct 31 18:21:33 volumio go-librespot[12206]: time="2025-10-31T18:21:33Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:21:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:34 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:21:34 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:21:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 212. Oct 31 18:21:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:36 volumio go-librespot[12227]: go-librespot daemon starting... Oct 31 18:21:36 volumio go-librespot[12228]: time="2025-10-31T18:21:36Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:21:36 volumio go-librespot[12228]: time="2025-10-31T18:21:36Z" level=debug msg="app state loaded" Oct 31 18:21:36 volumio go-librespot[12228]: time="2025-10-31T18:21:36Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:21:36 volumio go-librespot[12228]: time="2025-10-31T18:21:36Z" 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]" Oct 31 18:21:36 volumio go-librespot[12228]: time="2025-10-31T18:21:36Z" 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]" Oct 31 18:21:36 volumio go-librespot[12228]: time="2025-10-31T18:21:36Z" 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]" Oct 31 18:21:36 volumio go-librespot[12228]: time="2025-10-31T18:21:36Z" level=info msg="zeroconf server listening on port 45795" Oct 31 18:21:36 volumio go-librespot[12228]: time="2025-10-31T18:21:36Z" level=debug msg="obtained new client token: AAA0EvPAbP6qGE9x7JylMNiD3D8j1vfg8J7T7izOQlaADflzbaqiktnFC0DFU7HPq66S4HQvhlIy3MB1Xw2aV1p4m+RHo9xI//gXf0/rUZcheIUQufIuG3EXevS8O00y1Bm3Q1ijc669kjugiuhMf1LjPtkcH0p1VTn18Ewkdr4hoOdAdXeOV3wyJGoTHXClAWI7WE4pwqUZ4+aUuw2ARKdijHJUrb6E0VgCLG5XR0eaLLPmXhf2BWs=" Oct 31 18:21:36 volumio go-librespot[12228]: time="2025-10-31T18:21:36Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:21:36 volumio go-librespot[12228]: time="2025-10-31T18:21:36Z" level=debug msg="completed keyexchange" Oct 31 18:21:36 volumio go-librespot[12228]: time="2025-10-31T18:21:36Z" level=debug msg="completed challenge" Oct 31 18:21:36 volumio go-librespot[12228]: time="2025-10-31T18:21:36Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:21:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::volumioGetBrowseSources Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 31 18:21:37 volumio volumio[11815]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 31 18:21:37 volumio volumio[11815]: info: Completed starting MyVolumio Plugin Oct 31 18:21:37 volumio volumio[11815]: [Metrics] CommandRouter: 32s 206.11ms Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::volumiosetStartupVolume Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::Close All Modals sent Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::Close All Modals sent Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 31 18:21:37 volumio volumio-remote-updater[874]: Test mode disabled Oct 31 18:21:37 volumio volumio-remote-updater[874]: Alpha mode disabled Oct 31 18:21:37 volumio volumio-remote-updater[874]: Alpha legacy test mode disabled Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 31 18:21:37 volumio volumio[11815]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 31 18:21:37 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 31 18:21:37 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:21:37 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:21:38 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 31 18:21:38 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 31 18:21:38 volumio volumio[11815]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 31 18:21:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 213. Oct 31 18:21:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:40 volumio go-librespot[12245]: go-librespot daemon starting... Oct 31 18:21:40 volumio go-librespot[12246]: time="2025-10-31T18:21:40Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:21:40 volumio go-librespot[12246]: time="2025-10-31T18:21:40Z" level=debug msg="app state loaded" Oct 31 18:21:40 volumio go-librespot[12246]: time="2025-10-31T18:21:40Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:21:40 volumio go-librespot[12246]: time="2025-10-31T18:21:40Z" 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]" Oct 31 18:21:40 volumio go-librespot[12246]: time="2025-10-31T18:21:40Z" 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]" Oct 31 18:21:40 volumio go-librespot[12246]: time="2025-10-31T18:21:40Z" 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]" Oct 31 18:21:40 volumio go-librespot[12246]: time="2025-10-31T18:21:40Z" level=info msg="zeroconf server listening on port 36959" Oct 31 18:21:40 volumio go-librespot[12246]: time="2025-10-31T18:21:40Z" level=debug msg="obtained new client token: AACr2s73/b/wc86fBmWG5aQ5a8Qahydd4wbIVjk8QkQVk1a+h/6sd5FmosvWixzK9cRmqwZsshQ6vLuo/iTB7VCEVZzza8udou9V1cnXu8MOBahO7wxBWEs2XgekZ6tYISEVV9ZHQYY/KVI7EK33AtKPVoTut0pUphzoAdZYlxTsjLseVyO8ardMekq3/XeQgryKxJ/xuFok5Qobw4fJ8m76ctDoIYyiojWjnVHeZFO3oJKJaizB" Oct 31 18:21:40 volumio go-librespot[12246]: time="2025-10-31T18:21:40Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:21:40 volumio go-librespot[12246]: time="2025-10-31T18:21:40Z" level=debug msg="completed keyexchange" Oct 31 18:21:40 volumio go-librespot[12246]: time="2025-10-31T18:21:40Z" level=debug msg="completed challenge" Oct 31 18:21:40 volumio go-librespot[12246]: time="2025-10-31T18:21:40Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:21:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:40 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:21:40 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:21:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 214. Oct 31 18:21:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:43 volumio go-librespot[12254]: go-librespot daemon starting... Oct 31 18:21:43 volumio go-librespot[12255]: time="2025-10-31T18:21:43Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:21:43 volumio go-librespot[12255]: time="2025-10-31T18:21:43Z" level=debug msg="app state loaded" Oct 31 18:21:43 volumio go-librespot[12255]: time="2025-10-31T18:21:43Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:21:43 volumio go-librespot[12255]: time="2025-10-31T18:21:43Z" 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]" Oct 31 18:21:43 volumio go-librespot[12255]: time="2025-10-31T18:21:43Z" 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]" Oct 31 18:21:43 volumio go-librespot[12255]: time="2025-10-31T18:21:43Z" 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]" Oct 31 18:21:43 volumio go-librespot[12255]: time="2025-10-31T18:21:43Z" level=info msg="zeroconf server listening on port 35337" Oct 31 18:21:43 volumio go-librespot[12255]: time="2025-10-31T18:21:43Z" level=debug msg="obtained new client token: AABhBLGeP7uFq6cATzmMK/Nf3LuHIB/jax5Rm7LuZMJ5FGc8M5a66tBPh1TqyG0O4Oks6KQD0TwiGjUybMpXVYKRd4X1Xx5FAbv8bRv2zFW7c/NJ0fhxdeNi2nAuP7/sFGIPXXbmZLUAptdOvhhNupw2HsjsM2KnFTDzCsFOIHahywnWPDz3EY9/86NONwiYfXd0NjLQ0bXBQX7TlKNOMK+wi33nHZcYYsLmpvIQ7eyZWREorsboOkg=" Oct 31 18:21:43 volumio go-librespot[12255]: time="2025-10-31T18:21:43Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:21:43 volumio go-librespot[12255]: time="2025-10-31T18:21:43Z" level=debug msg="completed keyexchange" Oct 31 18:21:43 volumio go-librespot[12255]: time="2025-10-31T18:21:43Z" level=debug msg="completed challenge" Oct 31 18:21:43 volumio go-librespot[12255]: time="2025-10-31T18:21:43Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:21:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:43 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:21:43 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:21:44 volumio volumio[11815]: info: BOOT COMPLETED Oct 31 18:21:46 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:21:46 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:21:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 215. Oct 31 18:21:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:47 volumio go-librespot[12277]: go-librespot daemon starting... Oct 31 18:21:47 volumio go-librespot[12278]: time="2025-10-31T18:21:47Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:21:47 volumio go-librespot[12278]: time="2025-10-31T18:21:47Z" level=debug msg="app state loaded" Oct 31 18:21:47 volumio go-librespot[12278]: time="2025-10-31T18:21:47Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:21:47 volumio go-librespot[12278]: time="2025-10-31T18:21: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]" Oct 31 18:21:47 volumio go-librespot[12278]: time="2025-10-31T18:21: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]" Oct 31 18:21:47 volumio go-librespot[12278]: time="2025-10-31T18:21: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]" Oct 31 18:21:47 volumio go-librespot[12278]: time="2025-10-31T18:21:47Z" level=info msg="zeroconf server listening on port 45387" Oct 31 18:21:47 volumio go-librespot[12278]: time="2025-10-31T18:21:47Z" level=debug msg="obtained new client token: AADE0YGMGwJHAc8KKva5DdKhPQQcYbmRt8zTefEUIE8XyF3dHHk7tByGG0G3wKMTEiL9dRacD3WQoU6/f5um2K/J9RRigfgBJY99CVYU2slftzORRyyY9eQ9BBE0+7OZnA4F5eVlAs2rO1UxoLhfEKov2aYJtzy3imXjvsmw7U5RwmIrxmbwhWvLvxojHSGFzJuVUCKMzBRwY0A+7/At+bHGKOQOagxJveBsU39uj7+nOnSmHTCj" Oct 31 18:21:47 volumio go-librespot[12278]: time="2025-10-31T18:21:47Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:21:47 volumio go-librespot[12278]: time="2025-10-31T18:21:47Z" level=debug msg="completed keyexchange" Oct 31 18:21:47 volumio go-librespot[12278]: time="2025-10-31T18:21:47Z" level=debug msg="completed challenge" Oct 31 18:21:47 volumio go-librespot[12278]: time="2025-10-31T18:21:47Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:21:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:49 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:21:49 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:21:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 216. Oct 31 18:21:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:50 volumio go-librespot[12286]: go-librespot daemon starting... Oct 31 18:21:50 volumio go-librespot[12287]: time="2025-10-31T18:21:50Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:21:50 volumio go-librespot[12287]: time="2025-10-31T18:21:50Z" level=debug msg="app state loaded" Oct 31 18:21:50 volumio go-librespot[12287]: time="2025-10-31T18:21:50Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:21:50 volumio go-librespot[12287]: time="2025-10-31T18:21:50Z" 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]" Oct 31 18:21:50 volumio go-librespot[12287]: time="2025-10-31T18:21:50Z" 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]" Oct 31 18:21:50 volumio go-librespot[12287]: time="2025-10-31T18:21:50Z" 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]" Oct 31 18:21:50 volumio go-librespot[12287]: time="2025-10-31T18:21:50Z" level=info msg="zeroconf server listening on port 39591" Oct 31 18:21:50 volumio go-librespot[12287]: time="2025-10-31T18:21:50Z" level=debug msg="obtained new client token: AAD1SneaqTzYc0GBQ3z68OxtJ45m1xwp3mkMdy54NX/PldnPBu6NdQEV3ckE5zLI9roMQ/5Pgp86elC7BL/lfBaeiu+k1LkW8KuDWP6cO2/lHCW4W6GYUnSUy53EUlIgDkAY2tbSN/lBPHPNpWI/dsmCrFKW1hiVtKLlsbl5LqR8hoZ/Q80wtBaVIc/29RlNNTij8J1/7IgEgs0jWyEVe9qbo7W4BQtxYr4NUYxsmCqgrUebUvFP62g=" Oct 31 18:21:50 volumio go-librespot[12287]: time="2025-10-31T18:21:50Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:21:50 volumio go-librespot[12287]: time="2025-10-31T18:21:50Z" level=debug msg="completed keyexchange" Oct 31 18:21:50 volumio go-librespot[12287]: time="2025-10-31T18:21:50Z" level=debug msg="completed challenge" Oct 31 18:21:50 volumio go-librespot[12287]: time="2025-10-31T18:21:50Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:21:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:52 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:21:52 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:21:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 217. Oct 31 18:21:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:54 volumio go-librespot[12297]: go-librespot daemon starting... Oct 31 18:21:54 volumio go-librespot[12298]: time="2025-10-31T18:21:54Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:21:54 volumio go-librespot[12298]: time="2025-10-31T18:21:54Z" level=debug msg="app state loaded" Oct 31 18:21:54 volumio go-librespot[12298]: time="2025-10-31T18:21:54Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:21:54 volumio go-librespot[12298]: time="2025-10-31T18:21:54Z" 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]" Oct 31 18:21:54 volumio go-librespot[12298]: time="2025-10-31T18:21:54Z" 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]" Oct 31 18:21:54 volumio go-librespot[12298]: time="2025-10-31T18:21:54Z" 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]" Oct 31 18:21:54 volumio go-librespot[12298]: time="2025-10-31T18:21:54Z" level=info msg="zeroconf server listening on port 40757" Oct 31 18:21:54 volumio go-librespot[12298]: time="2025-10-31T18:21:54Z" level=debug msg="obtained new client token: AAB6rALLUcoMllmOVZzuN/4hFHerijyeGNvuMgLxBVDfiibxZTJjl77gRJpHIUnXkBLfEEO6viuWGDlorQGNVNhxCQVQcRnmvcCcuR/YkK3NeiQLbmwdnw8J4mSru+co58dNzwt2R4nLmUlKUbns1OGHwH5kuR/9u8WdVyy+6q/MWLcRYvxtszLrw8t0/nDhkqadQXbAkMTcxkZErvP9srOQXc9fSvPNOzoUx0sE5SSa3vNeSpib" Oct 31 18:21:54 volumio go-librespot[12298]: time="2025-10-31T18:21:54Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:21:54 volumio go-librespot[12298]: time="2025-10-31T18:21:54Z" level=debug msg="completed keyexchange" Oct 31 18:21:54 volumio go-librespot[12298]: time="2025-10-31T18:21:54Z" level=debug msg="completed challenge" Oct 31 18:21:54 volumio go-librespot[12298]: time="2025-10-31T18:21:54Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:21:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:55 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:21:55 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:21:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 218. Oct 31 18:21:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:21:57 volumio go-librespot[12319]: go-librespot daemon starting... Oct 31 18:21:57 volumio go-librespot[12320]: time="2025-10-31T18:21:57Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:21:57 volumio go-librespot[12320]: time="2025-10-31T18:21:57Z" level=debug msg="app state loaded" Oct 31 18:21:57 volumio go-librespot[12320]: time="2025-10-31T18:21:57Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:21:57 volumio go-librespot[12320]: time="2025-10-31T18:21:57Z" 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]" Oct 31 18:21:57 volumio go-librespot[12320]: time="2025-10-31T18:21:57Z" 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]" Oct 31 18:21:57 volumio go-librespot[12320]: time="2025-10-31T18:21:57Z" 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]" Oct 31 18:21:57 volumio go-librespot[12320]: time="2025-10-31T18:21:57Z" level=info msg="zeroconf server listening on port 40487" Oct 31 18:21:57 volumio go-librespot[12320]: time="2025-10-31T18:21:57Z" level=debug msg="obtained new client token: AABLqOxWFd2UQhHkHURmrFDtgFQL3oS/XmGd4/T4DReyNc2lyDw2JF9y+erxn1QHX4rGs4JyYLqHOTcJVbKUPYNLWsakhF+zjG3M2i+2S5dsD+0JsggobtHNBwoKU/wRnPFgg1bQhfFL3YbY9+ONJZ6RXHxMQTDVsCbTmL9BfpcNVM1UqH+4a9KV7KBM74uHShv3IwWE/Grs94NcTpdFNUZHAMu9YAvSXcNyLKEHBdPqkw55mRjxXSQ=" Oct 31 18:21:57 volumio go-librespot[12320]: time="2025-10-31T18:21:57Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:21:57 volumio go-librespot[12320]: time="2025-10-31T18:21:57Z" level=debug msg="completed keyexchange" Oct 31 18:21:57 volumio go-librespot[12320]: time="2025-10-31T18:21:57Z" level=debug msg="completed challenge" Oct 31 18:21:57 volumio go-librespot[12320]: time="2025-10-31T18:21:57Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:21:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:21:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:21:58 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:21:58 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 219. Oct 31 18:22:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:01 volumio go-librespot[12327]: go-librespot daemon starting... Oct 31 18:22:01 volumio go-librespot[12328]: time="2025-10-31T18:22:01Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:22:01 volumio go-librespot[12328]: time="2025-10-31T18:22:01Z" level=debug msg="app state loaded" Oct 31 18:22:01 volumio go-librespot[12328]: time="2025-10-31T18:22:01Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:22:01 volumio go-librespot[12328]: time="2025-10-31T18:22:01Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 31 18:22:01 volumio go-librespot[12328]: time="2025-10-31T18:22:01Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 31 18:22:01 volumio go-librespot[12328]: time="2025-10-31T18:22:01Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 31 18:22:01 volumio go-librespot[12328]: time="2025-10-31T18:22:01Z" level=info msg="zeroconf server listening on port 34565" Oct 31 18:22:01 volumio go-librespot[12328]: time="2025-10-31T18:22:01Z" level=debug msg="obtained new client token: AACG5ICgyrJr6N47MqZ9A1gt0dcJzx19OJ+6XIgAND7zZmEDoEIh2D7TN4J7RXjxrItudtXJbiJWBA5ptWn0+Rz0BiIVl+6MLgp/4+o7+8wSQ5r9YNBkwlug9XrI2ffH4lrSH8G7M8DA/JKHcWqIRZZtTdiINsNDyeojkXQKsPOwfcKYmy/jIc6UTtPFvwPnFSut8+uwv+D628iE22kyf8PH+PYs0TPjOvSzTv8x4rmmwpdC/3lP" Oct 31 18:22:01 volumio go-librespot[12328]: time="2025-10-31T18:22:01Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:22:01 volumio go-librespot[12328]: time="2025-10-31T18:22:01Z" level=debug msg="completed keyexchange" Oct 31 18:22:01 volumio go-librespot[12328]: time="2025-10-31T18:22:01Z" level=debug msg="completed challenge" Oct 31 18:22:01 volumio go-librespot[12328]: time="2025-10-31T18:22:01Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:22:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:22:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:22:01 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:22:01 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 220. Oct 31 18:22:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:04 volumio go-librespot[12336]: go-librespot daemon starting... Oct 31 18:22:04 volumio go-librespot[12337]: time="2025-10-31T18:22:04Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:22:04 volumio go-librespot[12337]: time="2025-10-31T18:22:04Z" level=debug msg="app state loaded" Oct 31 18:22:04 volumio go-librespot[12337]: time="2025-10-31T18:22:04Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:22:04 volumio go-librespot[12337]: time="2025-10-31T18:22:04Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 31 18:22:04 volumio go-librespot[12337]: time="2025-10-31T18:22:04Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 31 18:22:04 volumio go-librespot[12337]: time="2025-10-31T18:22:04Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 31 18:22:04 volumio go-librespot[12337]: time="2025-10-31T18:22:04Z" level=info msg="zeroconf server listening on port 40871" Oct 31 18:22:04 volumio go-librespot[12337]: time="2025-10-31T18:22:04Z" level=debug msg="obtained new client token: AADNGnBsPjpacXoptSXj6Zz7DhKMvmTrSdKJRenJ/IW99CZLYrEiO+PI0p/nD4lRwgAAmtDb2/AHowt5h+slAJnjj4VLbXPp3iMGwAD0Jj53wi8AWeRn0HZXR/HTc7oQNukK94e94BTaWYaM5IvZ8XqIHWhRv7UToTh1Ux9N+e/8ezak5mJQXHMTkYaw9kZhD1rPXFgh4V13jblPr3IRCvKOdjCsxEFgahJr+BI4/qbNKK6HZsNhV/0=" Oct 31 18:22:04 volumio go-librespot[12337]: time="2025-10-31T18:22:04Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:22:04 volumio go-librespot[12337]: time="2025-10-31T18:22:04Z" level=debug msg="completed keyexchange" Oct 31 18:22:04 volumio go-librespot[12337]: time="2025-10-31T18:22:04Z" level=debug msg="completed challenge" Oct 31 18:22:04 volumio go-librespot[12337]: time="2025-10-31T18:22:04Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:22:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:22:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:22:04 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:22:04 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:07 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:22:07 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 221. Oct 31 18:22:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:08 volumio go-librespot[12359]: go-librespot daemon starting... Oct 31 18:22:08 volumio go-librespot[12360]: time="2025-10-31T18:22:08Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:22:08 volumio go-librespot[12360]: time="2025-10-31T18:22:08Z" level=debug msg="app state loaded" Oct 31 18:22:08 volumio go-librespot[12360]: time="2025-10-31T18:22:08Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:22:08 volumio go-librespot[12360]: time="2025-10-31T18:22:08Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 31 18:22:08 volumio go-librespot[12360]: time="2025-10-31T18:22:08Z" 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]" Oct 31 18:22:08 volumio go-librespot[12360]: time="2025-10-31T18:22:08Z" 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]" Oct 31 18:22:08 volumio go-librespot[12360]: time="2025-10-31T18:22:08Z" level=info msg="zeroconf server listening on port 37107" Oct 31 18:22:08 volumio go-librespot[12360]: time="2025-10-31T18:22:08Z" level=debug msg="obtained new client token: AABXwGmcSBzN1iyxo2wZQ7kAIvDhZkAWngBkNC76SPw8mqmjveMAMUn/uNkm/WpSEJ8ai0ychkvrKPpMFi9Zn1QLZT8L1DU/hwUqbedUpOOCd38blHggzXEtJeWVuNRW9bulEmkN1XbGfbxVN/Yi5JUEEOmUSRgEp/tbjcx6v90pLqOwr7F1+dtcfIwsjmStvb6HCSVmcU9QZrysnFDZWflRqWo1gxvp1hmYN8NzbqLcMdcEpO2g" Oct 31 18:22:08 volumio go-librespot[12360]: time="2025-10-31T18:22:08Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:22:08 volumio go-librespot[12360]: time="2025-10-31T18:22:08Z" level=debug msg="completed keyexchange" Oct 31 18:22:08 volumio go-librespot[12360]: time="2025-10-31T18:22:08Z" level=debug msg="completed challenge" Oct 31 18:22:08 volumio go-librespot[12360]: time="2025-10-31T18:22:08Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:22:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:22:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:22:10 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:22:10 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 222. Oct 31 18:22:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:11 volumio go-librespot[12370]: go-librespot daemon starting... Oct 31 18:22:11 volumio go-librespot[12371]: time="2025-10-31T18:22:11Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:22:11 volumio go-librespot[12371]: time="2025-10-31T18:22:11Z" level=debug msg="app state loaded" Oct 31 18:22:11 volumio go-librespot[12371]: time="2025-10-31T18:22:11Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:22:11 volumio go-librespot[12371]: time="2025-10-31T18:22:11Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 31 18:22:11 volumio go-librespot[12371]: time="2025-10-31T18:22:11Z" 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]" Oct 31 18:22:11 volumio go-librespot[12371]: time="2025-10-31T18:22:11Z" 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]" Oct 31 18:22:11 volumio go-librespot[12371]: time="2025-10-31T18:22:11Z" level=info msg="zeroconf server listening on port 39171" Oct 31 18:22:11 volumio go-librespot[12371]: time="2025-10-31T18:22:11Z" level=debug msg="obtained new client token: AAC+O6ss9SKAG0WKo6PymyqEFf68JX/HwhO84eeQtJplnIsdPYI3+WXCi04Fy96MwMbzGdNYjn1234gwck4P7rfB7T3NmVrooz+eUgopqZPlNEgNMkg8/x3VH3slPfVj5kc6RRxnEC4Cna9pWIORrYXWjfsc8XwoSC3812el6PQjVg3tYHsRvZME2Vq+DCsKlS4BwlOwo++avYG58hucwZMphxCCMHU0m3FKVHNI86Y/3tSQaF/y/ug=" Oct 31 18:22:11 volumio go-librespot[12371]: time="2025-10-31T18:22:11Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:22:11 volumio go-librespot[12371]: time="2025-10-31T18:22:11Z" level=debug msg="completed keyexchange" Oct 31 18:22:11 volumio go-librespot[12371]: time="2025-10-31T18:22:11Z" level=debug msg="completed challenge" Oct 31 18:22:11 volumio go-librespot[12371]: time="2025-10-31T18:22:11Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:22:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:22:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:22:13 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:22:13 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 223. Oct 31 18:22:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:15 volumio go-librespot[12379]: go-librespot daemon starting... Oct 31 18:22:15 volumio go-librespot[12380]: time="2025-10-31T18:22:15Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:22:15 volumio go-librespot[12380]: time="2025-10-31T18:22:15Z" level=debug msg="app state loaded" Oct 31 18:22:15 volumio go-librespot[12380]: time="2025-10-31T18:22:15Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:22:15 volumio go-librespot[12380]: time="2025-10-31T18:22:15Z" 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]" Oct 31 18:22:15 volumio go-librespot[12380]: time="2025-10-31T18:22:15Z" 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]" Oct 31 18:22:15 volumio go-librespot[12380]: time="2025-10-31T18:22:15Z" 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]" Oct 31 18:22:15 volumio go-librespot[12380]: time="2025-10-31T18:22:15Z" level=info msg="zeroconf server listening on port 39129" Oct 31 18:22:15 volumio go-librespot[12380]: time="2025-10-31T18:22:15Z" level=debug msg="obtained new client token: AAAgjYnYb3vU9l7Q6BMXEVcgz/0x2QnIoRINu38z57WOkS6x6EmeCkZqNAS1GCODK0PWdcbU1c1aAwzf9brTPPavA/yjwTtk87/5D779QKlDBC5nGBoRp/o0nJtNLt3LiR/UMEx9athL74HlRUzaoo65Cucs8g05DWiZOJJLj8YWwA1ZvUXIR/63mKETbPRAqU1WThR+s5StkDvlSGkVPUkJFBPSmk7p0deXF3xgUf3k0pvWoxUE" Oct 31 18:22:15 volumio go-librespot[12380]: time="2025-10-31T18:22:15Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:22:15 volumio go-librespot[12380]: time="2025-10-31T18:22:15Z" level=debug msg="completed keyexchange" Oct 31 18:22:15 volumio go-librespot[12380]: time="2025-10-31T18:22:15Z" level=debug msg="completed challenge" Oct 31 18:22:15 volumio go-librespot[12380]: time="2025-10-31T18:22:15Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:22:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:22:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:22:16 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:22:16 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 224. Oct 31 18:22:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:18 volumio go-librespot[12401]: go-librespot daemon starting... Oct 31 18:22:18 volumio go-librespot[12402]: time="2025-10-31T18:22:18Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:22:18 volumio go-librespot[12402]: time="2025-10-31T18:22:18Z" level=debug msg="app state loaded" Oct 31 18:22:18 volumio go-librespot[12402]: time="2025-10-31T18:22:18Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:22:18 volumio go-librespot[12402]: time="2025-10-31T18:22:18Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 31 18:22:18 volumio go-librespot[12402]: time="2025-10-31T18:22:18Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 31 18:22:18 volumio go-librespot[12402]: time="2025-10-31T18:22:18Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 31 18:22:18 volumio go-librespot[12402]: time="2025-10-31T18:22:18Z" level=info msg="zeroconf server listening on port 44629" Oct 31 18:22:18 volumio go-librespot[12402]: time="2025-10-31T18:22:18Z" level=debug msg="obtained new client token: AAC2ACuhnvoC7nCTneX8he/Vu6g4bxhFTtUpGh13dQXDru3uEFQFm6/fgfDpSF1+iX0JFpkmA9THXaT7Nx7EaEHUrzayCtVaMYxz8nvEvum8ucTf+/nFiSDv+fbftkr3cc5GKAPzM3Tw30wdvTIk2XCCcI8+iSI4QipNd+1xq6cESJV9648Jh6ZheZbFYngH/UfUt1AnRJgkMjFGYDQArb+PHZn85PfrBnE1pFXVNfv3lUvDO7DiRsk=" Oct 31 18:22:18 volumio go-librespot[12402]: time="2025-10-31T18:22:18Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:22:18 volumio go-librespot[12402]: time="2025-10-31T18:22:18Z" level=debug msg="completed keyexchange" Oct 31 18:22:18 volumio go-librespot[12402]: time="2025-10-31T18:22:18Z" level=debug msg="completed challenge" Oct 31 18:22:18 volumio go-librespot[12402]: time="2025-10-31T18:22:18Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:22:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:22:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:22:19 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:22:19 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 225. Oct 31 18:22:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:22 volumio go-librespot[12409]: go-librespot daemon starting... Oct 31 18:22:22 volumio go-librespot[12410]: time="2025-10-31T18:22:22Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:22:22 volumio go-librespot[12410]: time="2025-10-31T18:22:22Z" level=debug msg="app state loaded" Oct 31 18:22:22 volumio go-librespot[12410]: time="2025-10-31T18:22:22Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:22:22 volumio go-librespot[12410]: time="2025-10-31T18:22:22Z" 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]" Oct 31 18:22:22 volumio go-librespot[12410]: time="2025-10-31T18:22:22Z" 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]" Oct 31 18:22:22 volumio go-librespot[12410]: time="2025-10-31T18:22:22Z" 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]" Oct 31 18:22:22 volumio go-librespot[12410]: time="2025-10-31T18:22:22Z" level=info msg="zeroconf server listening on port 39465" Oct 31 18:22:22 volumio go-librespot[12410]: time="2025-10-31T18:22:22Z" level=debug msg="obtained new client token: AADkN6MsVmZUOGsNR/4e2iWHsJnxanaa/QQwt1hVgr6y14Ha3BKSxc7lH3bIKtyJRoUWJx8+uX+i91Y2guTVnJx5BTk5dnnasjXyA0XrRuEGH2f+NVY4DKRogeiOps3GgEnaz0tDJN8zSpUD1Ml43DqY4fa7fMp36I9L2Ilff3xgprxHSmqqudSzhU1QyQDVY1OcWr7I5vzK7xJFKfGIzf7ioRcERLMYn/aDk6hxOPHvBSVSzwrm" Oct 31 18:22:22 volumio go-librespot[12410]: time="2025-10-31T18:22:22Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:22:22 volumio go-librespot[12410]: time="2025-10-31T18:22:22Z" level=debug msg="completed keyexchange" Oct 31 18:22:22 volumio go-librespot[12410]: time="2025-10-31T18:22:22Z" level=debug msg="completed challenge" Oct 31 18:22:22 volumio go-librespot[12410]: time="2025-10-31T18:22:22Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:22:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:22:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:22:22 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:22:22 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 226. Oct 31 18:22:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:25 volumio go-librespot[12417]: go-librespot daemon starting... Oct 31 18:22:25 volumio go-librespot[12418]: time="2025-10-31T18:22:25Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:22:25 volumio go-librespot[12418]: time="2025-10-31T18:22:25Z" level=debug msg="app state loaded" Oct 31 18:22:25 volumio go-librespot[12418]: time="2025-10-31T18:22:25Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:22:25 volumio go-librespot[12418]: time="2025-10-31T18:22:25Z" 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]" Oct 31 18:22:25 volumio go-librespot[12418]: time="2025-10-31T18:22:25Z" 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]" Oct 31 18:22:25 volumio go-librespot[12418]: time="2025-10-31T18:22:25Z" 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]" Oct 31 18:22:25 volumio go-librespot[12418]: time="2025-10-31T18:22:25Z" level=info msg="zeroconf server listening on port 46449" Oct 31 18:22:25 volumio go-librespot[12418]: time="2025-10-31T18:22:25Z" level=debug msg="obtained new client token: AABHiqjqDnAj53k0kqxgrc2MyvR8En6b6UA969Ro+DiCiPb1p2klxaC9Bhb2S3qZ077czfP5Ca6itbLME8V6CjF3dyQvahmE0OIHwc8we2GOezJZNe/vt33Wk9pozNeee2nsrjhdnLgMjUF6CRwEmXz7i8d9eBGvMdQZ8Dsh2zm5I+WQZEYB7NbJSgyTHfOaddl21h76uMNGP4lL9/0YhWly0UIy034pYMFRxxxhQS80o1xExsPeJ/Y=" Oct 31 18:22:25 volumio go-librespot[12418]: time="2025-10-31T18:22:25Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:22:25 volumio go-librespot[12418]: time="2025-10-31T18:22:25Z" level=debug msg="completed keyexchange" Oct 31 18:22:25 volumio go-librespot[12418]: time="2025-10-31T18:22:25Z" level=debug msg="completed challenge" Oct 31 18:22:25 volumio go-librespot[12418]: time="2025-10-31T18:22:25Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:22:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:22:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:22:25 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:22:25 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:28 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:22:28 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 227. Oct 31 18:22:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:29 volumio go-librespot[12440]: go-librespot daemon starting... Oct 31 18:22:29 volumio go-librespot[12441]: time="2025-10-31T18:22:29Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:22:29 volumio go-librespot[12441]: time="2025-10-31T18:22:29Z" level=debug msg="app state loaded" Oct 31 18:22:29 volumio go-librespot[12441]: time="2025-10-31T18:22:29Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:22:29 volumio go-librespot[12441]: time="2025-10-31T18:22:29Z" 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]" Oct 31 18:22:29 volumio go-librespot[12441]: time="2025-10-31T18:22:29Z" 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]" Oct 31 18:22:29 volumio go-librespot[12441]: time="2025-10-31T18:22:29Z" 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]" Oct 31 18:22:29 volumio go-librespot[12441]: time="2025-10-31T18:22:29Z" level=info msg="zeroconf server listening on port 44513" Oct 31 18:22:29 volumio go-librespot[12441]: time="2025-10-31T18:22:29Z" level=debug msg="obtained new client token: AACStjWOtpwlbG0T52Xc0d5rGU4s0MlvQC96UXfaHM2cT4jOg8kJp7k0mhphodX0LSFSx8Kvd67gyWRJpJntJvtrAjJN6cBQsk80MuVc9Oogdi2gQBoykAT38rSrdEk7nv3T4/LwO798zuSpfHbEx3HZ/18vUxNNrcJ7lAYluGpuI+8vFboi2n30G6EU7E6/nTEMSFKHEBNdNSirBs2wC6XKLx4JuZ/lho4k5C0oKmBWcZntwHMF" Oct 31 18:22:29 volumio go-librespot[12441]: time="2025-10-31T18:22:29Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:22:29 volumio go-librespot[12441]: time="2025-10-31T18:22:29Z" level=debug msg="completed keyexchange" Oct 31 18:22:29 volumio go-librespot[12441]: time="2025-10-31T18:22:29Z" level=debug msg="completed challenge" Oct 31 18:22:29 volumio go-librespot[12441]: time="2025-10-31T18:22:29Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:22:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:22:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:22:31 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:22:31 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 228. Oct 31 18:22:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:32 volumio go-librespot[12451]: go-librespot daemon starting... Oct 31 18:22:32 volumio go-librespot[12452]: time="2025-10-31T18:22:32Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:22:32 volumio go-librespot[12452]: time="2025-10-31T18:22:32Z" level=debug msg="app state loaded" Oct 31 18:22:32 volumio go-librespot[12452]: time="2025-10-31T18:22:32Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:22:32 volumio go-librespot[12452]: time="2025-10-31T18:22:32Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 31 18:22:32 volumio go-librespot[12452]: time="2025-10-31T18:22:32Z" 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]" Oct 31 18:22:32 volumio go-librespot[12452]: time="2025-10-31T18:22:32Z" 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]" Oct 31 18:22:32 volumio go-librespot[12452]: time="2025-10-31T18:22:32Z" level=info msg="zeroconf server listening on port 46127" Oct 31 18:22:32 volumio go-librespot[12452]: time="2025-10-31T18:22:32Z" level=debug msg="obtained new client token: AAChOKNw3ybPWv/R+IOaOWGL2Podjtk68tfjNwyBPKpoQ8HRHz+PVqnyocTZvMCWd44zLT3oMy4Vm6YtEAqb9ZrEuChe9goDg+zUQCyeDacjlP8vMNOD0hCaKKoPvsNJpXhDCHKVdzT3U8i1zfGtNgDwHD0LCNvHCH13XZ+ZU7iTH2Z/z6T8m4OlZxoyKxOqFUrW9xeocjw5xM1B6Pwfybx6EE5EihJ+tYkBaQBARbG9UJLtek+my4s=" Oct 31 18:22:32 volumio go-librespot[12452]: time="2025-10-31T18:22:32Z" 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" Oct 31 18:22:32 volumio go-librespot[12452]: time="2025-10-31T18:22:32Z" level=debug msg="connected to ap-gew1.spotify.com:443" Oct 31 18:22:32 volumio go-librespot[12452]: time="2025-10-31T18:22:32Z" level=debug msg="completed keyexchange" Oct 31 18:22:32 volumio go-librespot[12452]: time="2025-10-31T18:22:32Z" level=debug msg="completed challenge" Oct 31 18:22:32 volumio go-librespot[12452]: time="2025-10-31T18:22:32Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:22:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:22:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:22:34 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:22:34 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 229. Oct 31 18:22:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:36 volumio go-librespot[12473]: go-librespot daemon starting... Oct 31 18:22:36 volumio go-librespot[12474]: time="2025-10-31T18:22:36Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:22:36 volumio go-librespot[12474]: time="2025-10-31T18:22:36Z" level=debug msg="app state loaded" Oct 31 18:22:36 volumio go-librespot[12474]: time="2025-10-31T18:22:36Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:22:36 volumio go-librespot[12474]: time="2025-10-31T18:22:36Z" 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]" Oct 31 18:22:36 volumio go-librespot[12474]: time="2025-10-31T18:22:36Z" 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]" Oct 31 18:22:36 volumio go-librespot[12474]: time="2025-10-31T18:22:36Z" 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]" Oct 31 18:22:36 volumio go-librespot[12474]: time="2025-10-31T18:22:36Z" level=info msg="zeroconf server listening on port 44369" Oct 31 18:22:36 volumio go-librespot[12474]: time="2025-10-31T18:22:36Z" level=debug msg="obtained new client token: AABQccoXLW1Ii/FWh50YV7KmUJzp9Qz7L5Wifct+7hYDdz0W9IMX/Kae1erPyT7rhtbeitxC2FlPR4aPdU4KQeoT2ozNjQgC7FfYqyfYikEfiUyTEitA/PVoZPGWIoxVZZE8LkwWZl7A8IlQgYioGIDV4i1ReaD3LQKOBaFSj9Ii7y9pLPPZgXhkNIUUFedu6X9L5uKYxGVZr9yEjwIhsSilROjzoexITzqzP+hOI5Dc8T5sGi3t" Oct 31 18:22:36 volumio go-librespot[12474]: time="2025-10-31T18:22:36Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:22:36 volumio go-librespot[12474]: time="2025-10-31T18:22:36Z" level=debug msg="completed keyexchange" Oct 31 18:22:36 volumio go-librespot[12474]: time="2025-10-31T18:22:36Z" level=debug msg="completed challenge" Oct 31 18:22:36 volumio go-librespot[12474]: time="2025-10-31T18:22:36Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:22:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:22:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:22:37 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:22:37 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 230. Oct 31 18:22:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:39 volumio go-librespot[12482]: go-librespot daemon starting... Oct 31 18:22:39 volumio go-librespot[12483]: time="2025-10-31T18:22:39Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:22:39 volumio go-librespot[12483]: time="2025-10-31T18:22:39Z" level=debug msg="app state loaded" Oct 31 18:22:39 volumio go-librespot[12483]: time="2025-10-31T18:22:39Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:22:39 volumio go-librespot[12483]: time="2025-10-31T18:22:39Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 31 18:22:39 volumio go-librespot[12483]: time="2025-10-31T18:22:39Z" 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]" Oct 31 18:22:39 volumio go-librespot[12483]: time="2025-10-31T18:22:39Z" 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]" Oct 31 18:22:39 volumio go-librespot[12483]: time="2025-10-31T18:22:39Z" level=info msg="zeroconf server listening on port 46147" Oct 31 18:22:39 volumio go-librespot[12483]: time="2025-10-31T18:22:39Z" level=debug msg="obtained new client token: AADu4sO6iWAaTB9Xu/Bl8u/kH4MZozA1trSWPhey3q18274WeCO3fASGaD1dypREQiJdxk9m6z2/rHP8j6A4s2yULjbnX2oXT1WTa5TJyO7P2B3RuUQUGfb1pbvkk2v3DixlPeUB/kiL4iId2BXJCEiV6XXol4VFlU4sIY8w6aZQo/XA8BtGEkJ/RwOaIs8A77FgNnfdDXi3lIc7HSaR32ml0QEdBMyD+aWy2F6Ufdrb3Ki/5hGxyWA=" Oct 31 18:22:39 volumio go-librespot[12483]: time="2025-10-31T18:22:39Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:22:39 volumio go-librespot[12483]: time="2025-10-31T18:22:39Z" level=debug msg="completed keyexchange" Oct 31 18:22:39 volumio go-librespot[12483]: time="2025-10-31T18:22:39Z" level=debug msg="completed challenge" Oct 31 18:22:39 volumio go-librespot[12483]: time="2025-10-31T18:22:39Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:22:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:22:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:22:40 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:22:40 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 231. Oct 31 18:22:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:43 volumio go-librespot[12490]: go-librespot daemon starting... Oct 31 18:22:43 volumio go-librespot[12491]: time="2025-10-31T18:22:43Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:22:43 volumio go-librespot[12491]: time="2025-10-31T18:22:43Z" level=debug msg="app state loaded" Oct 31 18:22:43 volumio go-librespot[12491]: time="2025-10-31T18:22:43Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:22:43 volumio go-librespot[12491]: time="2025-10-31T18:22:43Z" 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]" Oct 31 18:22:43 volumio go-librespot[12491]: time="2025-10-31T18:22:43Z" 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]" Oct 31 18:22:43 volumio go-librespot[12491]: time="2025-10-31T18:22:43Z" 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]" Oct 31 18:22:43 volumio go-librespot[12491]: time="2025-10-31T18:22:43Z" level=info msg="zeroconf server listening on port 37943" Oct 31 18:22:43 volumio go-librespot[12491]: time="2025-10-31T18:22:43Z" level=debug msg="obtained new client token: AAAQ2JB6PD4Cz6wdcfzrCTFDxNMvR42QkBU8c8AQfb9vywVGfEmr0Jsa/AKxmuY1DxHvUev47hp04SDjvxtFAwQa1T2AhxzH2SW07yomGIf2uLA6YFjOksO5z6Y9R5CAJ4+MA+bpnbcSGxXcooBjt6v45u3UWwuTIIqItU8cZGEyO1iwi7cYNgLkY6mKjH90eKGGrJu6l51hHhPxOgf+otTYRIVcDtjVTsdxtwK4hC5kRvQqJy+Y" Oct 31 18:22:43 volumio go-librespot[12491]: time="2025-10-31T18:22:43Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:22:43 volumio go-librespot[12491]: time="2025-10-31T18:22:43Z" level=debug msg="completed keyexchange" Oct 31 18:22:43 volumio go-librespot[12491]: time="2025-10-31T18:22:43Z" level=debug msg="completed challenge" Oct 31 18:22:43 volumio go-librespot[12491]: time="2025-10-31T18:22:43Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:22:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:22:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:22:43 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:22:43 volumio volumio[11815]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 232. Oct 31 18:22:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 31 18:22:46 volumio go-librespot[12512]: go-librespot daemon starting... Oct 31 18:22:46 volumio go-librespot[12514]: time="2025-10-31T18:22:46Z" level=info msg="running go-librespot 0.4.0" Oct 31 18:22:46 volumio go-librespot[12514]: time="2025-10-31T18:22:46Z" level=debug msg="app state loaded" Oct 31 18:22:46 volumio go-librespot[12514]: time="2025-10-31T18:22:46Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 31 18:22:46 volumio go-librespot[12514]: time="2025-10-31T18:22:46Z" 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]" Oct 31 18:22:46 volumio go-librespot[12514]: time="2025-10-31T18:22:46Z" 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]" Oct 31 18:22:46 volumio go-librespot[12514]: time="2025-10-31T18:22:46Z" 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]" Oct 31 18:22:46 volumio go-librespot[12514]: time="2025-10-31T18:22:46Z" level=info msg="zeroconf server listening on port 39325" Oct 31 18:22:46 volumio go-librespot[12514]: time="2025-10-31T18:22:46Z" level=debug msg="obtained new client token: AAAhQuAB4FdfT/veS1dgRldUtsAanb+jqTJZR85zfwyacR/WoXZibffIqkY8wJSJZGBJGrLJVR1XscwQlebhpd0vrnXwOedKtspY5PBWGgbFZhkqm9/ESjn5dLUlHhBU5W32P4hsZzmDweKj/d6yTgBjyy4/SfEoa/Q5XsIjTcUQh59cAx6zjC61o97M3zsFtdfMarrPZ/N3ElW/XWw6rCA4t4gdP3j2XmljRKOxlhXvRaz46pn6XAc=" Oct 31 18:22:46 volumio go-librespot[12514]: time="2025-10-31T18:22:46Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 31 18:22:46 volumio volumio[11815]: info: Initializing connection to go-librespot Websocket Oct 31 18:22:46 volumio go-librespot[12514]: time="2025-10-31T18:22:46Z" level=debug msg="new websocket client" Oct 31 18:22:46 volumio volumio[11815]: info: Connection to go-librespot Websocket established Oct 31 18:22:47 volumio go-librespot[12514]: time="2025-10-31T18:22:47Z" level=debug msg="completed keyexchange" Oct 31 18:22:47 volumio go-librespot[12514]: time="2025-10-31T18:22:47Z" level=debug msg="completed challenge" Oct 31 18:22:47 volumio go-librespot[12514]: time="2025-10-31T18:22:47Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 31 18:22:47 volumio volumio[11815]: info: Connection to go-librespot Websocket closed Oct 31 18:22:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 31 18:22:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 31 18:22:49 volumio volumio[11815]: info: Getting Spotify volume Oct 31 18:22:49 volumio volumio[11815]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 31 18:22:49 volumio volumio[11815]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 31 18:22:49 volumio volumio[11815]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 31 18:22:49 volumio volumio[11815]: errno: -111, Oct 31 18:22:49 volumio volumio[11815]: code: 'ECONNREFUSED', Oct 31 18:22:49 volumio volumio[11815]: syscall: 'connect', Oct 31 18:22:49 volumio volumio[11815]: address: '127.0.0.1', Oct 31 18:22:49 volumio volumio[11815]: port: 9879, Oct 31 18:22:49 volumio volumio[11815]: response: undefined Oct 31 18:22:49 volumio volumio[11815]: } Oct 31 18:22:49 volumio volumio[11815]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 31 18:22:50 volumio sudo[12535]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-10-31 18:21' Oct 31 18:22:50 volumio sudo[12535]: 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"