Nov 06 02:59:00 volumio volumio[16518]: info: CoreCommandRouter::volumioGetState Nov 06 02:59:00 volumio volumio[16518]: info: CorePlayQueue::getTrack 0 Nov 06 02:59:00 volumio go-librespot[16840]: time="2025-11-06T02:59:00Z" 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" Nov 06 02:59:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:00 volumio volumio[16518]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Nov 06 02:59:00 volumio volumio[16518]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 06 02:59:00 volumio volumio[16518]: Error: socket hang up Nov 06 02:59:00 volumio volumio[16518]: at connResetException (node:internal/errors:720:14) Nov 06 02:59:00 volumio volumio[16518]: at Socket.socketOnEnd (node:_http_client:519:23) Nov 06 02:59:00 volumio volumio[16518]: at Socket.emit (node:events:526:35) Nov 06 02:59:00 volumio volumio[16518]: at endReadableNT (node:internal/streams/readable:1376:12) Nov 06 02:59:00 volumio volumio[16518]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Nov 06 02:59:00 volumio volumio[16518]: code: 'ECONNRESET', Nov 06 02:59:00 volumio volumio[16518]: response: undefined Nov 06 02:59:00 volumio volumio[16518]: } Nov 06 02:59:00 volumio volumio[16518]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 06 02:59:00 volumio sudo[17876]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-11-06 02:58' Nov 06 02:59:00 volumio sudo[17876]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:00 volumio sudo[17876]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:00 volumio volumio-remote-updater[874]: [2025-11-06 02:59:00] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Nov 06 02:59:00 volumio volumio-remote-updater[874]: [2025-11-06 02:59:00] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Nov 06 02:59:00 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:00 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Nov 06 02:59:00 volumio systemd[1]: volumio.service: Consumed 10.516s CPU time. Nov 06 02:59:00 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Nov 06 02:59:00 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Nov 06 02:59:01 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8180. Nov 06 02:59:01 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Nov 06 02:59:01 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Nov 06 02:59:01 volumio systemd[1]: volumio.service: Consumed 10.516s CPU time. Nov 06 02:59:01 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Nov 06 02:59:01 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Nov 06 02:59:01 volumio volumio[17922]: info: ------------------------------------------- Nov 06 02:59:01 volumio volumio[17922]: info: ----- Volumio3 ---- Nov 06 02:59:01 volumio volumio[17922]: info: ------------------------------------------- Nov 06 02:59:01 volumio volumio[17922]: info: ----- System startup ---- Nov 06 02:59:01 volumio volumio[17922]: info: ------------------------------------------- Nov 06 02:59:01 volumio volumio[17922]: info: MYVOLUMIO Environment detected Nov 06 02:59:01 volumio volumio[17922]: info: Plugin folders cleanup Nov 06 02:59:01 volumio volumio[17922]: info: Scanning into folder /volumio/app/plugins/ Nov 06 02:59:01 volumio volumio[17922]: info: Scanning category audio_interface Nov 06 02:59:01 volumio volumio[17922]: info: Scanning category miscellanea Nov 06 02:59:01 volumio volumio[17922]: info: Scanning category music_service Nov 06 02:59:01 volumio volumio[17922]: info: Scanning category plugins.json Nov 06 02:59:01 volumio volumio[17922]: info: Scanning category system_controller Nov 06 02:59:01 volumio volumio[17922]: info: Scanning category user_interface Nov 06 02:59:01 volumio volumio[17922]: info: Scanning into folder /data/plugins/ Nov 06 02:59:01 volumio volumio[17922]: info: Scanning category music_service Nov 06 02:59:01 volumio volumio[17922]: info: Scanning category user_interface Nov 06 02:59:01 volumio volumio[17922]: info: Plugin folders cleanup completed Nov 06 02:59:01 volumio volumio[17922]: info: ------------------------------------------- Nov 06 02:59:01 volumio volumio[17922]: info: ----- Core plugins startup ---- Nov 06 02:59:01 volumio volumio[17922]: info: ------------------------------------------- Nov 06 02:59:01 volumio volumio[17922]: info: Loading plugins from folder /volumio/app/plugins/ Nov 06 02:59:01 volumio volumio[17922]: info: Adding plugin upnp to MyMusic Plugins Nov 06 02:59:01 volumio volumio[17922]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 06 02:59:01 volumio volumio[17922]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 06 02:59:01 volumio volumio[17922]: info: Loading plugins from folder /data/plugins/ Nov 06 02:59:01 volumio volumio[17922]: info: Loading plugin "system"... Nov 06 02:59:01 volumio volumio[17922]: info: Loading plugin "appearance"... Nov 06 02:59:01 volumio volumio[17922]: info: Loading plugin "network"... Nov 06 02:59:01 volumio volumio[17922]: info: Refreshing Cached IP Addresses Nov 06 02:59:01 volumio sudo[17950]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 06 02:59:01 volumio sudo[17950]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:01 volumio sudo[17950]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:01 volumio sudo[17952]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 06 02:59:01 volumio volumio[17922]: info: Loading plugin "services"... Nov 06 02:59:01 volumio sudo[17952]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:01 volumio volumio[17922]: info: Loading plugin "alsa_controller"... Nov 06 02:59:01 volumio sudo[17952]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:01 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 06 02:59:01 volumio volumio[17922]: info: Loading plugin "wizard"... Nov 06 02:59:01 volumio volumio[17922]: info: Loading plugin "networkfs"... Nov 06 02:59:01 volumio volumio[17922]: info: Cannot mount NAS NAS at system boot, trial number 1 ,retrying in 5 seconds Nov 06 02:59:01 volumio volumio[17922]: info: Starting Udev Watcher for removable devices Nov 06 02:59:01 volumio volumio[17922]: info: Ignoring mount for partition: boot Nov 06 02:59:01 volumio volumio[17922]: info: Ignoring mount for partition: volumio Nov 06 02:59:01 volumio volumio[17922]: info: Ignoring mount for partition: volumio_data Nov 06 02:59:01 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 06 02:59:01 volumio volumio[17922]: info: Loading plugin "volumio_command_line_client"... Nov 06 02:59:01 volumio volumio[17922]: info: Loading plugin "upnp"... Nov 06 02:59:01 volumio volumio[17922]: info: [1762397941813] Starting Upmpd Daemon Nov 06 02:59:01 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 06 02:59:01 volumio volumio[17922]: info: Loading plugin "my_music"... Nov 06 02:59:01 volumio volumio[17922]: info: Loading plugin "mpd"... Nov 06 02:59:01 volumio volumio[17922]: info: Loading plugin "upnp_browser"... Nov 06 02:59:02 volumio volumio[17922]: info: Loading plugin "alarm-clock"... Nov 06 02:59:02 volumio volumio[17922]: info: Loading plugin "airplay_emulation"... Nov 06 02:59:02 volumio volumio[17922]: info: Starting Shairport Sync Nov 06 02:59:02 volumio volumio[17922]: info: Loading plugin "last_100"... Nov 06 02:59:02 volumio volumio[17922]: info: Loading plugin "webradio"... Nov 06 02:59:02 volumio volumio[17922]: info: Loading plugin "i2s_dacs"... Nov 06 02:59:02 volumio volumio[17922]: info: I2S DAC not set, start Auto-detection Nov 06 02:59:02 volumio volumio[17922]: info: Loading plugin "volumiodiscovery"... Nov 06 02:59:02 volumio volumio[17922]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 06 02:59:02 volumio node[17922]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 06 02:59:02 volumio volumio[17922]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 06 02:59:02 volumio node[17922]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 06 02:59:02 volumio volumio[17922]: *** WARNING *** For more information see Nov 06 02:59:02 volumio node[17922]: *** WARNING *** For more information see Nov 06 02:59:02 volumio volumio[17922]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 06 02:59:02 volumio node[17922]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 06 02:59:02 volumio volumio[17922]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 06 02:59:02 volumio node[17922]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 06 02:59:02 volumio volumio[17922]: *** WARNING *** For more information see Nov 06 02:59:02 volumio node[17922]: *** WARNING *** For more information see Nov 06 02:59:02 volumio volumio[17922]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 06 02:59:02 volumio volumio[17922]: info: Discovery: Started advertising with name: Volumio Nov 06 02:59:02 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 06 02:59:02 volumio volumio[17922]: info: Loading plugin "spop"... Nov 06 02:59:02 volumio volumio[17922]: info: Loading plugin "ytcr"... Nov 06 02:59:03 volumio volumio[17922]: info: Loading plugin "outputs"... Nov 06 02:59:03 volumio volumio[17922]: info: Loading plugin "albumart"... Nov 06 02:59:03 volumio volumio[17922]: info: Plugin example_plugin is not enabled Nov 06 02:59:03 volumio volumio[17922]: info: Loading plugin "inputs"... Nov 06 02:59:03 volumio volumio[17922]: info: Loading plugin "updater_comm"... Nov 06 02:59:03 volumio volumio[17922]: info: Plugin mpdemulation is not enabled Nov 06 02:59:03 volumio volumio[17922]: info: Loading plugin "rest_api"... Nov 06 02:59:03 volumio volumio[17922]: info: Loading plugin "websocket"... Nov 06 02:59:03 volumio volumio[17922]: info: Starting Socket.io Server version 1.7.4 Nov 06 02:59:03 volumio volumio[17922]: info: Loading plugin "Systeminfo"... Nov 06 02:59:03 volumio volumio[17922]: info: Loading i18n strings for locale en Nov 06 02:59:03 volumio volumio[17922]: Updating browse sources language Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 06 02:59:03 volumio volumio[17982]: Forking 3 albumart workers Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::initPlayerControls Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: Express server listening on port 3000 Nov 06 02:59:03 volumio volumio[17922]: [Metrics] WebUI: 1s 952.84ms Nov 06 02:59:03 volumio volumio[17922]: info: CoreStateMachine::resetVolumioState Nov 06 02:59:03 volumio volumio[17922]: info: CoreStateMachine::getcurrentVolume Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::volumioRetrievevolume Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: Cannot read play queue from file Nov 06 02:59:03 volumio volumio[17922]: info: Volumio Network Manager: Network status updated: 1 Nov 06 02:59:03 volumio volumio[17922]: info: VolumeController:: Volume=33 Mute =false Nov 06 02:59:03 volumio volumio[17922]: info: CoreStateMachine::pushState Nov 06 02:59:03 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::volumioPushState Nov 06 02:59:03 volumio volumio[17922]: info: CoreStateMachine::updateTrackBlock Nov 06 02:59:03 volumio volumio[17922]: info: CorePlayQueue::getTrackBlock Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::volumioRetrievevolume Nov 06 02:59:03 volumio volumio[17922]: info: CoreStateMachine::setRepeat null single undefined Nov 06 02:59:03 volumio volumio[17922]: info: CoreStateMachine::pushState Nov 06 02:59:03 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::volumioPushState Nov 06 02:59:03 volumio volumio[17922]: info: CoreStateMachine::setRandom null Nov 06 02:59:03 volumio volumio[17922]: info: CoreStateMachine::pushState Nov 06 02:59:03 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::volumioPushState Nov 06 02:59:03 volumio volumio[17922]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Nov 06 02:59:03 volumio volumio[17922]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b04170 Nov 06 02:59:03 volumio volumio[17922]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Nov 06 02:59:03 volumio volumio[17922]: info: Setting Device type: Raspberry PI Nov 06 02:59:03 volumio volumio[17922]: info: VolumeController:: Volume=33 Mute =false Nov 06 02:59:03 volumio volumio[17922]: info: CoreStateMachine::pushState Nov 06 02:59:03 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::volumioPushState Nov 06 02:59:03 volumio volumio[17922]: info: Completed loading Core Plugins Nov 06 02:59:03 volumio volumio[17922]: info: Preparing to generate the ALSA configuration file Nov 06 02:59:03 volumio volumio[17922]: info: Discovery: adding 70853f74-8210-4683-a3fa-e1217517bd40 Nov 06 02:59:03 volumio volumio[17922]: info: Discovery: Found device Volumio Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::volumioGetState Nov 06 02:59:03 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 02:59:03 volumio volumio[17922]: info: Discovery: this is already registered, 70853f74-8210-4683-a3fa-e1217517bd40 Nov 06 02:59:03 volumio volumio[17922]: info: Discovery: Found device Volumio Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::volumioGetState Nov 06 02:59:03 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 02:59:03 volumio volumio[17922]: info: Asound.conf file unchanged, so no further update is needed Nov 06 02:59:03 volumio volumio[17922]: info: Output device has changed, restarting MPD Nov 06 02:59:03 volumio volumio[17922]: info: Output device has changed, restarting Shairport Sync Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:03 volumio sudo[18041]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 06 02:59:03 volumio sudo[18041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:03 volumio sudo[18040]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 06 02:59:03 volumio sudo[18040]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:03 volumio sudo[18040]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:03 volumio volumio[17922]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 06 02:59:03 volumio volumio[17922]: info: ___________ START PLUGINS ___________ Nov 06 02:59:03 volumio volumio[17922]: info: ControllerMpd::onStart: Initializing MPD Nov 06 02:59:03 volumio volumio[17922]: info: Creating MPD Configuration file Nov 06 02:59:03 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 06 02:59:03 volumio volumio[17922]: info: [1762397943451] CoreMusicLibrary::Adding element Media Servers Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 06 02:59:03 volumio sudo[18051]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 06 02:59:03 volumio sudo[18051]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:03 volumio sudo[18050]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 06 02:59:03 volumio sudo[18050]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:03 volumio sudo[18050]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:03 volumio systemd[1]: mpd.service: Deactivated successfully. Nov 06 02:59:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 06 02:59:03 volumio volumio[17922]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:03 volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 06 02:59:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 06 02:59:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 06 02:59:03 volumio volumio[17922]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 06 02:59:03 volumio volumio[17922]: info: [1762397943487] CoreMusicLibrary::Adding element Last_100 Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 06 02:59:03 volumio volumio[17922]: info: [1762397943488] CoreMusicLibrary::Adding element Webradio Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 06 02:59:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 06 02:59:03 volumio volumio[17922]: info: Initializing BBC Radios Nov 06 02:59:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 06 02:59:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 126. Nov 06 02:59:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:03 volumio go-librespot[18066]: go-librespot daemon starting... Nov 06 02:59:03 volumio go-librespot[18070]: time="2025-11-06T02:59:03Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:03 volumio go-librespot[18070]: time="2025-11-06T02:59:03Z" level=debug msg="app state loaded" Nov 06 02:59:03 volumio go-librespot[18070]: time="2025-11-06T02:59:03Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:03 volumio sudo[18063]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 06 02:59:03 volumio sudo[18063]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 06 02:59:03 volumio sudo[18063]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: Creating Spotify config file Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio go-librespot[18070]: time="2025-11-06T02:59:03Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 02:59:03 volumio go-librespot[18070]: time="2025-11-06T02:59:03Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 02:59:03 volumio go-librespot[18070]: time="2025-11-06T02:59:03Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 02:59:03 volumio go-librespot[18070]: time="2025-11-06T02:59:03Z" level=info msg="zeroconf server listening on port 38685" Nov 06 02:59:03 volumio volumio[17922]: info: Volumio Calling Home Nov 06 02:59:03 volumio go-librespot[18070]: time="2025-11-06T02:59:03Z" level=debug msg="obtained new client token: AABKWyDcETpgYwitjmcRCWubVCe7HrHdHdC2XE+059g13ol8wrKZhIzwOX5t7J//9qrpZMluYtZcO3t1dqzjiyq0SCVyxcYbtQvIJHpZA29rPjYwV6eRRJ/vL2MipzxLgBitAm5bdUbSRYfD6GNayjTTHmvskYyxRET3t1cfmVIqmrkzqk+I260zPXuT6tcEdeC6ZkAuxKdGzx4XqW8oF0vZpGK5pmITEOM/h2HBeT3S8plZY19/Kv0=" Nov 06 02:59:03 volumio go-librespot[18070]: time="2025-11-06T02:59:03Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 02:59:03 volumio go-librespot[18070]: time="2025-11-06T02:59:03Z" level=debug msg="completed keyexchange" Nov 06 02:59:03 volumio go-librespot[18070]: time="2025-11-06T02:59:03Z" level=debug msg="completed challenge" Nov 06 02:59:03 volumio go-librespot[18070]: time="2025-11-06T02:59:03Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:03 volumio volumio[17994]: Starting albumart workers Nov 06 02:59:03 volumio volumio[17992]: Starting albumart workers Nov 06 02:59:03 volumio volumio[17993]: Starting albumart workers Nov 06 02:59:03 volumio volumio[17922]: info: MPD Permissions set Nov 06 02:59:03 volumio volumio[17922]: info: MPD Permissions set Nov 06 02:59:03 volumio volumio[17922]: info: Volumio called home Nov 06 02:59:03 volumio volumio[17922]: info: Spotify config file written Nov 06 02:59:03 volumio volumio[17922]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Nov 06 02:59:03 volumio sudo[18091]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 06 02:59:03 volumio sudo[18091]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:03 volumio volumio[17922]: info: No need to fix Spotify hosts Nov 06 02:59:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:04 volumio go-librespot[18098]: go-librespot daemon starting... Nov 06 02:59:04 volumio go-librespot[18104]: time="2025-11-06T02:59:04Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:04 volumio go-librespot[18104]: time="2025-11-06T02:59:04Z" level=debug msg="app state loaded" Nov 06 02:59:04 volumio sudo[18091]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:04 volumio go-librespot[18104]: time="2025-11-06T02:59:04Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:04 volumio mpd[18085]: 2025-11-06T02:59:04 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 06 02:59:04 volumio systemd[1]: Started mpd.service - Music Player Daemon. Nov 06 02:59:04 volumio sudo[18041]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:04 volumio sudo[18051]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:04 volumio volumio[17922]: info: Starting Shairport Sync Nov 06 02:59:04 volumio volumio[17922]: info: Starting Shairport Sync Nov 06 02:59:04 volumio volumio[17922]: info: Starting Shairport Sync Nov 06 02:59:04 volumio sudo[18133]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 06 02:59:04 volumio go-librespot[18104]: time="2025-11-06T02:59:04Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 02:59:04 volumio go-librespot[18104]: time="2025-11-06T02:59:04Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 02:59:04 volumio go-librespot[18104]: time="2025-11-06T02:59:04Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 02:59:04 volumio sudo[18133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:04 volumio go-librespot[18104]: time="2025-11-06T02:59:04Z" level=info msg="zeroconf server listening on port 38051" Nov 06 02:59:04 volumio sudo[18138]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 06 02:59:04 volumio sudo[18138]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:04 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 06 02:59:04 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 06 02:59:04 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 06 02:59:04 volumio systemd[1]: shairport-sync.service: Consumed 1.865s CPU time. Nov 06 02:59:04 volumio sudo[18135]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 06 02:59:04 volumio sudo[18135]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:04 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 06 02:59:04 volumio sudo[18133]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:04 volumio sudo[18138]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:04 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 06 02:59:04 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 06 02:59:04 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 06 02:59:04 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 06 02:59:04 volumio sudo[18135]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:04 volumio go-librespot[18104]: time="2025-11-06T02:59:04Z" level=debug msg="obtained new client token: AAAbADtXIFnpxN/ewr3bwD9PQlLKp+wySeRnOUopl+hW/rgbJigtvZsch05iBFgBEVpxHHsAci11xPPVX2UzgIbSHp32/6KIhW8hOiQOA/LJtZ7uIz3GUNpa1k4n5Wg7/ihgrOYW8K+QcuchMdLPQ7EwYKZUyyDBEGYLGAk6MPlnmijEQVttnVzT6EdirCIAmP9nRtNGM6zHMVCvJrbqMH/kLlxQT0DCwiySVxqd3B8DIzjiJY+9" Nov 06 02:59:04 volumio volumio[17922]: info: Shairport-Sync Started Nov 06 02:59:04 volumio volumio[17922]: Error adding Membership: Error: addMembership EINVAL Nov 06 02:59:04 volumio volumio[17922]: info: Shairport-Sync Started Nov 06 02:59:04 volumio go-librespot[18104]: time="2025-11-06T02:59:04Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 02:59:04 volumio volumio[17922]: error: MPD error: The expression evaluated to a falsy value: Nov 06 02:59:04 volumio volumio[17922]: assert.ok(self.idling) Nov 06 02:59:04 volumio volumio[17922]: error: The expression evaluated to a falsy value: Nov 06 02:59:04 volumio volumio[17922]: assert.ok(self.idling) Nov 06 02:59:04 volumio volumio[17922]: info: MPD running with PID18085 Nov 06 02:59:04 volumio volumio[17922]: ,establishing connection Nov 06 02:59:04 volumio volumio[17922]: info: Shairport-Sync Started Nov 06 02:59:04 volumio volumio[17922]: error: updateQueue error: null Nov 06 02:59:04 volumio volumio[17922]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 06 02:59:04 volumio volumio[17922]: SPOTIFY: BQCgR5pQF-GIe0cMMn8IvB21PcDboeaDBxoyldxVpVnYP3tL4Mh3U8BqWAE2FfaG_1CT2gQF1dH7DQfUvWq5CoIAH-3Zn3SZkSfsrRwMc5uxX_ywcuwtag8-0BLwzLJ7VlR31RyVACKbKroDFuh-qIFHVykrciDzuAldIEoqj_ycGR6OZ9XDqJJ2mgtx8Ar42syJFMoxK3gd3WgvzDf4mxPyyh2ERRqBAFIakNSxH7pbLDReo0ZcSugnpI5To9SmTys86h-tmVo6ZktX8EBcQYX5_1Kkifk-dDi0I0PIqyZQ0H9BWeIwmfAY Nov 06 02:59:04 volumio volumio[17922]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 06 02:59:04 volumio volumio[17922]: info: New Spotify access token = BQCgR5pQF-GIe0cMMn8IvB21PcDboeaDBxoyldxVpVnYP3tL4Mh3U8BqWAE2FfaG_1CT2gQF1dH7DQfUvWq5CoIAH-3Zn3SZkSfsrRwMc5uxX_ywcuwtag8-0BLwzLJ7VlR31RyVACKbKroDFuh-qIFHVykrciDzuAldIEoqj_ycGR6OZ9XDqJJ2mgtx8Ar42syJFMoxK3gd3WgvzDf4mxPyyh2ERRqBAFIakNSxH7pbLDReo0ZcSugnpI5To9SmTys86h-tmVo6ZktX8EBcQYX5_1Kkifk-dDi0I0PIqyZQ0H9BWeIwmfAY Nov 06 02:59:04 volumio volumio[17922]: info: Spotify credentials grant success - running version from March 24, 2019 Nov 06 02:59:04 volumio volumio[17922]: error: updateQueue error: null Nov 06 02:59:04 volumio go-librespot[18104]: time="2025-11-06T02:59:04Z" level=debug msg="completed keyexchange" Nov 06 02:59:04 volumio go-librespot[18104]: time="2025-11-06T02:59:04Z" level=debug msg="completed challenge" Nov 06 02:59:04 volumio volumio[17922]: info: CoreCommandRouter::volumioGetState Nov 06 02:59:04 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 02:59:04 volumio go-librespot[18104]: time="2025-11-06T02:59:04Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:04 volumio volumio[17922]: SPOTIFY: User informations: {"country":"DE","display_name":"lapman","email":"ylm19961214@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31hyzsop5elyyfayaiyk5tmkxmky"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31hyzsop5elyyfayaiyk5tmkxmky","id":"31hyzsop5elyyfayaiyk5tmkxmky","images":[],"product":"free","type":"user","uri":"spotify:user:31hyzsop5elyyfayaiyk5tmkxmky"} Nov 06 02:59:04 volumio volumio[17922]: info: Spotify Successfully logged in Nov 06 02:59:04 volumio volumio[17922]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 06 02:59:04 volumio volumio[17922]: info: [1762397944422] CoreMusicLibrary::Adding element Spotify Nov 06 02:59:04 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 06 02:59:04 volumio volumio[17922]: Cannot find translation for source Spotify Nov 06 02:59:04 volumio volumio[17922]: info: [yt-cast-receiver] DIAL server listening on port 8098 Nov 06 02:59:04 volumio volumio[17922]: info: CoreCommandRouter::volumioRetrievevolume Nov 06 02:59:04 volumio volumio[17922]: info: VolumeController:: Volume=33 Mute =false Nov 06 02:59:04 volumio volumio[17922]: info: CoreCommandRouter::volumioGetState Nov 06 02:59:04 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 02:59:04 volumio volumio[17922]: info: CoreStateMachine::pushState Nov 06 02:59:04 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 02:59:04 volumio volumio[17922]: info: CoreCommandRouter::volumioPushState Nov 06 02:59:04 volumio volumio[17922]: info: Completed starting Core Plugins Nov 06 02:59:04 volumio volumio[17922]: info: ------------------------------------------- Nov 06 02:59:04 volumio volumio[17922]: info: ----- MyVolumio plugins startup ---- Nov 06 02:59:04 volumio volumio[17922]: info: ------------------------------------------- Nov 06 02:59:04 volumio volumio[17922]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 06 02:59:05 volumio volumio-remote-updater[874]: [2025-11-06 02:59:05] [connect] Successful connection Nov 06 02:59:05 volumio volumio-remote-updater[874]: [2025-11-06 02:59:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1762397945 101 Nov 06 02:59:05 volumio volumio[17922]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Nov 06 02:59:06 volumio volumio[17922]: info: Cannot mount NAS NAS at system boot, trial number 2 ,retrying in 5 seconds Nov 06 02:59:07 volumio volumio[17922]: info: go-librespot daemon successfully initialized Nov 06 02:59:07 volumio sudo[18164]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 06 02:59:07 volumio sudo[18164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:07 volumio sudo[18167]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 06 02:59:07 volumio sudo[18167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:07 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Nov 06 02:59:07 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Nov 06 02:59:07 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Nov 06 02:59:07 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Nov 06 02:59:07 volumio mpd_monitor.sh[18169]: MPD Monitor Service: Starting MPD Monitor Service Nov 06 02:59:07 volumio sudo[18164]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:07 volumio volumio[17922]: info: Successfully started MPD Monitor Nov 06 02:59:07 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Nov 06 02:59:07 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Nov 06 02:59:07 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Nov 06 02:59:07 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Nov 06 02:59:07 volumio mpd_monitor.sh[18173]: MPD Monitor Service: Starting MPD Monitor Service Nov 06 02:59:07 volumio sudo[18167]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:07 volumio volumio[17922]: info: Successfully started MPD Monitor Nov 06 02:59:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 127. Nov 06 02:59:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:07 volumio go-librespot[18177]: go-librespot daemon starting... Nov 06 02:59:07 volumio go-librespot[18178]: time="2025-11-06T02:59:07Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:07 volumio go-librespot[18178]: time="2025-11-06T02:59:07Z" level=debug msg="app state loaded" Nov 06 02:59:07 volumio go-librespot[18178]: time="2025-11-06T02:59:07Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:07 volumio go-librespot[18178]: time="2025-11-06T02:59:07Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 02:59:07 volumio go-librespot[18178]: time="2025-11-06T02:59:07Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 02:59:07 volumio go-librespot[18178]: time="2025-11-06T02:59:07Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 02:59:07 volumio go-librespot[18178]: time="2025-11-06T02:59:07Z" level=info msg="zeroconf server listening on port 37619" Nov 06 02:59:07 volumio go-librespot[18178]: time="2025-11-06T02:59:07Z" level=debug msg="obtained new client token: AADxZPq/1Rx0M9ddZqRJWrwMcMXGri+7iiCSjWh5SIQZ+9qgeQ+xu3Nc4RwMEqXnTLBUotDSh4touMKjFzTZHyi3/lXVBepdyoc3gg/kJdKtoei0ieBKYLv0kDqqrl7p79hCCzrMmCyjOEFGZzALwASS0yHFjw6qLAGmBQOdZ7jEeoLNzBJIOcjcgSDhxXgFLN7BAGNRUdHZFtFxrQktcnobpOC+gIuSFIXYjHfETAhyjv9F9uEi460=" Nov 06 02:59:07 volumio go-librespot[18178]: time="2025-11-06T02:59:07Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 02:59:07 volumio go-librespot[18178]: time="2025-11-06T02:59:07Z" level=debug msg="completed keyexchange" Nov 06 02:59:07 volumio go-librespot[18178]: time="2025-11-06T02:59:07Z" level=debug msg="completed challenge" Nov 06 02:59:07 volumio go-librespot[18178]: time="2025-11-06T02:59:07Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:09 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 06 02:59:09 volumio volumio[17922]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Nov 06 02:59:10 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:10 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:10 volumio volumio[17922]: info: CoreCommandRouter::volumioGetState Nov 06 02:59:10 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 02:59:10 volumio volumio[17922]: info: Listing playlists Nov 06 02:59:10 volumio volumio[17922]: info: Listing playlists Nov 06 02:59:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 128. Nov 06 02:59:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:11 volumio go-librespot[18186]: go-librespot daemon starting... Nov 06 02:59:11 volumio go-librespot[18187]: time="2025-11-06T02:59:11Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:11 volumio go-librespot[18187]: time="2025-11-06T02:59:11Z" level=debug msg="app state loaded" Nov 06 02:59:11 volumio go-librespot[18187]: time="2025-11-06T02:59:11Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:11 volumio go-librespot[18187]: time="2025-11-06T02:59: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]" Nov 06 02:59:11 volumio go-librespot[18187]: time="2025-11-06T02:59: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]" Nov 06 02:59:11 volumio go-librespot[18187]: time="2025-11-06T02:59: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]" Nov 06 02:59:11 volumio go-librespot[18187]: time="2025-11-06T02:59:11Z" level=info msg="zeroconf server listening on port 37209" Nov 06 02:59:11 volumio go-librespot[18187]: time="2025-11-06T02:59:11Z" level=debug msg="obtained new client token: AABUSMU2LyTZ+lyA5DKyfoS4dc4ZWDHeG6Mh7aJAX5whO5tU7c1lhceLnluIkH0DKhL3TQ/K4Z88xkOi2KvrEBaLGFiOHinQQVHhc1BZTnE9TkdgJ9waxHm3BPtW24wFgtgMWhQut2rDEaQCScmWMT5ZAz2qmfpjtmykkmBe8k5/u4jE8gks1+QOYB2d0v82gf0XZ4gn/EAeqXaWqKfdcYscjDe0RBbC/GZ/qPnoOGsj0PzG98d4" Nov 06 02:59:11 volumio go-librespot[18187]: time="2025-11-06T02:59:11Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 02:59:11 volumio go-librespot[18187]: time="2025-11-06T02:59:11Z" level=debug msg="completed keyexchange" Nov 06 02:59:11 volumio go-librespot[18187]: time="2025-11-06T02:59:11Z" level=debug msg="completed challenge" Nov 06 02:59:11 volumio go-librespot[18187]: time="2025-11-06T02:59:11Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:11 volumio volumio[17922]: info: Cannot mount NAS NAS at system boot, trial number 3 ,retrying in 5 seconds Nov 06 02:59:11 volumio sudo[18211]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 06 02:59:11 volumio sudo[18211]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:11 volumio sudo[18213]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 06 02:59:11 volumio sudo[18213]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:11 volumio sudo[18211]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:11 volumio sudo[18213]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:11 volumio sudo[18217]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 06 02:59:11 volumio sudo[18217]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:11 volumio sudo[18217]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:11 volumio volumio[17922]: info: Upmpdcli Daemon Started Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Nov 06 02:59:13 volumio volumio[17922]: info: Adding plugin bluetooth to MyMusic Plugins Nov 06 02:59:13 volumio volumio[17922]: info: Adding plugin multiroom to MyMusic Plugins Nov 06 02:59:13 volumio volumio[17922]: info: Adding plugin metavolumio to MyMusic Plugins Nov 06 02:59:13 volumio volumio[17922]: info: Adding plugin cd_controller to MyMusic Plugins Nov 06 02:59:13 volumio volumio[17922]: info: Adding plugin qobuzconnect to MyMusic Plugins Nov 06 02:59:13 volumio volumio[17922]: info: Adding plugin smart_inputs to MyMusic Plugins Nov 06 02:59:13 volumio volumio[17922]: info: Adding plugin tidalconnect to MyMusic Plugins Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 06 02:59:13 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:13 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:13 volumio volumio[17922]: info: Starting MyVolumio Remote Streaming Endpoints Nov 06 02:59:13 volumio volumio[17922]: info: MyVolumio login type: Token Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 06 02:59:13 volumio volumio[17922]: info: Streaming services startup Nov 06 02:59:13 volumio volumio[17922]: info: Starting Streaming Daemon Nov 06 02:59:13 volumio sudo[18220]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 06 02:59:13 volumio sudo[18220]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:13 volumio volumio[17922]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 06 02:59:13 volumio sudo[18220]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:13 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:13 volumio volumio[17922]: error: Cannot start Volumio Streaming Daemon Nov 06 02:59:13 volumio volumio[17922]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 06 02:59:13 volumio volumio[17922]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 06 02:59:13 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:13 volumio volumio[17922]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Nov 06 02:59:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 129. Nov 06 02:59:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:14 volumio go-librespot[18226]: go-librespot daemon starting... Nov 06 02:59:14 volumio go-librespot[18227]: time="2025-11-06T02:59:14Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:14 volumio go-librespot[18227]: time="2025-11-06T02:59:14Z" level=debug msg="app state loaded" Nov 06 02:59:14 volumio go-librespot[18227]: time="2025-11-06T02:59:14Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:14 volumio go-librespot[18227]: time="2025-11-06T02:59:14Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 02:59:14 volumio go-librespot[18227]: time="2025-11-06T02:59:14Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 02:59:14 volumio go-librespot[18227]: time="2025-11-06T02:59:14Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 02:59:14 volumio go-librespot[18227]: time="2025-11-06T02:59:14Z" level=info msg="zeroconf server listening on port 37569" Nov 06 02:59:14 volumio go-librespot[18227]: time="2025-11-06T02:59:14Z" level=debug msg="obtained new client token: AACOVqTh0IzajNeLoXBLU1kAIsbTtdsa7TNugvdC6NWUv2Z5mjndf4embe8EvEbz7kDQCz5T5GRasDfz3SrDDBe93II1wtB3IU1bpxN7WJLZ8jQi4hWC7JTkoPqf8TD9S8i9moX1bUa4gw1tEF6jTIZpFwHjHxriqM3uMEyoNe6U2FXpjmnHFPzvRtdsZYdO234y4TDS+tSQt20ludDIHj1+GbIoHzf3YQvL21ftTfakFKgypuIYaMY=" Nov 06 02:59:14 volumio go-librespot[18227]: time="2025-11-06T02:59:14Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 02:59:14 volumio go-librespot[18227]: time="2025-11-06T02:59:14Z" level=debug msg="completed keyexchange" Nov 06 02:59:14 volumio go-librespot[18227]: time="2025-11-06T02:59:14Z" level=debug msg="completed challenge" Nov 06 02:59:14 volumio go-librespot[18227]: time="2025-11-06T02:59:14Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:14 volumio volumio[17922]: info: MyVolumio token set successfully Nov 06 02:59:14 volumio volumio[17922]: info: MYVOLUMIO: Adding device Nov 06 02:59:14 volumio volumio[17922]: info: MYVOLUMIO: Evaluating Server Nov 06 02:59:15 volumio volumio[17922]: info: MyVolumio status changed Nov 06 02:59:15 volumio volumio[17922]: info: Streaming services startup Nov 06 02:59:15 volumio volumio[17922]: info: Starting Streaming Daemon Nov 06 02:59:15 volumio volumio[17922]: info: Removing browser output: myVolumio user plan is not superstar Nov 06 02:59:15 volumio volumio[17922]: info: Removing audio output: Nov 06 02:59:15 volumio volumio[17922]: info: Stoppping Tunnel 1 Nov 06 02:59:15 volumio sudo[18252]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 06 02:59:15 volumio sudo[18252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:15 volumio sudo[18254]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Nov 06 02:59:15 volumio sudo[18254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 06 02:59:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 06 02:59:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 06 02:59:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 06 02:59:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 06 02:59:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 06 02:59:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 06 02:59:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 06 02:59:15 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 06 02:59:15 volumio sudo[18254]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:15 volumio sudo[18252]: pam_unix(sudo:session): session closed for user root Nov 06 02:59:15 volumio volumio[17922]: info: Remote SSH Stopped Nov 06 02:59:15 volumio volumio[17922]: error: Cannot start Volumio Streaming Daemon Nov 06 02:59:15 volumio volumio[17922]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 06 02:59:15 volumio volumio[17922]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 06 02:59:15 volumio volumio[17922]: info: Setting Geolocation for MyVolumio to eu3 Nov 06 02:59:15 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:15 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:15 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:15 volumio volumio[17922]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 06 02:59:16 volumio volumio[17922]: info: Updating MyVolumio device info Nov 06 02:59:16 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:16 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:16 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:16 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:16 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:16 volumio volumio[17922]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 06 02:59:16 volumio volumio[17922]: info: Cannot mount NAS NAS at system boot, trial number 4 ,retrying in 5 seconds Nov 06 02:59:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 130. Nov 06 02:59:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:18 volumio go-librespot[18257]: go-librespot daemon starting... Nov 06 02:59:18 volumio go-librespot[18258]: time="2025-11-06T02:59:18Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:18 volumio go-librespot[18258]: time="2025-11-06T02:59:18Z" level=debug msg="app state loaded" Nov 06 02:59:18 volumio go-librespot[18258]: time="2025-11-06T02:59:18Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:18 volumio go-librespot[18258]: time="2025-11-06T02:59: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-gew4.spotify.com:80]" Nov 06 02:59:18 volumio go-librespot[18258]: time="2025-11-06T02:59:18Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 06 02:59:18 volumio go-librespot[18258]: time="2025-11-06T02:59:18Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 06 02:59:18 volumio go-librespot[18258]: time="2025-11-06T02:59:18Z" level=info msg="zeroconf server listening on port 39619" Nov 06 02:59:18 volumio go-librespot[18258]: time="2025-11-06T02:59:18Z" level=debug msg="obtained new client token: AACTKVBzDxyfoXqLSwoyIg9V2ZKWTpOQeoLy2ESsXN3Yr3ak8IyiDNaDkH7ELt5kitkdIg7NdM5DZ08Xb9CTyIKByYqXNOo+nMgY1zUFf2qi/QCuRLUFewRXLbkUZffXEY2WBnbPpx5LLPrc29LuetYyjtmbXR8L9zHhNBDnzrq6rPuXb4YsRwTI0JSHuu0hfsdSmHIl9y99k+wR7VoGNlXxUrfH1TwNizc1BxuUhOlKH/JR3JG1" Nov 06 02:59:18 volumio go-librespot[18258]: time="2025-11-06T02:59:18Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 02:59:18 volumio go-librespot[18258]: time="2025-11-06T02:59:18Z" level=debug msg="completed keyexchange" Nov 06 02:59:18 volumio go-librespot[18258]: time="2025-11-06T02:59:18Z" level=debug msg="completed challenge" Nov 06 02:59:18 volumio go-librespot[18258]: time="2025-11-06T02:59:18Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:19 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:19 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:19 volumio volumio[17922]: info: MYVOLUMIO: Adding device Nov 06 02:59:19 volumio volumio[17922]: info: MYVOLUMIO: Evaluating Server Nov 06 02:59:20 volumio volumio[17922]: info: CoreCommandRouter::volumioGetState Nov 06 02:59:20 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 02:59:20 volumio volumio[17922]: info: Setting Geolocation for MyVolumio to eu3 Nov 06 02:59:20 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:20 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:20 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:20 volumio volumio[17922]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Nov 06 02:59:21 volumio volumio[17922]: info: Updating MyVolumio device info Nov 06 02:59:21 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:21 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:21 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 131. Nov 06 02:59:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:21 volumio go-librespot[18281]: go-librespot daemon starting... Nov 06 02:59:21 volumio go-librespot[18282]: time="2025-11-06T02:59:21Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:21 volumio go-librespot[18282]: time="2025-11-06T02:59:21Z" level=debug msg="app state loaded" Nov 06 02:59:21 volumio go-librespot[18282]: time="2025-11-06T02:59:21Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:21 volumio volumio[17922]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Nov 06 02:59:21 volumio go-librespot[18282]: time="2025-11-06T02:59:21Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 06 02:59:21 volumio go-librespot[18282]: time="2025-11-06T02:59:21Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 06 02:59:21 volumio go-librespot[18282]: time="2025-11-06T02:59:21Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 06 02:59:21 volumio go-librespot[18282]: time="2025-11-06T02:59:21Z" level=info msg="zeroconf server listening on port 43933" Nov 06 02:59:21 volumio go-librespot[18282]: time="2025-11-06T02:59:21Z" level=debug msg="obtained new client token: AACgilsbWMnKfVsm7MBfTut6a787ibpyweEH6Wx7z32kfrVJS9QybIU/OXr7DV6ubn47Yr39ftkm3cvNQ7gdMNtJtyzMA/XFnD62NZnlUWKMoxU0JMd0VTs6fWK4c0D0obEzGYnqZOY3jbX/o+W186uaNYo89YGVziFeGnVuTt5y4AxNunizEVr/kLR5Ie4p/kIv9I7ZUaDATokZFgp9BtD3+go+2Gk6MVW+ct9khNV6d9DWBrc7foM=" Nov 06 02:59:21 volumio go-librespot[18282]: time="2025-11-06T02:59:21Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 02:59:21 volumio go-librespot[18282]: time="2025-11-06T02:59:21Z" level=debug msg="completed keyexchange" Nov 06 02:59:21 volumio go-librespot[18282]: time="2025-11-06T02:59:21Z" level=debug msg="completed challenge" Nov 06 02:59:21 volumio volumio[17922]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Nov 06 02:59:21 volumio go-librespot[18282]: time="2025-11-06T02:59:21Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:22 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:22 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 132. Nov 06 02:59:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:25 volumio go-librespot[18303]: go-librespot daemon starting... Nov 06 02:59:25 volumio go-librespot[18304]: time="2025-11-06T02:59:25Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:25 volumio go-librespot[18304]: time="2025-11-06T02:59:25Z" level=debug msg="app state loaded" Nov 06 02:59:25 volumio go-librespot[18304]: time="2025-11-06T02:59:25Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:25 volumio go-librespot[18304]: time="2025-11-06T02:59: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]" Nov 06 02:59:25 volumio go-librespot[18304]: time="2025-11-06T02:59: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]" Nov 06 02:59:25 volumio go-librespot[18304]: time="2025-11-06T02:59: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]" Nov 06 02:59:25 volumio go-librespot[18304]: time="2025-11-06T02:59:25Z" level=info msg="zeroconf server listening on port 43627" Nov 06 02:59:25 volumio go-librespot[18304]: time="2025-11-06T02:59:25Z" level=debug msg="obtained new client token: AABB6oCuOCgGyjE5Ir8Y+UoBSgzStvGprovk320YB1UgDKYOmyraDBdfcdXhW4dDkIicLQtsqjrdu0ZW0LWmJNhszq0hPF1V7hJzAyE7vuyA/W68SHZrK2gzeE6sVC/cgUCbeJHwkQCJcd/aWD/dkIVIvhSOggJBFT1foOG7XrJCwg35cTl1BAZTS2L3e6Z/0HCE8KPGEHT/q6votJ9uECWSgsGYmzj+63vtCPdn5wHFHchwkU0X" Nov 06 02:59:25 volumio go-librespot[18304]: time="2025-11-06T02:59:25Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 02:59:25 volumio go-librespot[18304]: time="2025-11-06T02:59:25Z" level=debug msg="completed keyexchange" Nov 06 02:59:25 volumio go-librespot[18304]: time="2025-11-06T02:59:25Z" level=debug msg="completed challenge" Nov 06 02:59:25 volumio go-librespot[18304]: time="2025-11-06T02:59:25Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:25 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:25 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:28 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 06 02:59:28 volumio volumio[17922]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Nov 06 02:59:28 volumio volumio[17922]: info: CoreCommandRouter::volumioGetState Nov 06 02:59:28 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 02:59:28 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:28 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 133. Nov 06 02:59:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:28 volumio go-librespot[18314]: go-librespot daemon starting... Nov 06 02:59:28 volumio go-librespot[18315]: time="2025-11-06T02:59:28Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:28 volumio go-librespot[18315]: time="2025-11-06T02:59:28Z" level=debug msg="app state loaded" Nov 06 02:59:28 volumio go-librespot[18315]: time="2025-11-06T02:59:28Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:28 volumio go-librespot[18315]: time="2025-11-06T02:59:28Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 02:59:28 volumio go-librespot[18315]: time="2025-11-06T02:59:28Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 02:59:28 volumio go-librespot[18315]: time="2025-11-06T02:59:28Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 02:59:28 volumio go-librespot[18315]: time="2025-11-06T02:59:28Z" level=info msg="zeroconf server listening on port 44157" Nov 06 02:59:28 volumio go-librespot[18315]: time="2025-11-06T02:59:28Z" level=debug msg="obtained new client token: AACf1H+zk+qPrVGEAstLx5vd0y7DrKxoyY76VBJ5EvdHF2bQF4R851zUtxy4+gynu96O9yRokMVsWBCozNt//UwlCLHwvdpg4rGUpRdSz31za4dBprWyqCrvQkRpAEK7FY5a7MIpTyhylzYBnrMyTCmLq2wUqa4s6Vib3gurJyfSsv7ZVHevdsFSPD6ibf0WUqaFbMh2AZVO0wXPwc4zRKFxoXmvnliMHCQNW4XYDN5kaKN5SPXJDp0=" Nov 06 02:59:28 volumio go-librespot[18315]: time="2025-11-06T02:59:28Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 02:59:28 volumio go-librespot[18315]: time="2025-11-06T02:59:28Z" level=debug msg="completed keyexchange" Nov 06 02:59:28 volumio go-librespot[18315]: time="2025-11-06T02:59:28Z" level=debug msg="completed challenge" Nov 06 02:59:28 volumio go-librespot[18315]: time="2025-11-06T02:59:28Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:30 volumio volumio[17922]: info: CoreCommandRouter::volumioGetState Nov 06 02:59:30 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 02:59:30 volumio volumio[17922]: info: Listing playlists Nov 06 02:59:30 volumio volumio[17922]: info: Listing playlists Nov 06 02:59:30 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 06 02:59:30 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 06 02:59:31 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:31 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 134. Nov 06 02:59:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:32 volumio go-librespot[18336]: go-librespot daemon starting... Nov 06 02:59:32 volumio go-librespot[18337]: time="2025-11-06T02:59:32Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:32 volumio go-librespot[18337]: time="2025-11-06T02:59:32Z" level=debug msg="app state loaded" Nov 06 02:59:32 volumio go-librespot[18337]: time="2025-11-06T02:59:32Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:32 volumio go-librespot[18337]: time="2025-11-06T02:59: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-gew4.spotify.com:80]" Nov 06 02:59:32 volumio go-librespot[18337]: time="2025-11-06T02:59:32Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 06 02:59:32 volumio go-librespot[18337]: time="2025-11-06T02:59:32Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 06 02:59:32 volumio go-librespot[18337]: time="2025-11-06T02:59:32Z" level=info msg="zeroconf server listening on port 42443" Nov 06 02:59:32 volumio go-librespot[18337]: time="2025-11-06T02:59:32Z" level=debug msg="obtained new client token: AAACJGing6GQgTmdXsmd3NAZW66BNI2+TB1MBHaTto157K52uIFBFyGRuf36NmKFUAtl7VR054o/xIvT+sodCu70R6xfvskjzNEqXQM969HEmFckaxPHbslv8M8vC9cyYdlDswhMJ8YRkarYzvYjcaMvbmdUXB6eApY1FUOvJdrWuh+EMfo5Ki36g74ALhAk3URLOYUMDpFgPpDm+wswsNnuy8KuH72TIQrjDuASqGLeEqVSTk2W" Nov 06 02:59:32 volumio go-librespot[18337]: time="2025-11-06T02:59: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" Nov 06 02:59:32 volumio go-librespot[18337]: time="2025-11-06T02:59:32Z" level=debug msg="connected to ap-gew1.spotify.com:443" Nov 06 02:59:32 volumio go-librespot[18337]: time="2025-11-06T02:59:32Z" level=debug msg="completed keyexchange" Nov 06 02:59:32 volumio go-librespot[18337]: time="2025-11-06T02:59:32Z" level=debug msg="completed challenge" Nov 06 02:59:32 volumio go-librespot[18337]: time="2025-11-06T02:59:32Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::volumioGetBrowseSources Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 06 02:59:33 volumio volumio[17922]: error: MyVolumio Plugin failed to authenticate in a timely fashion Nov 06 02:59:33 volumio volumio[17922]: info: Completed starting MyVolumio Plugin Nov 06 02:59:33 volumio volumio[17922]: [Metrics] CommandRouter: 32s 57.94ms Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::volumiosetStartupVolume Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::Close All Modals sent Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::Close All Modals sent Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 06 02:59:33 volumio volumio-remote-updater[874]: Test mode disabled Nov 06 02:59:33 volumio volumio-remote-updater[874]: Alpha mode disabled Nov 06 02:59:33 volumio volumio-remote-updater[874]: Alpha legacy test mode disabled Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Nov 06 02:59:33 volumio volumio[17922]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 06 02:59:33 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 06 02:59:34 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 06 02:59:34 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 06 02:59:34 volumio volumio[17922]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 06 02:59:34 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:34 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 135. Nov 06 02:59:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:35 volumio go-librespot[18353]: go-librespot daemon starting... Nov 06 02:59:35 volumio go-librespot[18354]: time="2025-11-06T02:59:35Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:35 volumio go-librespot[18354]: time="2025-11-06T02:59:35Z" level=debug msg="app state loaded" Nov 06 02:59:35 volumio go-librespot[18354]: time="2025-11-06T02:59:35Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:35 volumio go-librespot[18354]: time="2025-11-06T02:59:35Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 02:59:35 volumio go-librespot[18354]: time="2025-11-06T02:59:35Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 02:59:35 volumio go-librespot[18354]: time="2025-11-06T02:59:35Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 02:59:35 volumio go-librespot[18354]: time="2025-11-06T02:59:35Z" level=info msg="zeroconf server listening on port 38661" Nov 06 02:59:35 volumio go-librespot[18354]: time="2025-11-06T02:59:35Z" level=debug msg="obtained new client token: AAAye59miHSY5E2SPJw1NM6U1tNmEk1ftR330D1dD5gnL0pnpouzDxNuv3EXDM/EzIHAzkJ5moucfcUUZuUH6u1868An/juVYF/JlCNQ0QV5jAcUjiDNG/6U4Nj9/xSeyeyeEh8p42gWjZgY3UC7hDEiSNFi/FYdNlPEJvlb2RkvTfmhdPWTXZEqGyWE1MLO8dpy97L1FBxpiAFf2WNxm5WgCiuRR7hQu0zVUOB6DanvxUuQnKBw/iY=" Nov 06 02:59:35 volumio go-librespot[18354]: time="2025-11-06T02:59:35Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 02:59:35 volumio go-librespot[18354]: time="2025-11-06T02:59:35Z" level=debug msg="completed keyexchange" Nov 06 02:59:35 volumio go-librespot[18354]: time="2025-11-06T02:59:35Z" level=debug msg="completed challenge" Nov 06 02:59:35 volumio go-librespot[18354]: time="2025-11-06T02:59:35Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:37 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:37 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 136. Nov 06 02:59:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:39 volumio go-librespot[18361]: go-librespot daemon starting... Nov 06 02:59:39 volumio go-librespot[18362]: time="2025-11-06T02:59:39Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:39 volumio go-librespot[18362]: time="2025-11-06T02:59:39Z" level=debug msg="app state loaded" Nov 06 02:59:39 volumio go-librespot[18362]: time="2025-11-06T02:59:39Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:39 volumio go-librespot[18362]: time="2025-11-06T02:59:39Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 02:59:39 volumio go-librespot[18362]: time="2025-11-06T02:59:39Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 02:59:39 volumio go-librespot[18362]: time="2025-11-06T02:59:39Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 02:59:39 volumio go-librespot[18362]: time="2025-11-06T02:59:39Z" level=info msg="zeroconf server listening on port 46131" Nov 06 02:59:39 volumio go-librespot[18362]: time="2025-11-06T02:59:39Z" level=debug msg="obtained new client token: AAAZqKIVQKMegyglFN3ISo/YWx5+vyrX22a+CuyIL6BdssBlf45KzUjCCa8P3/VyZooWi1OLK4/UvsQFqMKH90z2Wg/fD9X507z8CCRAE6/BswAfqfimmLwWrde6rblAs+5Oldnw4tfmn0xl0h4M/Ne/eiWiu1AaS7bXwI3yQDoNvSae/9b3BCV9YifLK7XIyCIFLJHC+BNEFB30Wrq7brHBA8z+7cAF1b6pVw8CtE6XgYRFV2hM" Nov 06 02:59:39 volumio go-librespot[18362]: time="2025-11-06T02:59:39Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 02:59:39 volumio go-librespot[18362]: time="2025-11-06T02:59:39Z" level=debug msg="completed keyexchange" Nov 06 02:59:39 volumio go-librespot[18362]: time="2025-11-06T02:59:39Z" level=debug msg="completed challenge" Nov 06 02:59:39 volumio go-librespot[18362]: time="2025-11-06T02:59:39Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:40 volumio volumio[17922]: info: CoreCommandRouter::volumioGetState Nov 06 02:59:40 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 02:59:40 volumio volumio[17922]: info: BOOT COMPLETED Nov 06 02:59:40 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:40 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:40 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 06 02:59:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 137. Nov 06 02:59:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:42 volumio go-librespot[18384]: go-librespot daemon starting... Nov 06 02:59:42 volumio go-librespot[18385]: time="2025-11-06T02:59:42Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:42 volumio go-librespot[18385]: time="2025-11-06T02:59:42Z" level=debug msg="app state loaded" Nov 06 02:59:42 volumio go-librespot[18385]: time="2025-11-06T02:59:42Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:42 volumio go-librespot[18385]: time="2025-11-06T02:59:42Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 02:59:42 volumio go-librespot[18385]: time="2025-11-06T02:59:42Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 02:59:42 volumio go-librespot[18385]: time="2025-11-06T02:59:42Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 02:59:42 volumio go-librespot[18385]: time="2025-11-06T02:59:42Z" level=info msg="zeroconf server listening on port 34661" Nov 06 02:59:42 volumio go-librespot[18385]: time="2025-11-06T02:59:42Z" level=debug msg="obtained new client token: AAA0sQUul5kUyRZSr6s9PvC3TQ39yQl8/LXkCdkV8oJH3JgpnLQhHyx1nRDQUJkRMdwLyS93VTHyJUB4AF2VPLD9LEUP0G7xa1jWeIWUuqRSEhEp7z03hUd/Zf/ZOiGSrAMVnddQBZ3SSZ1m7dxYvldQBCRmGfKterDt0Oa7r0Q3IjrF53D3kPaciZ3a0ndnQsBZNF3vm+SsOUYsfMLB/mpHaXm4RMeaqwANRgkWAlFMXviRgs2nIKw=" Nov 06 02:59:42 volumio go-librespot[18385]: time="2025-11-06T02:59:42Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 02:59:42 volumio go-librespot[18385]: time="2025-11-06T02:59:42Z" level=debug msg="completed keyexchange" Nov 06 02:59:42 volumio go-librespot[18385]: time="2025-11-06T02:59:42Z" level=debug msg="completed challenge" Nov 06 02:59:42 volumio go-librespot[18385]: time="2025-11-06T02:59:42Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:43 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:43 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 138. Nov 06 02:59:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:46 volumio go-librespot[18392]: go-librespot daemon starting... Nov 06 02:59:46 volumio go-librespot[18393]: time="2025-11-06T02:59:46Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:46 volumio go-librespot[18393]: time="2025-11-06T02:59:46Z" level=debug msg="app state loaded" Nov 06 02:59:46 volumio go-librespot[18393]: time="2025-11-06T02:59:46Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:46 volumio go-librespot[18393]: time="2025-11-06T02:59: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]" Nov 06 02:59:46 volumio go-librespot[18393]: time="2025-11-06T02:59: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]" Nov 06 02:59:46 volumio go-librespot[18393]: time="2025-11-06T02:59: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]" Nov 06 02:59:46 volumio go-librespot[18393]: time="2025-11-06T02:59:46Z" level=info msg="zeroconf server listening on port 32963" Nov 06 02:59:46 volumio go-librespot[18393]: time="2025-11-06T02:59:46Z" level=debug msg="obtained new client token: AAAQ/Qr2QHJOkLToc9z7iFVUq9RLlwGPypExfJC3uZfOS4x5cyAt41EG4W6q0NGagwlas5c33zOAOoH6IBUAkAHu30zwoweSsz6rj1Q/Y04jzlappR4zYOl6UW3yuWqs4fe1kVbNJtNCcEN6RfYp/LdTaB7ODWCc+uBnNl7Kc7bqIGfec0wr3QQVxQjddA4Qw/dUFpbMJoF9vhghz0jyBCDnXdIOdAaXQjwlF/pS3+29G1G49VyW" Nov 06 02:59:46 volumio go-librespot[18393]: time="2025-11-06T02:59:46Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 02:59:46 volumio go-librespot[18393]: time="2025-11-06T02:59:46Z" level=debug msg="completed keyexchange" Nov 06 02:59:46 volumio go-librespot[18393]: time="2025-11-06T02:59:46Z" level=debug msg="completed challenge" Nov 06 02:59:46 volumio go-librespot[18393]: time="2025-11-06T02:59:46Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:46 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:46 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:49 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:49 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 139. Nov 06 02:59:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:49 volumio go-librespot[18403]: go-librespot daemon starting... Nov 06 02:59:49 volumio go-librespot[18404]: time="2025-11-06T02:59:49Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:49 volumio go-librespot[18404]: time="2025-11-06T02:59:49Z" level=debug msg="app state loaded" Nov 06 02:59:49 volumio go-librespot[18404]: time="2025-11-06T02:59:49Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:49 volumio go-librespot[18404]: time="2025-11-06T02:59:49Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 02:59:49 volumio go-librespot[18404]: time="2025-11-06T02:59:49Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 02:59:49 volumio go-librespot[18404]: time="2025-11-06T02:59:49Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 02:59:49 volumio go-librespot[18404]: time="2025-11-06T02:59:49Z" level=info msg="zeroconf server listening on port 44203" Nov 06 02:59:49 volumio go-librespot[18404]: time="2025-11-06T02:59:49Z" level=debug msg="obtained new client token: AADv85IWxm4qp2RqqwNvIYkU5xP5LeCr55QS/Ub3ti8xxVIHo2DBbVUKDUpkO1noaCvsuVrbj7fe1ri/YVI5u7aYzuWb8OsCDdAdSBZvbRKyZtruj8XBGBA/3nZM0LMRaF/dQZlwMdh0FGccJUzjpGCFIfDccS7QviST45EfigYUwvMgPOhcwHHvs7wYcdZWp1Ywln9RNWlt9foqNBj4tKOev2HONyMytHxU+00FrpAx75b4yYZp0lA=" Nov 06 02:59:49 volumio go-librespot[18404]: time="2025-11-06T02:59:49Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 02:59:49 volumio go-librespot[18404]: time="2025-11-06T02:59:49Z" level=debug msg="completed keyexchange" Nov 06 02:59:49 volumio go-librespot[18404]: time="2025-11-06T02:59:49Z" level=debug msg="completed challenge" Nov 06 02:59:49 volumio go-librespot[18404]: time="2025-11-06T02:59:49Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:50 volumio volumio[17922]: info: CoreCommandRouter::volumioGetState Nov 06 02:59:50 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 02:59:50 volumio volumio[17922]: info: Listing playlists Nov 06 02:59:50 volumio volumio[17922]: info: Listing playlists Nov 06 02:59:50 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 06 02:59:52 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:52 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 140. Nov 06 02:59:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:53 volumio go-librespot[18425]: go-librespot daemon starting... Nov 06 02:59:53 volumio go-librespot[18426]: time="2025-11-06T02:59:53Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:53 volumio go-librespot[18426]: time="2025-11-06T02:59:53Z" level=debug msg="app state loaded" Nov 06 02:59:53 volumio go-librespot[18426]: time="2025-11-06T02:59:53Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:53 volumio go-librespot[18426]: time="2025-11-06T02:59:53Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 02:59:53 volumio go-librespot[18426]: time="2025-11-06T02:59:53Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 02:59:53 volumio go-librespot[18426]: time="2025-11-06T02:59:53Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 02:59:53 volumio go-librespot[18426]: time="2025-11-06T02:59:53Z" level=info msg="zeroconf server listening on port 38815" Nov 06 02:59:53 volumio go-librespot[18426]: time="2025-11-06T02:59:53Z" level=debug msg="obtained new client token: AAB4d5YNBQUF1SB11OF4s4zPxMckxnhaWJ/B3Rat0BpNcG+HDsMpft19EMZmA5eDctFTxhrsrtRAOduWYSdW9WiwyTeeQ9BALIPh8S171xwnv6ZBFv6CZ25tF2dkA07YQE3ZnKAXUobO/m386htdvIwgGZ9DMwPvXsLRPG0UhpqDpcnq7ApV9uIdDo0649QwDwX2E55xByBnHo36MamLEZt08rRDTciKSMqQ/5Ov7PHke6btZYW0" Nov 06 02:59:53 volumio go-librespot[18426]: time="2025-11-06T02:59:53Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 02:59:53 volumio go-librespot[18426]: time="2025-11-06T02:59:53Z" level=debug msg="completed keyexchange" Nov 06 02:59:53 volumio go-librespot[18426]: time="2025-11-06T02:59:53Z" level=debug msg="completed challenge" Nov 06 02:59:53 volumio go-librespot[18426]: time="2025-11-06T02:59:53Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:55 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:55 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 141. Nov 06 02:59:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 02:59:56 volumio go-librespot[18433]: go-librespot daemon starting... Nov 06 02:59:56 volumio go-librespot[18434]: time="2025-11-06T02:59:56Z" level=info msg="running go-librespot 0.4.0" Nov 06 02:59:56 volumio go-librespot[18434]: time="2025-11-06T02:59:56Z" level=debug msg="app state loaded" Nov 06 02:59:56 volumio go-librespot[18434]: time="2025-11-06T02:59:56Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 02:59:56 volumio go-librespot[18434]: time="2025-11-06T02:59:56Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 02:59:56 volumio go-librespot[18434]: time="2025-11-06T02:59:56Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 02:59:56 volumio go-librespot[18434]: time="2025-11-06T02:59:56Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 02:59:56 volumio go-librespot[18434]: time="2025-11-06T02:59:56Z" level=info msg="zeroconf server listening on port 45587" Nov 06 02:59:56 volumio go-librespot[18434]: time="2025-11-06T02:59:56Z" level=debug msg="obtained new client token: AAANqzqnLBNlw8DSjqVsJWXQQ5CUWJ/Q4NRrN4ky1FlJ6FqTLJEN/DxB7MfE+PbCNzOcI1OGrmym1tFmsOyZIYZjWhlHv7kRY5EyO2pQzYBgi0v0LNf/XK6pvOSyI7YEJpxziYQlnawoVze2Me7PcrgdSf0T5oPk9kdAFJGid4QTqzi6AsiKgitZf3UCCK7I+zOF75OQJcwFrcxEw1U6YNJZDsKn5jOg29GRebdMS2J9qZQIiRT/kbA=" Nov 06 02:59:56 volumio go-librespot[18434]: time="2025-11-06T02:59:56Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 02:59:56 volumio go-librespot[18434]: time="2025-11-06T02:59:56Z" level=debug msg="completed keyexchange" Nov 06 02:59:56 volumio go-librespot[18434]: time="2025-11-06T02:59:56Z" level=debug msg="completed challenge" Nov 06 02:59:56 volumio go-librespot[18434]: time="2025-11-06T02:59:56Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 02:59:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 02:59:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 02:59:58 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 02:59:58 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 02:59:59 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 06 03:00:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 142. Nov 06 03:00:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:00 volumio go-librespot[18443]: go-librespot daemon starting... Nov 06 03:00:00 volumio go-librespot[18444]: time="2025-11-06T03:00:00Z" level=info msg="running go-librespot 0.4.0" Nov 06 03:00:00 volumio go-librespot[18444]: time="2025-11-06T03:00:00Z" level=debug msg="app state loaded" Nov 06 03:00:00 volumio go-librespot[18444]: time="2025-11-06T03:00:00Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 03:00:00 volumio go-librespot[18444]: time="2025-11-06T03:00:00Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 06 03:00:00 volumio go-librespot[18444]: time="2025-11-06T03:00:00Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 06 03:00:00 volumio go-librespot[18444]: time="2025-11-06T03:00:00Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 06 03:00:00 volumio go-librespot[18444]: time="2025-11-06T03:00:00Z" level=info msg="zeroconf server listening on port 44017" Nov 06 03:00:00 volumio go-librespot[18444]: time="2025-11-06T03:00:00Z" level=debug msg="obtained new client token: AACil3FunvrKHvLFKHmROOYCNpsZ7OI60f6TupbT1KIoj80xmlVe2q+qXWwZI81zq9ltpsme1qvUVT64pB1LMxVsJwJKULDdDfphMeD82Lrklo7pLqIhvzBxkfq4ne70mtxidODt6Bbkatj1CCNzIAcH/JoXcuRKiezAo1ifQTbVIDssajQZCaY9vCChwFi/RUT0sV5n6NeRDeMfQsSf5Ex+5dFEEBvdKYwaHNTDRmpW74uE4Sho" Nov 06 03:00:00 volumio go-librespot[18444]: time="2025-11-06T03:00:00Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 03:00:00 volumio volumio[17922]: info: CoreCommandRouter::volumioGetState Nov 06 03:00:00 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 03:00:00 volumio go-librespot[18444]: time="2025-11-06T03:00:00Z" level=debug msg="completed keyexchange" Nov 06 03:00:00 volumio go-librespot[18444]: time="2025-11-06T03:00:00Z" level=debug msg="completed challenge" Nov 06 03:00:00 volumio go-librespot[18444]: time="2025-11-06T03:00:00Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 03:00:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 03:00:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 03:00:01 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 03:00:01 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 03:00:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 143. Nov 06 03:00:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:03 volumio go-librespot[18466]: go-librespot daemon starting... Nov 06 03:00:03 volumio go-librespot[18467]: time="2025-11-06T03:00:03Z" level=info msg="running go-librespot 0.4.0" Nov 06 03:00:03 volumio go-librespot[18467]: time="2025-11-06T03:00:03Z" level=debug msg="app state loaded" Nov 06 03:00:03 volumio go-librespot[18467]: time="2025-11-06T03:00:03Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 03:00:03 volumio go-librespot[18467]: time="2025-11-06T03:00:03Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 03:00:03 volumio go-librespot[18467]: time="2025-11-06T03:00:03Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 03:00:03 volumio go-librespot[18467]: time="2025-11-06T03:00:03Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 03:00:03 volumio go-librespot[18467]: time="2025-11-06T03:00:03Z" level=info msg="zeroconf server listening on port 35855" Nov 06 03:00:03 volumio go-librespot[18467]: time="2025-11-06T03:00:03Z" level=debug msg="obtained new client token: AACjITB6pTBYKHXJNIx3EYHEWSWJ3t1SYZ9RqDw8BQEhRuf1Q4KN+lFZ/voaKQHNKKPdXW5aUNmrIzHfIUsP9rpZfI+IaRURWj0gxLLckdF7F0sVsX4nj+CQkLU4SoD8IXJFoQahlN48meyCYIuGJCuLMD8vUWNjGd7N1HNVBDbLVL6JxGagf8Y2+4oLc65eK2SKmd2XMvqspBPmzCDNhmqzJ5QEdlZnt4Rd6ioAVJP9TB35aI9PIyc=" Nov 06 03:00:03 volumio go-librespot[18467]: time="2025-11-06T03:00:03Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 03:00:03 volumio go-librespot[18467]: time="2025-11-06T03:00:03Z" level=debug msg="completed keyexchange" Nov 06 03:00:03 volumio go-librespot[18467]: time="2025-11-06T03:00:03Z" level=debug msg="completed challenge" Nov 06 03:00:03 volumio go-librespot[18467]: time="2025-11-06T03:00:03Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 03:00:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 03:00:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 03:00:04 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 03:00:04 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 03:00:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 144. Nov 06 03:00:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:07 volumio go-librespot[18475]: go-librespot daemon starting... Nov 06 03:00:07 volumio go-librespot[18476]: time="2025-11-06T03:00:07Z" level=info msg="running go-librespot 0.4.0" Nov 06 03:00:07 volumio go-librespot[18476]: time="2025-11-06T03:00:07Z" level=debug msg="app state loaded" Nov 06 03:00:07 volumio go-librespot[18476]: time="2025-11-06T03:00:07Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 03:00:07 volumio go-librespot[18476]: time="2025-11-06T03:00:07Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 03:00:07 volumio go-librespot[18476]: time="2025-11-06T03:00:07Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 03:00:07 volumio go-librespot[18476]: time="2025-11-06T03:00:07Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 03:00:07 volumio go-librespot[18476]: time="2025-11-06T03:00:07Z" level=info msg="zeroconf server listening on port 43223" Nov 06 03:00:07 volumio go-librespot[18476]: time="2025-11-06T03:00:07Z" level=debug msg="obtained new client token: AABKPr3EWl8QMYF9cbXIbzW3h//gtQHrFLFPMTI/5aB0PglAVLupCOfOI9MIlp7MIe1qwQ5gDNr0WoxNiy/qDjMeeghTBkrCLefaQC1WpcTI+1+ZoWMVXmmeBBBOBmKpV44xW1DdkbsSUwGsbeQ4seTOWTFmI8Qr3O4WcgLkweXwIFJPYVDLW3vNd/59JZM4DR5vUbPV3HxB3hdiYyGswARVGHeOJng9b7PWWSBt+CP64Kj8MSI4" Nov 06 03:00:07 volumio go-librespot[18476]: time="2025-11-06T03:00:07Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 03:00:07 volumio go-librespot[18476]: time="2025-11-06T03:00:07Z" level=debug msg="completed keyexchange" Nov 06 03:00:07 volumio go-librespot[18476]: time="2025-11-06T03:00:07Z" level=debug msg="completed challenge" Nov 06 03:00:07 volumio go-librespot[18476]: time="2025-11-06T03:00:07Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 03:00:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 03:00:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 03:00:07 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 03:00:07 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 03:00:10 volumio volumio[17922]: info: CoreCommandRouter::volumioGetState Nov 06 03:00:10 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 03:00:10 volumio volumio[17922]: info: Listing playlists Nov 06 03:00:10 volumio volumio[17922]: info: Listing playlists Nov 06 03:00:10 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 03:00:10 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 03:00:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 145. Nov 06 03:00:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:10 volumio go-librespot[18486]: go-librespot daemon starting... Nov 06 03:00:10 volumio go-librespot[18487]: time="2025-11-06T03:00:10Z" level=info msg="running go-librespot 0.4.0" Nov 06 03:00:10 volumio go-librespot[18487]: time="2025-11-06T03:00:10Z" level=debug msg="app state loaded" Nov 06 03:00:10 volumio go-librespot[18487]: time="2025-11-06T03:00:10Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 03:00:10 volumio go-librespot[18487]: time="2025-11-06T03:00:10Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 03:00:10 volumio go-librespot[18487]: time="2025-11-06T03:00:10Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 03:00:10 volumio go-librespot[18487]: time="2025-11-06T03:00:10Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 03:00:10 volumio go-librespot[18487]: time="2025-11-06T03:00:10Z" level=info msg="zeroconf server listening on port 34249" Nov 06 03:00:10 volumio go-librespot[18487]: time="2025-11-06T03:00:10Z" level=debug msg="obtained new client token: AACXtNFCPUeXm5NqoSQ4wKe8o2KW/BFQ8E6SrjWTO/5zpiHSmbkiPDIg7/B1dbxGdB8Jw6D0ihu7PE/+Og0jifYp/StJURPV67dCsGqF2tcfNPGxd864CRjeYzDLPNN+eXdmfcP4gkrJw4nONGas1+qgDUfExlp93/geGiM9WmDMV7fNvbSfB/mH2+ULVrlPCLzTqhSAyQJa1mzFYALO0d8PKrNCf08yBMLg0YdEhD7VB0g63du0VnY=" Nov 06 03:00:10 volumio go-librespot[18487]: time="2025-11-06T03:00:10Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 03:00:10 volumio go-librespot[18487]: time="2025-11-06T03:00:10Z" level=debug msg="completed keyexchange" Nov 06 03:00:10 volumio go-librespot[18487]: time="2025-11-06T03:00:10Z" level=debug msg="completed challenge" Nov 06 03:00:10 volumio go-librespot[18487]: time="2025-11-06T03:00:10Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 03:00:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 03:00:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 03:00:13 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 03:00:13 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 03:00:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 146. Nov 06 03:00:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:14 volumio go-librespot[18508]: go-librespot daemon starting... Nov 06 03:00:14 volumio go-librespot[18509]: time="2025-11-06T03:00:14Z" level=info msg="running go-librespot 0.4.0" Nov 06 03:00:14 volumio go-librespot[18509]: time="2025-11-06T03:00:14Z" level=debug msg="app state loaded" Nov 06 03:00:14 volumio go-librespot[18509]: time="2025-11-06T03:00:14Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 03:00:14 volumio go-librespot[18509]: time="2025-11-06T03:00:14Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 03:00:14 volumio go-librespot[18509]: time="2025-11-06T03:00:14Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 03:00:14 volumio go-librespot[18509]: time="2025-11-06T03:00:14Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 03:00:14 volumio go-librespot[18509]: time="2025-11-06T03:00:14Z" level=info msg="zeroconf server listening on port 46513" Nov 06 03:00:14 volumio go-librespot[18509]: time="2025-11-06T03:00:14Z" level=debug msg="obtained new client token: AAD9HYt0Sdf8SFUvAsS790GgQoIwO/f9f/CO+Jd4etqX0PIyyuDpGDhKnvHUSmakRrN0WzjlUTg5XiCdFCEoicPqlHrOIzwfMjt2PerH8TVV4Da3VJQauhvZk79ud1AxgAsTdPVRqauslUP8ajxgg7nxQzS7OLiAx6vCFGycNHg/QX1yhx4pfROM9t6F9+/fFZ38pidP8ifRPW5tpHZ7jVvk+VIP5vAu8WkmzpzsWsHl58wUVDyX" Nov 06 03:00:14 volumio go-librespot[18509]: time="2025-11-06T03:00:14Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 03:00:14 volumio go-librespot[18509]: time="2025-11-06T03:00:14Z" level=debug msg="completed keyexchange" Nov 06 03:00:14 volumio go-librespot[18509]: time="2025-11-06T03:00:14Z" level=debug msg="completed challenge" Nov 06 03:00:14 volumio go-librespot[18509]: time="2025-11-06T03:00:14Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 03:00:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 03:00:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 03:00:14 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 06 03:00:16 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 03:00:16 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 03:00:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 147. Nov 06 03:00:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:17 volumio go-librespot[18517]: go-librespot daemon starting... Nov 06 03:00:17 volumio go-librespot[18518]: time="2025-11-06T03:00:17Z" level=info msg="running go-librespot 0.4.0" Nov 06 03:00:17 volumio go-librespot[18518]: time="2025-11-06T03:00:17Z" level=debug msg="app state loaded" Nov 06 03:00:17 volumio go-librespot[18518]: time="2025-11-06T03:00:17Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 03:00:17 volumio go-librespot[18518]: time="2025-11-06T03:00:17Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 03:00:17 volumio go-librespot[18518]: time="2025-11-06T03:00:17Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 03:00:17 volumio go-librespot[18518]: time="2025-11-06T03:00:17Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 03:00:17 volumio go-librespot[18518]: time="2025-11-06T03:00:17Z" level=info msg="zeroconf server listening on port 35261" Nov 06 03:00:17 volumio go-librespot[18518]: time="2025-11-06T03:00:17Z" level=debug msg="obtained new client token: AAA1NKEX5QpzNdNk+DkYp3/c/AN5pvpJ2YIOxASjR1VIpOASQ6hGzw7bZ0oAVphgtWjtnXVbHwRP5bDyptuAfovezmW7Yas2MToAGieGTuvy29v/O8+JB0GBjfLhMp7ZjmJzP4UAFgLZN5bqP7diKI/WOdsHnIgTUR+30WbC0W1iR2h6JSyU0d59yTHA2BUJ+XdtNnpjHMy9miXob9j2YQAg8Ua0+sagdngV/lPMI4d23tpXI1Z6K30=" Nov 06 03:00:17 volumio go-librespot[18518]: time="2025-11-06T03:00:17Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 03:00:17 volumio go-librespot[18518]: time="2025-11-06T03:00:17Z" level=debug msg="completed keyexchange" Nov 06 03:00:17 volumio go-librespot[18518]: time="2025-11-06T03:00:17Z" level=debug msg="completed challenge" Nov 06 03:00:17 volumio go-librespot[18518]: time="2025-11-06T03:00:17Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 03:00:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 03:00:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 03:00:19 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 03:00:19 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 03:00:20 volumio volumio[17922]: info: CoreCommandRouter::volumioGetState Nov 06 03:00:20 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 03:00:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 148. Nov 06 03:00:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:21 volumio go-librespot[18526]: go-librespot daemon starting... Nov 06 03:00:21 volumio go-librespot[18527]: time="2025-11-06T03:00:21Z" level=info msg="running go-librespot 0.4.0" Nov 06 03:00:21 volumio go-librespot[18527]: time="2025-11-06T03:00:21Z" level=debug msg="app state loaded" Nov 06 03:00:21 volumio go-librespot[18527]: time="2025-11-06T03:00:21Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 03:00:21 volumio go-librespot[18527]: time="2025-11-06T03:00:21Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 03:00:21 volumio go-librespot[18527]: time="2025-11-06T03:00:21Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 03:00:21 volumio go-librespot[18527]: time="2025-11-06T03:00:21Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 03:00:21 volumio go-librespot[18527]: time="2025-11-06T03:00:21Z" level=info msg="zeroconf server listening on port 43327" Nov 06 03:00:21 volumio go-librespot[18527]: time="2025-11-06T03:00:21Z" level=debug msg="obtained new client token: AAB692dJ5Q0FxnvToa5ygpfgMb/G5vISPgSF/ba1Mf+ScHO31WRHjaSRMU5Vv4wvP22hj3reAQcRdX3xpJG0kn91RojYXRoTaa7BK8xBXFJ73d9YLEXiCoBuQ214n7rZLHnQqqaxuNkh5RVym1X9Ve1X4dCNbvoYFNBfFeySPwGYjovXtf7O9VyqGO/AOUGnVd3KZ3a1vPuUl+NuipozrIzIDnmVivgRVCGU2bAkXbWqTxPFg7og" Nov 06 03:00:21 volumio go-librespot[18527]: time="2025-11-06T03:00:21Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 03:00:21 volumio go-librespot[18527]: time="2025-11-06T03:00:21Z" level=debug msg="completed keyexchange" Nov 06 03:00:21 volumio go-librespot[18527]: time="2025-11-06T03:00:21Z" level=debug msg="completed challenge" Nov 06 03:00:21 volumio go-librespot[18527]: time="2025-11-06T03:00:21Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 03:00:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 03:00:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 03:00:22 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 03:00:22 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 03:00:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 149. Nov 06 03:00:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:24 volumio go-librespot[18548]: go-librespot daemon starting... Nov 06 03:00:24 volumio go-librespot[18549]: time="2025-11-06T03:00:24Z" level=info msg="running go-librespot 0.4.0" Nov 06 03:00:24 volumio go-librespot[18549]: time="2025-11-06T03:00:24Z" level=debug msg="app state loaded" Nov 06 03:00:24 volumio go-librespot[18549]: time="2025-11-06T03:00:24Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 03:00:24 volumio go-librespot[18549]: time="2025-11-06T03:00:24Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 06 03:00:24 volumio go-librespot[18549]: time="2025-11-06T03:00:24Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 06 03:00:24 volumio go-librespot[18549]: time="2025-11-06T03:00:24Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 06 03:00:24 volumio go-librespot[18549]: time="2025-11-06T03:00:24Z" level=info msg="zeroconf server listening on port 38547" Nov 06 03:00:24 volumio go-librespot[18549]: time="2025-11-06T03:00:24Z" level=debug msg="obtained new client token: AAClv7ShIlyJU6xA3riBRCMcFvmD948pFi9StlXhmEuC9odHFQAkKczRXvMKytu+jJlQtQV3hvsT/cQEVhwxKOqbUL9e8kCu1VPSr4PF6FNGSWlUpQO/2IKRrp/MNtTgYFA7l9gVRf/3gjHZzTaT+7sE+I3ADdjJE61DQysYFz3Fx/237iUQ3CY/bMmzrfS2p0H+yyXWThai8UGgEhxj869T7WExdktGSMpl6GTs3Hyo1dGJ810JgJI=" Nov 06 03:00:24 volumio go-librespot[18549]: time="2025-11-06T03:00:24Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.65.9:4070: connect: connection refused" Nov 06 03:00:24 volumio go-librespot[18549]: time="2025-11-06T03:00:24Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Nov 06 03:00:24 volumio go-librespot[18549]: time="2025-11-06T03:00:24Z" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.65.9:80: connect: connection refused" Nov 06 03:00:24 volumio go-librespot[18549]: time="2025-11-06T03:00:24Z" level=debug msg="connected to ap-guc3.spotify.com:4070" Nov 06 03:00:25 volumio go-librespot[18549]: time="2025-11-06T03:00:25Z" level=debug msg="completed keyexchange" Nov 06 03:00:25 volumio go-librespot[18549]: time="2025-11-06T03:00:25Z" level=debug msg="completed challenge" Nov 06 03:00:25 volumio go-librespot[18549]: time="2025-11-06T03:00:25Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 03:00:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 03:00:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 03:00:25 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 03:00:25 volumio volumio[17922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 03:00:26 volumio kernel: nfs: server 192.168.1.3 not responding, timed out Nov 06 03:00:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 150. Nov 06 03:00:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 06 03:00:28 volumio go-librespot[18559]: go-librespot daemon starting... Nov 06 03:00:28 volumio go-librespot[18560]: time="2025-11-06T03:00:28Z" level=info msg="running go-librespot 0.4.0" Nov 06 03:00:28 volumio go-librespot[18560]: time="2025-11-06T03:00:28Z" level=debug msg="app state loaded" Nov 06 03:00:28 volumio go-librespot[18560]: time="2025-11-06T03:00:28Z" level=info msg="api server listening on 127.0.0.1:9879" Nov 06 03:00:28 volumio go-librespot[18560]: time="2025-11-06T03:00:28Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 06 03:00:28 volumio go-librespot[18560]: time="2025-11-06T03:00:28Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 06 03:00:28 volumio go-librespot[18560]: time="2025-11-06T03:00:28Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 06 03:00:28 volumio go-librespot[18560]: time="2025-11-06T03:00:28Z" level=info msg="zeroconf server listening on port 42869" Nov 06 03:00:28 volumio go-librespot[18560]: time="2025-11-06T03:00:28Z" level=debug msg="obtained new client token: AACsjvMSDCmzT3riqmqe0cnw52pLjEidy5eM34IXp+inQfA6aPlymGzOkRaCYsYsVuYetgLoL0E8enCpnMwrIyqRavLDMSCBgj44XzzTMZsZxURgonRIy/NitirKghEeh+F8pcMkxdMR4QSNgJAKDMq8nID+ItXVjOrh2VwcspXBzzKjKQ/Sx4J70mCzwyMywdpsC0S0lB2HUvZmdYcvIn+USQ8WItkyxqQkuHKTtCPTxEMlXodwUGg=" Nov 06 03:00:28 volumio go-librespot[18560]: time="2025-11-06T03:00:28Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Nov 06 03:00:28 volumio go-librespot[18560]: time="2025-11-06T03:00:28Z" level=debug msg="completed keyexchange" Nov 06 03:00:28 volumio go-librespot[18560]: time="2025-11-06T03:00:28Z" level=debug msg="completed challenge" Nov 06 03:00:28 volumio volumio[17922]: info: Initializing connection to go-librespot Websocket Nov 06 03:00:28 volumio go-librespot[18560]: time="2025-11-06T03:00:28Z" level=debug msg="new websocket client" Nov 06 03:00:28 volumio volumio[17922]: info: Connection to go-librespot Websocket established Nov 06 03:00:28 volumio go-librespot[18560]: time="2025-11-06T03:00:28Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Nov 06 03:00:28 volumio volumio[17922]: info: Connection to go-librespot Websocket closed Nov 06 03:00:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 06 03:00:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 06 03:00:30 volumio volumio[17922]: info: CoreCommandRouter::volumioGetState Nov 06 03:00:30 volumio volumio[17922]: info: CorePlayQueue::getTrack 0 Nov 06 03:00:30 volumio volumio[17922]: info: Listing playlists Nov 06 03:00:30 volumio volumio[17922]: info: Listing playlists Nov 06 03:00:31 volumio volumio[17922]: info: Getting Spotify volume Nov 06 03:00:31 volumio volumio[17922]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 06 03:00:31 volumio volumio[17922]: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 06 03:00:31 volumio volumio[17922]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Nov 06 03:00:31 volumio volumio[17922]: errno: -111, Nov 06 03:00:31 volumio volumio[17922]: code: 'ECONNREFUSED', Nov 06 03:00:31 volumio volumio[17922]: syscall: 'connect', Nov 06 03:00:31 volumio volumio[17922]: address: '127.0.0.1', Nov 06 03:00:31 volumio volumio[17922]: port: 9879, Nov 06 03:00:31 volumio volumio[17922]: response: undefined Nov 06 03:00:31 volumio volumio[17922]: } Nov 06 03:00:31 volumio volumio[17922]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 06 03:00:31 volumio sudo[18581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-11-06 02:59' Nov 06 03:00:31 volumio sudo[18581]: 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"