Oct 27 13:26:20 volumio go-librespot[16558]: time="2025-10-27T13:26:20Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Oct 27 13:26:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:26:20 volumio volumio[16174]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Oct 27 13:26:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:26:20 volumio volumio[16174]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 27 13:26:20 volumio volumio[16174]: Error: socket hang up Oct 27 13:26:20 volumio volumio[16174]: at connResetException (node:internal/errors:720:14) Oct 27 13:26:20 volumio volumio[16174]: at Socket.socketOnEnd (node:_http_client:519:23) Oct 27 13:26:20 volumio volumio[16174]: at Socket.emit (node:events:526:35) Oct 27 13:26:20 volumio volumio[16174]: at endReadableNT (node:internal/streams/readable:1376:12) Oct 27 13:26:20 volumio volumio[16174]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Oct 27 13:26:20 volumio volumio[16174]: code: 'ECONNRESET', Oct 27 13:26:20 volumio volumio[16174]: response: undefined Oct 27 13:26:20 volumio volumio[16174]: } Oct 27 13:26:20 volumio volumio[16174]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 27 13:26:20 volumio sudo[17851]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-10-27 13:25' Oct 27 13:26:20 volumio sudo[17851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:20 volumio sudo[17851]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:20 volumio volumio-remote-updater[874]: [2025-10-27 13:26:20] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 27 13:26:20 volumio volumio-remote-updater[874]: [2025-10-27 13:26:20] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 27 13:26:20 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:26:20 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 27 13:26:20 volumio systemd[1]: volumio.service: Consumed 16.330s CPU time. Oct 27 13:26:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 27 13:26:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Oct 27 13:26:21 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 747. Oct 27 13:26:21 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Oct 27 13:26:21 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Oct 27 13:26:21 volumio systemd[1]: volumio.service: Consumed 16.330s CPU time. Oct 27 13:26:21 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Oct 27 13:26:21 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Oct 27 13:26:21 volumio volumio[17889]: info: ------------------------------------------- Oct 27 13:26:21 volumio volumio[17889]: info: ----- Volumio3 ---- Oct 27 13:26:21 volumio volumio[17889]: info: ------------------------------------------- Oct 27 13:26:21 volumio volumio[17889]: info: ----- System startup ---- Oct 27 13:26:21 volumio volumio[17889]: info: ------------------------------------------- Oct 27 13:26:22 volumio volumio[17889]: info: MYVOLUMIO Environment detected Oct 27 13:26:22 volumio volumio[17889]: info: Plugin folders cleanup Oct 27 13:26:22 volumio volumio[17889]: info: Scanning into folder /volumio/app/plugins/ Oct 27 13:26:22 volumio volumio[17889]: info: Scanning category audio_interface Oct 27 13:26:22 volumio volumio[17889]: info: Scanning category miscellanea Oct 27 13:26:22 volumio volumio[17889]: info: Scanning category music_service Oct 27 13:26:22 volumio volumio[17889]: info: Scanning category plugins.json Oct 27 13:26:22 volumio volumio[17889]: info: Scanning category system_controller Oct 27 13:26:22 volumio volumio[17889]: info: Scanning category user_interface Oct 27 13:26:22 volumio volumio[17889]: info: Scanning into folder /data/plugins/ Oct 27 13:26:22 volumio volumio[17889]: info: Scanning category music_service Oct 27 13:26:22 volumio volumio[17889]: info: Scanning category user_interface Oct 27 13:26:22 volumio volumio[17889]: info: Plugin folders cleanup completed Oct 27 13:26:22 volumio volumio[17889]: info: ------------------------------------------- Oct 27 13:26:22 volumio volumio[17889]: info: ----- Core plugins startup ---- Oct 27 13:26:22 volumio volumio[17889]: info: ------------------------------------------- Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugins from folder /volumio/app/plugins/ Oct 27 13:26:22 volumio volumio[17889]: info: Adding plugin upnp to MyMusic Plugins Oct 27 13:26:22 volumio volumio[17889]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 27 13:26:22 volumio volumio[17889]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugins from folder /data/plugins/ Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugin "system"... Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugin "appearance"... Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugin "network"... Oct 27 13:26:22 volumio volumio[17889]: info: Refreshing Cached IP Addresses Oct 27 13:26:22 volumio sudo[17917]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 27 13:26:22 volumio sudo[17917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:22 volumio sudo[17919]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugin "services"... Oct 27 13:26:22 volumio sudo[17919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugin "alsa_controller"... Oct 27 13:26:22 volumio sudo[17917]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:22 volumio sudo[17919]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:22 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugin "wizard"... Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugin "networkfs"... Oct 27 13:26:22 volumio volumio[17889]: info: Cannot mount NAS NAS at system boot, trial number 1 ,retrying in 5 seconds Oct 27 13:26:22 volumio volumio[17889]: info: Starting Udev Watcher for removable devices Oct 27 13:26:22 volumio volumio[17889]: info: Ignoring mount for partition: boot Oct 27 13:26:22 volumio volumio[17889]: info: Ignoring mount for partition: volumio Oct 27 13:26:22 volumio volumio[17889]: info: Ignoring mount for partition: volumio_data Oct 27 13:26:22 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugin "volumio_command_line_client"... Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugin "upnp"... Oct 27 13:26:22 volumio volumio[17889]: info: [1761571582428] Starting Upmpd Daemon Oct 27 13:26:22 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugin "my_music"... Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugin "mpd"... Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugin "upnp_browser"... Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugin "alarm-clock"... Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugin "airplay_emulation"... Oct 27 13:26:22 volumio volumio[17889]: info: Starting Shairport Sync Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugin "last_100"... Oct 27 13:26:22 volumio volumio[17889]: info: Loading plugin "webradio"... Oct 27 13:26:23 volumio volumio[17889]: info: Loading plugin "i2s_dacs"... Oct 27 13:26:23 volumio volumio[17889]: info: I2S DAC not set, start Auto-detection Oct 27 13:26:23 volumio volumio[17889]: info: Loading plugin "volumiodiscovery"... Oct 27 13:26:23 volumio volumio[17889]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 27 13:26:23 volumio volumio[17889]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 27 13:26:23 volumio volumio[17889]: *** WARNING *** For more information see Oct 27 13:26:23 volumio volumio[17889]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 27 13:26:23 volumio volumio[17889]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 27 13:26:23 volumio volumio[17889]: *** WARNING *** For more information see Oct 27 13:26:23 volumio node[17889]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 27 13:26:23 volumio node[17889]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 27 13:26:23 volumio node[17889]: *** WARNING *** For more information see Oct 27 13:26:23 volumio node[17889]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 27 13:26:23 volumio node[17889]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 27 13:26:23 volumio node[17889]: *** WARNING *** For more information see Oct 27 13:26:23 volumio volumio[17889]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 27 13:26:23 volumio volumio[17889]: info: Discovery: Started advertising with name: Volumio Oct 27 13:26:23 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 27 13:26:23 volumio volumio[17889]: info: Loading plugin "spop"... Oct 27 13:26:23 volumio volumio[17889]: info: Loading plugin "ytcr"... Oct 27 13:26:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 118. Oct 27 13:26:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:23 volumio go-librespot[17952]: go-librespot daemon starting... Oct 27 13:26:23 volumio go-librespot[17953]: time="2025-10-27T13:26:23Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:26:23 volumio go-librespot[17953]: time="2025-10-27T13:26:23Z" level=debug msg="app state loaded" Oct 27 13:26:23 volumio go-librespot[17953]: time="2025-10-27T13:26:23Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:26:23 volumio go-librespot[17953]: time="2025-10-27T13:26:23Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 13:26:23 volumio go-librespot[17953]: time="2025-10-27T13:26:23Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 27 13:26:23 volumio go-librespot[17953]: time="2025-10-27T13:26:23Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 27 13:26:23 volumio go-librespot[17953]: time="2025-10-27T13:26:23Z" level=info msg="zeroconf server listening on port 33227" Oct 27 13:26:23 volumio go-librespot[17953]: time="2025-10-27T13:26:23Z" level=debug msg="obtained new client token: AABiFUQhpeCFmwyEKsG9/RbOkAYcG0/2e9htA/K8RprxfWCZD955DgXr+m/sjwW2r40iC0HkAQksATx69Sk+EbhDUW6xwnTxRzIy41lMKSIkZU6BPaa1WvBw3FoJcpBTE2SUijhI6Rl61o77Q5YrN/e4yJqZams3Td6LWgEB4Ds6/2cPSksPxcChSIW6ErvPUMKaAXjOMqyUyVDeQWJ8rzUnPl3GvJAWlfwDDwHlCx/IuY73gT6HMh0=" Oct 27 13:26:24 volumio go-librespot[17953]: time="2025-10-27T13:26:24Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:26:24 volumio go-librespot[17953]: time="2025-10-27T13:26:24Z" level=debug msg="completed keyexchange" Oct 27 13:26:24 volumio go-librespot[17953]: time="2025-10-27T13:26:24Z" level=debug msg="completed challenge" Oct 27 13:26:24 volumio go-librespot[17953]: time="2025-10-27T13:26:24Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:26:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:26:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:26:24 volumio volumio[17889]: info: Loading plugin "outputs"... Oct 27 13:26:24 volumio volumio[17889]: info: Loading plugin "albumart"... Oct 27 13:26:24 volumio volumio[17889]: info: Plugin example_plugin is not enabled Oct 27 13:26:24 volumio volumio[17889]: info: Loading plugin "inputs"... Oct 27 13:26:24 volumio volumio[17889]: info: Loading plugin "updater_comm"... Oct 27 13:26:24 volumio volumio[17889]: info: Plugin mpdemulation is not enabled Oct 27 13:26:24 volumio volumio[17889]: info: Loading plugin "rest_api"... Oct 27 13:26:24 volumio volumio[17889]: info: Loading plugin "websocket"... Oct 27 13:26:24 volumio volumio[17889]: info: Starting Socket.io Server version 1.7.4 Oct 27 13:26:24 volumio volumio[17889]: info: Loading plugin "Systeminfo"... Oct 27 13:26:24 volumio volumio[17889]: info: Loading i18n strings for locale en Oct 27 13:26:24 volumio volumio[17889]: Updating browse sources language Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 27 13:26:24 volumio volumio[17960]: Forking 3 albumart workers Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::initPlayerControls Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 27 13:26:24 volumio volumio[17889]: Express server listening on port 3000 Oct 27 13:26:24 volumio volumio[17889]: [Metrics] WebUI: 2s 918.56ms Oct 27 13:26:24 volumio volumio[17889]: info: CoreStateMachine::resetVolumioState Oct 27 13:26:24 volumio volumio[17889]: info: CoreStateMachine::getcurrentVolume Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::volumioRetrievevolume Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:24 volumio volumio[17889]: info: Cannot read play queue from file Oct 27 13:26:24 volumio volumio[17889]: info: Volumio Network Manager: Network status updated: 1 Oct 27 13:26:24 volumio volumio[17889]: info: VolumeController:: Volume=33 Mute =false Oct 27 13:26:24 volumio volumio[17889]: info: CoreStateMachine::pushState Oct 27 13:26:24 volumio volumio[17889]: info: CorePlayQueue::getTrack 0 Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::volumioPushState Oct 27 13:26:24 volumio volumio[17889]: info: CoreStateMachine::updateTrackBlock Oct 27 13:26:24 volumio volumio[17889]: info: CorePlayQueue::getTrackBlock Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::volumioRetrievevolume Oct 27 13:26:24 volumio volumio[17889]: info: CoreStateMachine::setRepeat null single undefined Oct 27 13:26:24 volumio volumio[17889]: info: CoreStateMachine::pushState Oct 27 13:26:24 volumio volumio[17889]: info: CorePlayQueue::getTrack 0 Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::volumioPushState Oct 27 13:26:24 volumio volumio[17889]: info: CoreStateMachine::setRandom null Oct 27 13:26:24 volumio volumio[17889]: info: CoreStateMachine::pushState Oct 27 13:26:24 volumio volumio[17889]: info: CorePlayQueue::getTrack 0 Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::volumioPushState Oct 27 13:26:24 volumio volumio[17889]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 27 13:26:24 volumio volumio[17889]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b04170 Oct 27 13:26:24 volumio volumio[17889]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 27 13:26:24 volumio volumio[17889]: info: Setting Device type: Raspberry PI Oct 27 13:26:24 volumio volumio[17889]: info: VolumeController:: Volume=33 Mute =false Oct 27 13:26:24 volumio volumio[17889]: info: CoreStateMachine::pushState Oct 27 13:26:24 volumio volumio[17889]: info: CorePlayQueue::getTrack 0 Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::volumioPushState Oct 27 13:26:24 volumio volumio[17889]: info: Completed loading Core Plugins Oct 27 13:26:24 volumio volumio[17889]: info: Preparing to generate the ALSA configuration file Oct 27 13:26:24 volumio volumio[17889]: info: Asound.conf file unchanged, so no further update is needed Oct 27 13:26:24 volumio volumio[17889]: info: Output device has changed, restarting MPD Oct 27 13:26:24 volumio volumio[17889]: info: Output device has changed, restarting Shairport Sync Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:24 volumio sudo[18018]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 27 13:26:24 volumio sudo[18018]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:24 volumio sudo[18018]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:24 volumio sudo[18022]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 27 13:26:24 volumio sudo[18022]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:24 volumio volumio[17889]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 27 13:26:24 volumio volumio[17889]: info: ___________ START PLUGINS ___________ Oct 27 13:26:24 volumio volumio[17889]: info: ControllerMpd::onStart: Initializing MPD Oct 27 13:26:24 volumio volumio[17889]: info: Creating MPD Configuration file Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 27 13:26:24 volumio volumio[17889]: info: [1761571584863] CoreMusicLibrary::Adding element Media Servers Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 27 13:26:24 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Oct 27 13:26:24 volumio sudo[18030]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 27 13:26:24 volumio sudo[18029]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 27 13:26:24 volumio sudo[18029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:24 volumio sudo[18030]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:24 volumio sudo[18030]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:24 volumio volumio[17889]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:24 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 27 13:26:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 27 13:26:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Oct 27 13:26:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 27 13:26:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 27 13:26:24 volumio volumio[17889]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 27 13:26:24 volumio volumio[17889]: info: [1761571584913] CoreMusicLibrary::Adding element Last_100 Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 27 13:26:24 volumio volumio[17889]: info: [1761571584914] CoreMusicLibrary::Adding element Webradio Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 27 13:26:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 27 13:26:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 27 13:26:24 volumio systemd[1]: mpd.service: Deactivated successfully. Oct 27 13:26:24 volumio volumio[17889]: info: Initializing BBC Radios Oct 27 13:26:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Oct 27 13:26:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Oct 27 13:26:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Oct 27 13:26:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Oct 27 13:26:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Oct 27 13:26:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:24 volumio volumio[17889]: info: Creating Spotify config file Oct 27 13:26:24 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio sudo[18052]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 27 13:26:25 volumio sudo[18052]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Oct 27 13:26:25 volumio sudo[18052]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:25 volumio volumio[17970]: Starting albumart workers Oct 27 13:26:25 volumio volumio[17889]: info: Volumio Calling Home Oct 27 13:26:25 volumio volumio[17972]: Starting albumart workers Oct 27 13:26:25 volumio volumio[17971]: Starting albumart workers Oct 27 13:26:25 volumio volumio[17889]: info: Discovery: adding 70853f74-8210-4683-a3fa-e1217517bd40 Oct 27 13:26:25 volumio volumio[17889]: info: Discovery: Found device Volumio Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::volumioGetState Oct 27 13:26:25 volumio volumio[17889]: info: CorePlayQueue::getTrack 0 Oct 27 13:26:25 volumio volumio[17889]: info: Discovery: this is already registered, 70853f74-8210-4683-a3fa-e1217517bd40 Oct 27 13:26:25 volumio volumio[17889]: info: Discovery: Found device Volumio Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::volumioGetState Oct 27 13:26:25 volumio volumio[17889]: info: CorePlayQueue::getTrack 0 Oct 27 13:26:25 volumio volumio[17889]: info: MPD Permissions set Oct 27 13:26:25 volumio volumio[17889]: info: MPD Permissions set Oct 27 13:26:25 volumio volumio[17889]: info: Volumio called home Oct 27 13:26:25 volumio volumio[17889]: info: Spotify config file written Oct 27 13:26:25 volumio sudo[18064]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 27 13:26:25 volumio sudo[18064]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:25 volumio volumio[17889]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 27 13:26:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio go-librespot[18066]: go-librespot daemon starting... Oct 27 13:26:25 volumio sudo[18064]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio go-librespot[18067]: time="2025-10-27T13:26:25Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:26:25 volumio go-librespot[18067]: time="2025-10-27T13:26:25Z" level=debug msg="app state loaded" Oct 27 13:26:25 volumio go-librespot[18067]: time="2025-10-27T13:26:25Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:25 volumio volumio[17889]: info: No need to fix Spotify hosts Oct 27 13:26:25 volumio go-librespot[18067]: time="2025-10-27T13:26:25Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 27 13:26:25 volumio go-librespot[18067]: time="2025-10-27T13:26:25Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 27 13:26:25 volumio go-librespot[18067]: time="2025-10-27T13:26:25Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 27 13:26:25 volumio go-librespot[18067]: time="2025-10-27T13:26:25Z" level=info msg="zeroconf server listening on port 36555" Oct 27 13:26:25 volumio volumio[17889]: info: Starting Shairport Sync Oct 27 13:26:25 volumio volumio[17889]: info: Starting Shairport Sync Oct 27 13:26:25 volumio volumio[17889]: info: Starting Shairport Sync Oct 27 13:26:25 volumio sudo[18104]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 27 13:26:25 volumio sudo[18104]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:25 volumio sudo[18106]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 27 13:26:25 volumio sudo[18106]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:25 volumio sudo[18108]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 27 13:26:25 volumio sudo[18108]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:25 volumio go-librespot[18067]: time="2025-10-27T13:26:25Z" level=debug msg="obtained new client token: AADCKZgjUcMCWKuC1ftHAYC912nHIvJx9zLkiFKP9uU1GjJzqAUjRS8lwna/6mfLDo32zG9c/0rQREbd4uMxP25wVmfAwXLQFS84A/ab6TMw/c1/qx9S9AADYfiHKVO5zpEeIzjD6rca7BxGW5I28BwCFG2tbbXjRlmOKTxGbgxW7yZRJUxq3YP29C8c1uT2xDt8PLfYe9m9W4sf3hbSjZMtWvvf+7Vg0I3fJiSFT7I+qenMv6fDpcQ=" Oct 27 13:26:25 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Oct 27 13:26:25 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Oct 27 13:26:25 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 27 13:26:25 volumio systemd[1]: shairport-sync.service: Consumed 2.120s CPU time. Oct 27 13:26:25 volumio go-librespot[18067]: time="2025-10-27T13:26:25Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:26:25 volumio volumio[17889]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 27 13:26:25 volumio volumio[17889]: SPOTIFY: BQAXE1UEHS6ECHvXEzNV-QsNf7Da77hU_B9yWdFgQSjV8Y5GsMCgghkzKunq_4JGV498yhfShJGuwnWj8rEuQsJj1ZGmr9KS4CcoUCVJC2lj23So5FQppxNvunQka6MNmdCbBisNUBaBuPMI2FvffRty-Bl3tWgs_5lj5uPxfNhxQ9IPmdCkmDimjgzUXVsoy-aYZX5NKkZtgXjdorZmPaTM77TzKHwKJ9rKQPVioFNOq-TRoLoiH21ZEIYtXQIUGbBz5j-_Wol59QTzfriVcqQaFX8te5CqOx20gWTdLIug_yUJ6JI Oct 27 13:26:25 volumio volumio[17889]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 27 13:26:25 volumio volumio[17889]: info: New Spotify access token = BQAXE1UEHS6ECHvXEzNV-QsNf7Da77hU_B9yWdFgQSjV8Y5GsMCgghkzKunq_4JGV498yhfShJGuwnWj8rEuQsJj1ZGmr9KS4CcoUCVJC2lj23So5FQppxNvunQka6MNmdCbBisNUBaBuPMI2FvffRty-Bl3tWgs_5lj5uPxfNhxQ9IPmdCkmDimjgzUXVsoy-aYZX5NKkZtgXjdorZmPaTM77TzKHwKJ9rKQPVioFNOq-TRoLoiH21ZEIYtXQIUGbBz5j-_Wol59QTzfriVcqQaFX8te5CqOx20gWTdLIug_yUJ6JI Oct 27 13:26:25 volumio volumio[17889]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 27 13:26:25 volumio go-librespot[18067]: time="2025-10-27T13:26:25Z" level=debug msg="completed keyexchange" Oct 27 13:26:25 volumio go-librespot[18067]: time="2025-10-27T13:26:25Z" level=debug msg="completed challenge" Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::volumioGetState Oct 27 13:26:25 volumio volumio[17889]: info: CorePlayQueue::getTrack 0 Oct 27 13:26:25 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Oct 27 13:26:25 volumio sudo[18106]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:25 volumio sudo[18108]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:25 volumio sudo[18104]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:25 volumio volumio[17889]: info: Shairport-Sync Started Oct 27 13:26:25 volumio volumio[17889]: Error adding Membership: Error: addMembership EINVAL Oct 27 13:26:25 volumio volumio[17889]: info: Shairport-Sync Started Oct 27 13:26:25 volumio volumio[17889]: info: Shairport-Sync Started Oct 27 13:26:25 volumio go-librespot[18067]: time="2025-10-27T13:26:25Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:26:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:26:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:26:25 volumio volumio[17889]: SPOTIFY: User informations: {"country":"DE","display_name":"lapman","email":"ylm19961214@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31hyzsop5elyyfayaiyk5tmkxmky"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31hyzsop5elyyfayaiyk5tmkxmky","id":"31hyzsop5elyyfayaiyk5tmkxmky","images":[],"product":"free","type":"user","uri":"spotify:user:31hyzsop5elyyfayaiyk5tmkxmky"} Oct 27 13:26:25 volumio volumio[17889]: info: Spotify Successfully logged in Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 27 13:26:25 volumio volumio[17889]: info: [1761571585861] CoreMusicLibrary::Adding element Spotify Oct 27 13:26:25 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 27 13:26:25 volumio volumio[17889]: Cannot find translation for source Spotify Oct 27 13:26:25 volumio mpd[18059]: 2025-10-27T13:26:25 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 27 13:26:25 volumio systemd[1]: Started mpd.service - Music Player Daemon. Oct 27 13:26:25 volumio sudo[18022]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:25 volumio sudo[18029]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:25 volumio volumio-remote-updater[874]: [2025-10-27 13:26:25] [connect] Successful connection Oct 27 13:26:25 volumio volumio[17889]: error: MPD error: The expression evaluated to a falsy value: Oct 27 13:26:25 volumio volumio[17889]: assert.ok(self.idling) Oct 27 13:26:25 volumio volumio[17889]: error: The expression evaluated to a falsy value: Oct 27 13:26:25 volumio volumio[17889]: assert.ok(self.idling) Oct 27 13:26:25 volumio volumio[17889]: info: MPD running with PID18059 Oct 27 13:26:25 volumio volumio[17889]: ,establishing connection Oct 27 13:26:25 volumio volumio[17889]: error: updateQueue error: null Oct 27 13:26:25 volumio volumio-remote-updater[874]: [2025-10-27 13:26:25] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1761571585 101 Oct 27 13:26:25 volumio volumio[17889]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Oct 27 13:26:25 volumio volumio[17889]: error: updateQueue error: null Oct 27 13:26:26 volumio volumio[17889]: info: [yt-cast-receiver] DIAL server listening on port 8098 Oct 27 13:26:26 volumio volumio[17889]: info: CoreCommandRouter::volumioRetrievevolume Oct 27 13:26:26 volumio volumio[17889]: info: VolumeController:: Volume=33 Mute =false Oct 27 13:26:26 volumio volumio[17889]: info: CoreCommandRouter::volumioGetState Oct 27 13:26:26 volumio volumio[17889]: info: CorePlayQueue::getTrack 0 Oct 27 13:26:26 volumio volumio[17889]: info: CoreStateMachine::pushState Oct 27 13:26:26 volumio volumio[17889]: info: CorePlayQueue::getTrack 0 Oct 27 13:26:26 volumio volumio[17889]: info: CoreCommandRouter::volumioPushState Oct 27 13:26:26 volumio volumio[17889]: info: Completed starting Core Plugins Oct 27 13:26:26 volumio volumio[17889]: info: ------------------------------------------- Oct 27 13:26:26 volumio volumio[17889]: info: ----- MyVolumio plugins startup ---- Oct 27 13:26:26 volumio volumio[17889]: info: ------------------------------------------- Oct 27 13:26:26 volumio volumio[17889]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 27 13:26:27 volumio volumio[17889]: info: Cannot mount NAS NAS at system boot, trial number 2 ,retrying in 5 seconds Oct 27 13:26:28 volumio volumio[17889]: info: go-librespot daemon successfully initialized Oct 27 13:26:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 119. Oct 27 13:26:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:28 volumio go-librespot[18134]: go-librespot daemon starting... Oct 27 13:26:28 volumio go-librespot[18135]: time="2025-10-27T13:26:28Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:26:28 volumio go-librespot[18135]: time="2025-10-27T13:26:28Z" level=debug msg="app state loaded" Oct 27 13:26:28 volumio go-librespot[18135]: time="2025-10-27T13:26:28Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:26:28 volumio sudo[18143]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Oct 27 13:26:28 volumio sudo[18143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:28 volumio sudo[18146]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Oct 27 13:26:28 volumio sudo[18146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:28 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Oct 27 13:26:28 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Oct 27 13:26:28 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Oct 27 13:26:28 volumio go-librespot[18135]: time="2025-10-27T13:26: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]" Oct 27 13:26:28 volumio go-librespot[18135]: time="2025-10-27T13:26: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]" Oct 27 13:26:28 volumio go-librespot[18135]: time="2025-10-27T13:26: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]" Oct 27 13:26:28 volumio go-librespot[18135]: time="2025-10-27T13:26:28Z" level=info msg="zeroconf server listening on port 42527" Oct 27 13:26:28 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Oct 27 13:26:28 volumio mpd_monitor.sh[18148]: MPD Monitor Service: Starting MPD Monitor Service Oct 27 13:26:28 volumio sudo[18143]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:28 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Oct 27 13:26:28 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Oct 27 13:26:28 volumio volumio[17889]: info: Successfully started MPD Monitor Oct 27 13:26:28 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Oct 27 13:26:28 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Oct 27 13:26:28 volumio sudo[18146]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:28 volumio mpd_monitor.sh[18151]: MPD Monitor Service: Starting MPD Monitor Service Oct 27 13:26:28 volumio volumio[17889]: info: Successfully started MPD Monitor Oct 27 13:26:28 volumio go-librespot[18135]: time="2025-10-27T13:26:28Z" level=debug msg="obtained new client token: AADsUAw/VAHTqTTpns/04BiL9NXY6jnL8404dQGPMOuEzHg570TpC0aasJgezUAlzHKnqLxdVZUctKbOgNfh3FPWnuAaAsfOpWBbauVYRV3zMDWxUkOHWFk33C6XjcuuEUbfKVTakILiIwiIHiVQbekJOk+tY04Q7ainLugiCrjGYBqGTtn29GIy95aKiUSe+53Wis04Ncn2+vUIrQI5IC4QId2F+A0mwNd16mw6JtWiOdSRg2hOtZM=" Oct 27 13:26:29 volumio go-librespot[18135]: time="2025-10-27T13:26:29Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:26:29 volumio go-librespot[18135]: time="2025-10-27T13:26:29Z" level=debug msg="completed keyexchange" Oct 27 13:26:29 volumio go-librespot[18135]: time="2025-10-27T13:26:29Z" level=debug msg="completed challenge" Oct 27 13:26:29 volumio go-librespot[18135]: time="2025-10-27T13:26:29Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:26:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:26:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:26:30 volumio volumio[17889]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 27 13:26:31 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:26:31 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:26:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 120. Oct 27 13:26:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:32 volumio go-librespot[18156]: go-librespot daemon starting... Oct 27 13:26:32 volumio go-librespot[18157]: time="2025-10-27T13:26:32Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:26:32 volumio go-librespot[18157]: time="2025-10-27T13:26:32Z" level=debug msg="app state loaded" Oct 27 13:26:32 volumio go-librespot[18157]: time="2025-10-27T13:26:32Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:26:32 volumio go-librespot[18157]: time="2025-10-27T13:26: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]" Oct 27 13:26:32 volumio go-librespot[18157]: time="2025-10-27T13:26: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]" Oct 27 13:26:32 volumio go-librespot[18157]: time="2025-10-27T13:26: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]" Oct 27 13:26:32 volumio go-librespot[18157]: time="2025-10-27T13:26:32Z" level=info msg="zeroconf server listening on port 34765" Oct 27 13:26:32 volumio volumio[17889]: info: Cannot mount NAS NAS at system boot, trial number 3 ,retrying in 5 seconds Oct 27 13:26:32 volumio sudo[18179]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 27 13:26:32 volumio sudo[18179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:32 volumio sudo[18181]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 27 13:26:32 volumio sudo[18179]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:32 volumio sudo[18181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:32 volumio sudo[18181]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:32 volumio sudo[18185]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 27 13:26:32 volumio sudo[18185]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:32 volumio sudo[18185]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:32 volumio volumio[17889]: info: Upmpdcli Daemon Started Oct 27 13:26:32 volumio go-librespot[18157]: time="2025-10-27T13:26:32Z" level=debug msg="obtained new client token: AABAJeO6qd2ecgPVTZaIuX3w6yW2/U4E1IqNXVX0R46zRkxNNktnE4sII5ZS0DvcMIj1uRgNNFJOu8jVSHwP3vPfNAE4v1PYZ9BfRMKocmbXtGNMC7CUYHFoetGSi75UVXwgj9hF5mLmgpuHI1jNiwkPqSqlNNcW22A1viHpMXMJ+Es3q7qpQMz782CnjQNchBkHydWFlU5buTpPNuC5Q2eMzl9gdb/lz0iYCQk+4BlNiCiDl8bE8E0=" Oct 27 13:26:32 volumio go-librespot[18157]: time="2025-10-27T13:26:32Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:26:32 volumio go-librespot[18157]: time="2025-10-27T13:26:32Z" level=debug msg="completed keyexchange" Oct 27 13:26:32 volumio go-librespot[18157]: time="2025-10-27T13:26:32Z" level=debug msg="completed challenge" Oct 27 13:26:32 volumio go-librespot[18157]: time="2025-10-27T13:26:32Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:26:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:26:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 27 13:26:34 volumio volumio[17889]: info: Adding plugin bluetooth to MyMusic Plugins Oct 27 13:26:34 volumio volumio[17889]: info: Adding plugin multiroom to MyMusic Plugins Oct 27 13:26:34 volumio volumio[17889]: info: Adding plugin metavolumio to MyMusic Plugins Oct 27 13:26:34 volumio volumio[17889]: info: Adding plugin cd_controller to MyMusic Plugins Oct 27 13:26:34 volumio volumio[17889]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 27 13:26:34 volumio volumio[17889]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 27 13:26:34 volumio volumio[17889]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 27 13:26:34 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:34 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:34 volumio volumio[17889]: info: Starting MyVolumio Remote Streaming Endpoints Oct 27 13:26:34 volumio volumio[17889]: info: MyVolumio login type: Token Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 27 13:26:34 volumio volumio[17889]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 27 13:26:35 volumio volumio[17889]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 27 13:26:35 volumio volumio[17889]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 27 13:26:35 volumio volumio[17889]: info: Streaming services startup Oct 27 13:26:35 volumio volumio[17889]: info: Starting Streaming Daemon Oct 27 13:26:35 volumio sudo[18196]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 27 13:26:35 volumio sudo[18196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:35 volumio volumio[17889]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 27 13:26:35 volumio sudo[18196]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:35 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:26:35 volumio volumio[17889]: error: Cannot start Volumio Streaming Daemon Oct 27 13:26:35 volumio volumio[17889]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 27 13:26:35 volumio volumio[17889]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 27 13:26:35 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:26:35 volumio volumio[17889]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 27 13:26:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 121. Oct 27 13:26:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:35 volumio go-librespot[18203]: go-librespot daemon starting... Oct 27 13:26:35 volumio go-librespot[18204]: time="2025-10-27T13:26:35Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:26:35 volumio go-librespot[18204]: time="2025-10-27T13:26:35Z" level=debug msg="app state loaded" Oct 27 13:26:35 volumio go-librespot[18204]: time="2025-10-27T13:26:35Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:26:35 volumio volumio[17889]: info: MyVolumio token set successfully Oct 27 13:26:35 volumio volumio[17889]: info: MYVOLUMIO: Adding device Oct 27 13:26:35 volumio volumio[17889]: info: MYVOLUMIO: Evaluating Server Oct 27 13:26:35 volumio go-librespot[18204]: time="2025-10-27T13:26:35Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 13:26:35 volumio go-librespot[18204]: time="2025-10-27T13:26:35Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 27 13:26:35 volumio go-librespot[18204]: time="2025-10-27T13:26:35Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 27 13:26:35 volumio go-librespot[18204]: time="2025-10-27T13:26:35Z" level=info msg="zeroconf server listening on port 34263" Oct 27 13:26:35 volumio go-librespot[18204]: time="2025-10-27T13:26:35Z" level=debug msg="obtained new client token: AABRXjwdkVm9Ft4WzLLdYlHaFkzFNk9JEl3rEKRe7rWTiBTcH6Dgmp0CsNVKX0UJSBPaZWRBmptLXF+t9FhQD3lIBilhpmKv5pKkhNMS1Yhkg04GiNwtMNaEBVZms7UQlx5ithYzj2v/Fzn18TkXpG2g+tH/SR/TPrejTY6fkBW8551N989xM6lBx66c+FjzDTAKXxxIAvrmYgL9Q7O6jYFSPvLaXVcVGbp/t8I1jd7AV5MlzH5eSLk=" Oct 27 13:26:35 volumio go-librespot[18204]: time="2025-10-27T13:26:35Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:26:36 volumio go-librespot[18204]: time="2025-10-27T13:26:36Z" level=debug msg="completed keyexchange" Oct 27 13:26:36 volumio go-librespot[18204]: time="2025-10-27T13:26:36Z" level=debug msg="completed challenge" Oct 27 13:26:36 volumio volumio[17889]: info: MyVolumio status changed Oct 27 13:26:36 volumio volumio[17889]: info: Streaming services startup Oct 27 13:26:36 volumio volumio[17889]: info: Starting Streaming Daemon Oct 27 13:26:36 volumio volumio[17889]: info: Removing browser output: myVolumio user plan is not superstar Oct 27 13:26:36 volumio volumio[17889]: info: Removing audio output: Oct 27 13:26:36 volumio volumio[17889]: info: Stoppping Tunnel 1 Oct 27 13:26:36 volumio sudo[18229]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 27 13:26:36 volumio sudo[18229]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:36 volumio go-librespot[18204]: time="2025-10-27T13:26:36Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:26:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:26:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:26:36 volumio sudo[18231]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 27 13:26:36 volumio sudo[18231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:26:36 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 27 13:26:36 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 27 13:26:36 volumio sudo[18229]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:36 volumio volumio[17889]: error: Cannot start Volumio Streaming Daemon Oct 27 13:26:36 volumio volumio[17889]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 27 13:26:36 volumio volumio[17889]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 27 13:26:36 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 27 13:26:36 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 27 13:26:36 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 27 13:26:36 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 27 13:26:36 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 27 13:26:36 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Oct 27 13:26:36 volumio sudo[18231]: pam_unix(sudo:session): session closed for user root Oct 27 13:26:36 volumio volumio[17889]: info: Remote SSH Stopped Oct 27 13:26:36 volumio volumio[17889]: info: Setting Geolocation for MyVolumio to eu3 Oct 27 13:26:36 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:36 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:36 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:36 volumio volumio[17889]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 27 13:26:37 volumio volumio[17889]: info: Updating MyVolumio device info Oct 27 13:26:37 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:37 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:37 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:37 volumio volumio[17889]: info: Cannot mount NAS NAS at system boot, trial number 4 ,retrying in 5 seconds Oct 27 13:26:37 volumio volumio[17889]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 27 13:26:38 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:26:38 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:26:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 122. Oct 27 13:26:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:39 volumio go-librespot[18234]: go-librespot daemon starting... Oct 27 13:26:39 volumio go-librespot[18235]: time="2025-10-27T13:26:39Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:26:39 volumio go-librespot[18235]: time="2025-10-27T13:26:39Z" level=debug msg="app state loaded" Oct 27 13:26:39 volumio go-librespot[18235]: time="2025-10-27T13:26:39Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:26:39 volumio go-librespot[18235]: time="2025-10-27T13:26:39Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 27 13:26:39 volumio go-librespot[18235]: time="2025-10-27T13:26:39Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 27 13:26:39 volumio go-librespot[18235]: time="2025-10-27T13:26:39Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 27 13:26:39 volumio go-librespot[18235]: time="2025-10-27T13:26:39Z" level=info msg="zeroconf server listening on port 40785" Oct 27 13:26:39 volumio go-librespot[18235]: time="2025-10-27T13:26:39Z" level=debug msg="obtained new client token: AABK1hWfRfGTdojtyJjY5xdN0DfkDVVVP+DyB7hbNiOcQPRpEWg5LUhQiS+V37f7myry9JcwPxhZfOboVXfFbz2vvAYRIftuWWWgXuU9FB0YdlpHfWpHujvdMGuoTeGw5ns/h62CDr9zRYtSxxMh6zIL9QLfs0hWetHEUEEdd/L1p71bATnjx+MJDJcfY6XRIeqlsaqT60TODCyKtz3Y4bSVKu0zNZbcdu9o/uTvOpGQ4l5UXjCnzD0=" Oct 27 13:26:39 volumio go-librespot[18235]: time="2025-10-27T13:26:39Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:26:39 volumio go-librespot[18235]: time="2025-10-27T13:26:39Z" level=debug msg="completed keyexchange" Oct 27 13:26:39 volumio go-librespot[18235]: time="2025-10-27T13:26:39Z" level=debug msg="completed challenge" Oct 27 13:26:39 volumio go-librespot[18235]: time="2025-10-27T13:26:39Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:26:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:26:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:26:40 volumio volumio[17889]: info: MYVOLUMIO: Adding device Oct 27 13:26:40 volumio volumio[17889]: info: MYVOLUMIO: Evaluating Server Oct 27 13:26:41 volumio volumio[17889]: info: Setting Geolocation for MyVolumio to eu3 Oct 27 13:26:41 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:41 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:41 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:41 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:26:41 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:26:41 volumio volumio[17889]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 27 13:26:42 volumio volumio[17889]: info: Updating MyVolumio device info Oct 27 13:26:42 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:42 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:42 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:42 volumio volumio[17889]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 27 13:26:42 volumio volumio[17889]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Oct 27 13:26:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 123. Oct 27 13:26:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:42 volumio go-librespot[18271]: go-librespot daemon starting... Oct 27 13:26:42 volumio go-librespot[18272]: time="2025-10-27T13:26:42Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:26:42 volumio go-librespot[18272]: time="2025-10-27T13:26:42Z" level=debug msg="app state loaded" Oct 27 13:26:42 volumio go-librespot[18272]: time="2025-10-27T13:26:42Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:26:42 volumio go-librespot[18272]: time="2025-10-27T13:26:42Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 13:26:42 volumio go-librespot[18272]: time="2025-10-27T13:26:42Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 27 13:26:42 volumio go-librespot[18272]: time="2025-10-27T13:26:42Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 27 13:26:42 volumio go-librespot[18272]: time="2025-10-27T13:26:42Z" level=info msg="zeroconf server listening on port 43695" Oct 27 13:26:42 volumio go-librespot[18272]: time="2025-10-27T13:26:42Z" level=debug msg="obtained new client token: AAAToNLDozhItWUWrYHR4HK002VN/5Do0Ns0n+ebVFuBoCApsuOV1IgWSGWclikZh/eHR2tauwcCB6UPP5VQF57nVXFn2SAV7Bg38cKcYhFddIciMCHfhquIV80ix/D9mFXBL+95JGBA2mCZWj9iNh+ZG4+MCBmhz9XhQZSyR2cMtjHTGqRhxbevCdbaNrPTMVlGNMqQ03pnkCuotNdfXnDszAkVN2mssyfw5PGPjbhrvmneA2u9ncA=" Oct 27 13:26:42 volumio go-librespot[18272]: time="2025-10-27T13:26:42Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:26:43 volumio go-librespot[18272]: time="2025-10-27T13:26:43Z" level=debug msg="completed keyexchange" Oct 27 13:26:43 volumio go-librespot[18272]: time="2025-10-27T13:26:43Z" level=debug msg="completed challenge" Oct 27 13:26:43 volumio go-librespot[18272]: time="2025-10-27T13:26:43Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:26:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:26:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:26:44 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:26:44 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:26:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 124. Oct 27 13:26:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:46 volumio go-librespot[18279]: go-librespot daemon starting... Oct 27 13:26:46 volumio go-librespot[18280]: time="2025-10-27T13:26:46Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:26:46 volumio go-librespot[18280]: time="2025-10-27T13:26:46Z" level=debug msg="app state loaded" Oct 27 13:26:46 volumio go-librespot[18280]: time="2025-10-27T13:26:46Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:26:46 volumio go-librespot[18280]: time="2025-10-27T13:26:46Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 27 13:26:46 volumio go-librespot[18280]: time="2025-10-27T13:26:46Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 27 13:26:46 volumio go-librespot[18280]: time="2025-10-27T13:26:46Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 27 13:26:46 volumio go-librespot[18280]: time="2025-10-27T13:26:46Z" level=info msg="zeroconf server listening on port 38321" Oct 27 13:26:46 volumio go-librespot[18280]: time="2025-10-27T13:26:46Z" level=debug msg="obtained new client token: AAA/Cz+2yUrhCkOCWHgSCNvbr5aOh4Vs9wp9M3eLntqdfMov1S7+9FLS9jcZWlP4ZMjqcSIYnXVGM52TNCdM0qFz/TvwDsUtTUO8o6At7mRbemYyNrd6sxBEyANEMZdmKKAKYes/wbuZSDaijqQORPyOgEa7zw3waz/QIddc+fHWjvXwTJ+xo1ZMVX+voUPNo0ZKuAXVCR/VQsNrzSNFWwG5qFdW300ozGcExwLn70sAzh/Niz86y3E=" Oct 27 13:26:46 volumio go-librespot[18280]: time="2025-10-27T13:26:46Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:26:46 volumio go-librespot[18280]: time="2025-10-27T13:26:46Z" level=debug msg="completed keyexchange" Oct 27 13:26:46 volumio go-librespot[18280]: time="2025-10-27T13:26:46Z" level=debug msg="completed challenge" Oct 27 13:26:46 volumio go-librespot[18280]: time="2025-10-27T13:26:46Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:26:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:26:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:26:47 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:26:47 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:26:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 125. Oct 27 13:26:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:49 volumio go-librespot[18296]: go-librespot daemon starting... Oct 27 13:26:49 volumio go-librespot[18297]: time="2025-10-27T13:26:49Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:26:49 volumio go-librespot[18297]: time="2025-10-27T13:26:49Z" level=debug msg="app state loaded" Oct 27 13:26:49 volumio go-librespot[18297]: time="2025-10-27T13:26:49Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:26:49 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 27 13:26:49 volumio volumio[17889]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Oct 27 13:26:49 volumio volumio[17889]: info: CoreCommandRouter::volumioGetState Oct 27 13:26:49 volumio volumio[17889]: info: CorePlayQueue::getTrack 0 Oct 27 13:26:49 volumio go-librespot[18297]: time="2025-10-27T13:26:49Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 13:26:49 volumio go-librespot[18297]: time="2025-10-27T13:26:49Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 27 13:26:49 volumio go-librespot[18297]: time="2025-10-27T13:26:49Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 27 13:26:49 volumio go-librespot[18297]: time="2025-10-27T13:26:49Z" level=info msg="zeroconf server listening on port 38221" Oct 27 13:26:49 volumio go-librespot[18297]: time="2025-10-27T13:26:49Z" level=debug msg="obtained new client token: AAC6WIULpxBqHsiU6Uq48fffxOPA3wyBpfcxjCNhYCgsW28epPn5V++ZaqZS3RxJHMOPkhrs8zapfd218c/3LAHRdKFtcJ+HYYFsdp6zoDN/jd9qo3I4onm/04hfKXlFSadypryR8EMK2Pc0V0LeNysVnjCHriEt8CXKRs7dxpQQt9QcJVyT1vMPmixH92q70Ezz/l7G8+DTuajY2QQeatwHP1bnJpwLwqL+o670U4zdBBvzbqN5+CU=" Oct 27 13:26:49 volumio go-librespot[18297]: time="2025-10-27T13:26:49Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:26:50 volumio go-librespot[18297]: time="2025-10-27T13:26:50Z" level=debug msg="completed keyexchange" Oct 27 13:26:50 volumio go-librespot[18297]: time="2025-10-27T13:26:50Z" level=debug msg="completed challenge" Oct 27 13:26:50 volumio go-librespot[18297]: time="2025-10-27T13:26:50Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:26:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:26:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:26:50 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:26:50 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:26:53 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:26:53 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:26:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 126. Oct 27 13:26:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:53 volumio go-librespot[18319]: go-librespot daemon starting... Oct 27 13:26:53 volumio go-librespot[18320]: time="2025-10-27T13:26:53Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:26:53 volumio go-librespot[18320]: time="2025-10-27T13:26:53Z" level=debug msg="app state loaded" Oct 27 13:26:53 volumio go-librespot[18320]: time="2025-10-27T13:26:53Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:26:53 volumio go-librespot[18320]: time="2025-10-27T13:26:53Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 27 13:26:53 volumio go-librespot[18320]: time="2025-10-27T13:26:53Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 27 13:26:53 volumio go-librespot[18320]: time="2025-10-27T13:26:53Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 27 13:26:53 volumio go-librespot[18320]: time="2025-10-27T13:26:53Z" level=info msg="zeroconf server listening on port 37687" Oct 27 13:26:53 volumio go-librespot[18320]: time="2025-10-27T13:26:53Z" level=debug msg="obtained new client token: AACKOS+ggA2lnIk6vPnYr77FhPecvpFQc3i/ixeRFaPhqlpWtlii12akoBx/ifaMy13gAq2oGA+WbvJ0twdZHXSxo+r4Gw/0gVDYjJfnOLoeIXZA2Y4TImHaVixQDGG5TywT4kP27o2jk0KhZHVERMzvCBsleMR3Jg+R8XIOIUeGyfqAEBwRrpa97stchvbUxY2rFi/AAF7DD9WwxNtY2bvMdpUzI7hdb6jqqHeZrO8rfkJ1g6IqQfk=" Oct 27 13:26:53 volumio go-librespot[18320]: time="2025-10-27T13:26:53Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:26:53 volumio go-librespot[18320]: time="2025-10-27T13:26:53Z" level=debug msg="completed keyexchange" Oct 27 13:26:53 volumio go-librespot[18320]: time="2025-10-27T13:26:53Z" level=debug msg="completed challenge" Oct 27 13:26:53 volumio go-librespot[18320]: time="2025-10-27T13:26:53Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:26:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:26:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:26:54 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:54 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:54 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 27 13:26:54 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 27 13:26:54 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 27 13:26:54 volumio volumio[17889]: info: CoreCommandRouter::volumioGetBrowseSources Oct 27 13:26:54 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 27 13:26:55 volumio volumio[17889]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 27 13:26:55 volumio volumio[17889]: info: Completed starting MyVolumio Plugin Oct 27 13:26:55 volumio volumio[17889]: [Metrics] CommandRouter: 33s 267.87ms Oct 27 13:26:55 volumio volumio[17889]: info: CoreCommandRouter::volumiosetStartupVolume Oct 27 13:26:55 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 27 13:26:55 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:55 volumio volumio[17889]: info: CoreCommandRouter::Close All Modals sent Oct 27 13:26:55 volumio volumio[17889]: info: CoreCommandRouter::Close All Modals sent Oct 27 13:26:55 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 27 13:26:55 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 27 13:26:55 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 27 13:26:55 volumio volumio-remote-updater[874]: Test mode disabled Oct 27 13:26:55 volumio volumio-remote-updater[874]: Alpha mode disabled Oct 27 13:26:55 volumio volumio-remote-updater[874]: Alpha legacy test mode disabled Oct 27 13:26:55 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 27 13:26:55 volumio volumio[17889]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 27 13:26:55 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 27 13:26:56 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 27 13:26:56 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 27 13:26:56 volumio volumio[17889]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 27 13:26:56 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:26:56 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:26:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 127. Oct 27 13:26:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:26:56 volumio go-librespot[18336]: go-librespot daemon starting... Oct 27 13:26:56 volumio go-librespot[18337]: time="2025-10-27T13:26:56Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:26:56 volumio go-librespot[18337]: time="2025-10-27T13:26:56Z" level=debug msg="app state loaded" Oct 27 13:26:56 volumio go-librespot[18337]: time="2025-10-27T13:26:56Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:26:56 volumio go-librespot[18337]: time="2025-10-27T13:26:56Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 13:26:56 volumio go-librespot[18337]: time="2025-10-27T13:26:56Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 27 13:26:56 volumio go-librespot[18337]: time="2025-10-27T13:26:56Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 27 13:26:56 volumio go-librespot[18337]: time="2025-10-27T13:26:56Z" level=info msg="zeroconf server listening on port 45409" Oct 27 13:26:56 volumio go-librespot[18337]: time="2025-10-27T13:26:56Z" level=debug msg="obtained new client token: AAD97mMpw1LX94pw+/sfG4DqHtUGgtsHBu5MvaGOGrZRtJYWTZczrgGuASy96wxk3Rsjv3wa3NeAtsMlM5WX5xXp/XbBE4IUHWHsoYN336jNfmNP7BomkLe2/I+V8CPkTCP0N8XlBf6pbe/je5+jr2E6Kw75Bzq/L6H4fKX0gvl+kH1UkOrUkvGkJyS59vZAMzYwonxthK4+dLP4JGj0xJJ13kVTQ/8RSUmJxffgT1dbNPmpXbCae98=" Oct 27 13:26:56 volumio go-librespot[18337]: time="2025-10-27T13:26:56Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:26:57 volumio go-librespot[18337]: time="2025-10-27T13:26:57Z" level=debug msg="completed keyexchange" Oct 27 13:26:57 volumio go-librespot[18337]: time="2025-10-27T13:26:57Z" level=debug msg="completed challenge" Oct 27 13:26:57 volumio go-librespot[18337]: time="2025-10-27T13:26:57Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:26:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:26:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:26:59 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:26:59 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 128. Oct 27 13:27:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:00 volumio go-librespot[18344]: go-librespot daemon starting... Oct 27 13:27:00 volumio go-librespot[18345]: time="2025-10-27T13:27:00Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:27:00 volumio go-librespot[18345]: time="2025-10-27T13:27:00Z" level=debug msg="app state loaded" Oct 27 13:27:00 volumio go-librespot[18345]: time="2025-10-27T13:27:00Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:27:00 volumio go-librespot[18345]: time="2025-10-27T13:27:00Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 27 13:27:00 volumio go-librespot[18345]: time="2025-10-27T13:27: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]" Oct 27 13:27:00 volumio go-librespot[18345]: time="2025-10-27T13:27: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]" Oct 27 13:27:00 volumio go-librespot[18345]: time="2025-10-27T13:27:00Z" level=info msg="zeroconf server listening on port 43637" Oct 27 13:27:00 volumio go-librespot[18345]: time="2025-10-27T13:27:00Z" level=debug msg="obtained new client token: AABup2qwvvgNGNVCU5TlnpjnQLOvm6OnmkGnTZ/6aXCFSEMDImycxWMWKxIxuZd/sf7lnN+tZK5NICspGk4S2qi2O1/xWk83Iq8rT07SsiBoCl3qd9Hj48OnWQws9+XYfqz3xFu68z2999x95SI5RQ4/WzmV0DxycZHZntKDAYBQIB7ORhLmJGd2yEsY5mXy3AH/fGN45cWgsKVPwua413sRwus5JnTMD2oXJhxQp1p18MIRPw/qwbk=" Oct 27 13:27:00 volumio go-librespot[18345]: time="2025-10-27T13:27:00Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:27:00 volumio go-librespot[18345]: time="2025-10-27T13:27:00Z" level=debug msg="completed keyexchange" Oct 27 13:27:00 volumio go-librespot[18345]: time="2025-10-27T13:27:00Z" level=debug msg="completed challenge" Oct 27 13:27:00 volumio go-librespot[18345]: time="2025-10-27T13:27:00Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:27:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:27:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:27:02 volumio volumio[17889]: info: BOOT COMPLETED Oct 27 13:27:02 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:02 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 129. Oct 27 13:27:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:03 volumio go-librespot[18372]: go-librespot daemon starting... Oct 27 13:27:03 volumio go-librespot[18373]: time="2025-10-27T13:27:03Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:27:03 volumio go-librespot[18373]: time="2025-10-27T13:27:03Z" level=debug msg="app state loaded" Oct 27 13:27:03 volumio go-librespot[18373]: time="2025-10-27T13:27:03Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:27:03 volumio go-librespot[18373]: time="2025-10-27T13:27: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]" Oct 27 13:27:03 volumio go-librespot[18373]: time="2025-10-27T13:27: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]" Oct 27 13:27:03 volumio go-librespot[18373]: time="2025-10-27T13:27: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]" Oct 27 13:27:03 volumio go-librespot[18373]: time="2025-10-27T13:27:03Z" level=info msg="zeroconf server listening on port 45575" Oct 27 13:27:03 volumio go-librespot[18373]: time="2025-10-27T13:27:03Z" level=debug msg="obtained new client token: AACFNZnvZWD9hY5hP6B4zmZyGMfOTbpLRAxYqk4KUu9gnP3YIdWLkAhSoIHjZffZUMSMOGpRqodIHAlGU6bKt+0qlayuXbByKGywLXg4akZOgMPqhQ2t34h8NdsxtRDfUVsvkR3Nnpfw0MG60SHz1Wh1JKyDr7H3Qxsmm2QRyiDUTwyGY3uhlvg3Bq+8r5vqWP0g1GuAqAVUAq+pM+a6mSeB6OQVq7Ey3a4jD2bpEftoESHKZn6ydQ8=" Oct 27 13:27:04 volumio go-librespot[18373]: time="2025-10-27T13:27:04Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:27:04 volumio go-librespot[18373]: time="2025-10-27T13:27:04Z" level=debug msg="completed keyexchange" Oct 27 13:27:04 volumio go-librespot[18373]: time="2025-10-27T13:27:04Z" level=debug msg="completed challenge" Oct 27 13:27:04 volumio go-librespot[18373]: time="2025-10-27T13:27:04Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:27:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:27:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:27:05 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:05 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 130. Oct 27 13:27:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:07 volumio go-librespot[18380]: go-librespot daemon starting... Oct 27 13:27:07 volumio go-librespot[18381]: time="2025-10-27T13:27:07Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:27:07 volumio go-librespot[18381]: time="2025-10-27T13:27:07Z" level=debug msg="app state loaded" Oct 27 13:27:07 volumio go-librespot[18381]: time="2025-10-27T13:27:07Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:27:07 volumio go-librespot[18381]: time="2025-10-27T13:27:07Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 27 13:27:07 volumio go-librespot[18381]: time="2025-10-27T13:27:07Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 27 13:27:07 volumio go-librespot[18381]: time="2025-10-27T13:27:07Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 27 13:27:07 volumio go-librespot[18381]: time="2025-10-27T13:27:07Z" level=info msg="zeroconf server listening on port 36467" Oct 27 13:27:07 volumio go-librespot[18381]: time="2025-10-27T13:27:07Z" level=debug msg="obtained new client token: AAAKIYjeWgC0BwG1vwM45B2vN35zT+KqR/sdIfdT9x9bYX7VY1QcEFVtb8AsXLqzZRbY6ffX69NtP6RwsT/w+R6ztnGK2bs9xJsxmdeGWqSrWRIwiFYLhgZe+rUaxAwJFqyrdig3LKvIDSoW30+UPFLcHlYvXm8Q8yElp9EwJG5gonv99RpvXjlatCY9yq3QdgunIzLVsY/iDx5IG35W8hzWMjWzMAoNlX6asb3FK7L481ACS0AFrwE=" Oct 27 13:27:07 volumio go-librespot[18381]: time="2025-10-27T13:27:07Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:27:07 volumio go-librespot[18381]: time="2025-10-27T13:27:07Z" level=debug msg="completed keyexchange" Oct 27 13:27:07 volumio go-librespot[18381]: time="2025-10-27T13:27:07Z" level=debug msg="completed challenge" Oct 27 13:27:07 volumio go-librespot[18381]: time="2025-10-27T13:27:07Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:27:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:27:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:27:08 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:08 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 131. Oct 27 13:27:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:10 volumio go-librespot[18391]: go-librespot daemon starting... Oct 27 13:27:10 volumio go-librespot[18392]: time="2025-10-27T13:27:10Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:27:10 volumio go-librespot[18392]: time="2025-10-27T13:27:10Z" level=debug msg="app state loaded" Oct 27 13:27:10 volumio go-librespot[18392]: time="2025-10-27T13:27:10Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:27:10 volumio go-librespot[18392]: time="2025-10-27T13:27: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 13:27:10 volumio go-librespot[18392]: time="2025-10-27T13:27:10Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 27 13:27:10 volumio go-librespot[18392]: time="2025-10-27T13:27:10Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 27 13:27:10 volumio go-librespot[18392]: time="2025-10-27T13:27:10Z" level=info msg="zeroconf server listening on port 39051" Oct 27 13:27:10 volumio go-librespot[18392]: time="2025-10-27T13:27:10Z" level=debug msg="obtained new client token: AADbsF/jjHABqjh0yUAYSiCOtQuCgi/voIUlpPTok31WzXix+Mt2tdH0bukXFRyZiCc2wk5uWkT7+Y4cCdqBY2SNawUpiwZLtkGRhqkoKIK8BuCXFsqJhg4eE6O+DGH3HCUwHQvBVI8FPhUwA0RUBWFvnlHINwMfdx+Lx17J10czQsIbxHjN+woQy6npeSObc1CF/wE8vsOctqDdyA29FLm6KPJGo+Rkss7uxG1FAjN8ZASTcYjpc7E=" Oct 27 13:27:10 volumio go-librespot[18392]: time="2025-10-27T13:27:10Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:27:11 volumio go-librespot[18392]: time="2025-10-27T13:27:11Z" level=debug msg="completed keyexchange" Oct 27 13:27:11 volumio go-librespot[18392]: time="2025-10-27T13:27:11Z" level=debug msg="completed challenge" Oct 27 13:27:11 volumio go-librespot[18392]: time="2025-10-27T13:27:11Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:27:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:27:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:27:11 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:11 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:14 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:14 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 132. Oct 27 13:27:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:14 volumio go-librespot[18414]: go-librespot daemon starting... Oct 27 13:27:14 volumio go-librespot[18415]: time="2025-10-27T13:27:14Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:27:14 volumio go-librespot[18415]: time="2025-10-27T13:27:14Z" level=debug msg="app state loaded" Oct 27 13:27:14 volumio go-librespot[18415]: time="2025-10-27T13:27:14Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:27:14 volumio go-librespot[18415]: time="2025-10-27T13:27: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]" Oct 27 13:27:14 volumio go-librespot[18415]: time="2025-10-27T13:27: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]" Oct 27 13:27:14 volumio go-librespot[18415]: time="2025-10-27T13:27: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]" Oct 27 13:27:14 volumio go-librespot[18415]: time="2025-10-27T13:27:14Z" level=info msg="zeroconf server listening on port 34029" Oct 27 13:27:14 volumio go-librespot[18415]: time="2025-10-27T13:27:14Z" level=debug msg="obtained new client token: AAC0d/IX46YP+kosv7G6RLXJzJRIfpa92/Lwd8UoCCOjNixyLY4Yn3r77WHJTK2jwdI+ohfpKXOdTmCisvBvpSLOUXubbzqLsmiqvkxfjYBht2FRapmfDHevyftChwM+S+rCyw8yxWYvY9sYtt9n/kKpUPhMQ+TJgW6Yb+GY8LjFHOr8LtF3l/zAXh/7ytCyNbxl591Zi93MRqAWSNGQnBF9Pwqp174yHJEGdvQoct9+dZltqcGgQgo=" Oct 27 13:27:14 volumio go-librespot[18415]: time="2025-10-27T13:27:14Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:27:14 volumio go-librespot[18415]: time="2025-10-27T13:27:14Z" level=debug msg="completed keyexchange" Oct 27 13:27:14 volumio go-librespot[18415]: time="2025-10-27T13:27:14Z" level=debug msg="completed challenge" Oct 27 13:27:14 volumio go-librespot[18415]: time="2025-10-27T13:27:14Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:27:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:27:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:27:17 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:17 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 133. Oct 27 13:27:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:17 volumio go-librespot[18422]: go-librespot daemon starting... Oct 27 13:27:17 volumio go-librespot[18423]: time="2025-10-27T13:27:17Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:27:17 volumio go-librespot[18423]: time="2025-10-27T13:27:17Z" level=debug msg="app state loaded" Oct 27 13:27:17 volumio go-librespot[18423]: time="2025-10-27T13:27:17Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:27:17 volumio go-librespot[18423]: time="2025-10-27T13:27: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]" Oct 27 13:27:17 volumio go-librespot[18423]: time="2025-10-27T13:27: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]" Oct 27 13:27:17 volumio go-librespot[18423]: time="2025-10-27T13:27: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]" Oct 27 13:27:17 volumio go-librespot[18423]: time="2025-10-27T13:27:17Z" level=info msg="zeroconf server listening on port 43103" Oct 27 13:27:17 volumio go-librespot[18423]: time="2025-10-27T13:27:17Z" level=debug msg="obtained new client token: AACyctU40Vm0lpj0Kch0y3vi7u77GpL67EECCxZeWMohuN7IgzO/Lbc6VTTiZK6zQYijADSeVV3VBJ7ddhku/bHAnbD6fGEv1XtcyjdQ0yb90PFDbNYCYPW2aybagIht+j+GYEn360V9pqYm6AKeKW1D0A3r8jMfq2aRK3X+ztFeSuW5utCHnbcK+N4cqTENMtHDtcBHIxzL0jBtjv4of4neY3PSj1u2yLRAnELFGnvJlGinpakrbMc=" Oct 27 13:27:17 volumio go-librespot[18423]: time="2025-10-27T13:27:17Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:27:18 volumio go-librespot[18423]: time="2025-10-27T13:27:18Z" level=debug msg="completed keyexchange" Oct 27 13:27:18 volumio go-librespot[18423]: time="2025-10-27T13:27:18Z" level=debug msg="completed challenge" Oct 27 13:27:18 volumio go-librespot[18423]: time="2025-10-27T13:27:18Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:27:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:27:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:27:20 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:20 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 134. Oct 27 13:27:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:21 volumio go-librespot[18436]: go-librespot daemon starting... Oct 27 13:27:21 volumio go-librespot[18437]: time="2025-10-27T13:27:21Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:27:21 volumio go-librespot[18437]: time="2025-10-27T13:27:21Z" level=debug msg="app state loaded" Oct 27 13:27:21 volumio go-librespot[18437]: time="2025-10-27T13:27:21Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:27:21 volumio go-librespot[18437]: time="2025-10-27T13:27:21Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 13:27:21 volumio go-librespot[18437]: time="2025-10-27T13:27:21Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 27 13:27:21 volumio go-librespot[18437]: time="2025-10-27T13:27:21Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 27 13:27:21 volumio go-librespot[18437]: time="2025-10-27T13:27:21Z" level=info msg="zeroconf server listening on port 37423" Oct 27 13:27:21 volumio go-librespot[18437]: time="2025-10-27T13:27:21Z" level=debug msg="obtained new client token: AACggaGtHewY6uIYqMCDefkO0awknX9pxRKov+5iA23gbvKePVmfv5vfT0xXbVX/2qIswm4ZAd6gutjLgg3WK36O8y5SxvSPIetztBzBX4ruZiirW6gmcZ2kvsNPPIzwcmjBBDWXC1NYwdjGhBtNI+E3EOLTvxNOwuy2auaijZny5RGktjnx6GRJ7jDFxHrRS9FmOhUM8DwWq5+jlHq8HEO/UV3P8QFAVhcGKswHc62tXdbxBPfI2GE=" Oct 27 13:27:21 volumio go-librespot[18437]: time="2025-10-27T13:27:21Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:27:21 volumio go-librespot[18437]: time="2025-10-27T13:27:21Z" level=debug msg="completed keyexchange" Oct 27 13:27:21 volumio go-librespot[18437]: time="2025-10-27T13:27:21Z" level=debug msg="completed challenge" Oct 27 13:27:21 volumio go-librespot[18437]: time="2025-10-27T13:27:21Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:27:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:27:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:27:23 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:23 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 135. Oct 27 13:27:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:24 volumio go-librespot[18458]: go-librespot daemon starting... Oct 27 13:27:24 volumio go-librespot[18459]: time="2025-10-27T13:27:24Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:27:24 volumio go-librespot[18459]: time="2025-10-27T13:27:24Z" level=debug msg="app state loaded" Oct 27 13:27:24 volumio go-librespot[18459]: time="2025-10-27T13:27:24Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:27:24 volumio go-librespot[18459]: time="2025-10-27T13:27: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-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 13:27:24 volumio go-librespot[18459]: time="2025-10-27T13:27:24Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 27 13:27:24 volumio go-librespot[18459]: time="2025-10-27T13:27:24Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 27 13:27:24 volumio go-librespot[18459]: time="2025-10-27T13:27:24Z" level=info msg="zeroconf server listening on port 40097" Oct 27 13:27:24 volumio go-librespot[18459]: time="2025-10-27T13:27:24Z" level=debug msg="obtained new client token: AADk805V7l8bKiqfLoQMAsuIr9PHhrnsbVdLCWLyxPJPDaH5/dSG1cbmjUI2mwg229De3u9IzDwBm7R3xJ7PQKtEV5XVe/Fo9xS8OkpFiMax33toDoQ/j1eg/6GMHSwYK7Cz59WonmVJR3ow7ZqN8eSJX9RSSI6/QhyE2nkduMqHKyZc6eDsfxO3g+sTxiq7sGiV7DcQMVvRwVO5kKktanNgp66CPNzDRa/8gUi1H0l/N69sDz1m6FQ=" Oct 27 13:27:24 volumio go-librespot[18459]: time="2025-10-27T13:27:24Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:27:25 volumio go-librespot[18459]: time="2025-10-27T13:27:25Z" level=debug msg="completed keyexchange" Oct 27 13:27:25 volumio go-librespot[18459]: time="2025-10-27T13:27:25Z" level=debug msg="completed challenge" Oct 27 13:27:25 volumio go-librespot[18459]: time="2025-10-27T13:27:25Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:27:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:27:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:27:26 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:26 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 136. Oct 27 13:27:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:28 volumio go-librespot[18466]: go-librespot daemon starting... Oct 27 13:27:28 volumio go-librespot[18467]: time="2025-10-27T13:27:28Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:27:28 volumio go-librespot[18467]: time="2025-10-27T13:27:28Z" level=debug msg="app state loaded" Oct 27 13:27:28 volumio go-librespot[18467]: time="2025-10-27T13:27:28Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:27:28 volumio go-librespot[18467]: time="2025-10-27T13:27:28Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 13:27:28 volumio go-librespot[18467]: time="2025-10-27T13:27:28Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 27 13:27:28 volumio go-librespot[18467]: time="2025-10-27T13:27:28Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 27 13:27:28 volumio go-librespot[18467]: time="2025-10-27T13:27:28Z" level=info msg="zeroconf server listening on port 43497" Oct 27 13:27:28 volumio go-librespot[18467]: time="2025-10-27T13:27:28Z" level=debug msg="obtained new client token: AACOzkHHqUbPsxcn+5yPB9IyJAmhM+akXK23Zp2SvrZWL06jfZI/h3HWZPILSDHAcihRBAm/uGnRovlyZmKzOWAnmvnbVPMDfCdQHTvXBKXvOPe6YUSTWxh3lfr60ufbTumieySmFBqwoAtiG9mGiL8R1PzjzursngHlTj2+99goKHoIHRyezb+wFi1ctC0fCZaCjjWbhB2YCme9S34W7xZrEcx9No6ECJ6IaaCgSM5rMbQr9BxUZVk=" Oct 27 13:27:28 volumio go-librespot[18467]: time="2025-10-27T13:27:28Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:27:28 volumio go-librespot[18467]: time="2025-10-27T13:27:28Z" level=debug msg="completed keyexchange" Oct 27 13:27:28 volumio go-librespot[18467]: time="2025-10-27T13:27:28Z" level=debug msg="completed challenge" Oct 27 13:27:28 volumio go-librespot[18467]: time="2025-10-27T13:27:28Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:27:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:27:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:27:29 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:29 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 137. Oct 27 13:27:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:31 volumio go-librespot[18477]: go-librespot daemon starting... Oct 27 13:27:31 volumio go-librespot[18478]: time="2025-10-27T13:27:31Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:27:31 volumio go-librespot[18478]: time="2025-10-27T13:27:31Z" level=debug msg="app state loaded" Oct 27 13:27:31 volumio go-librespot[18478]: time="2025-10-27T13:27:31Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:27:31 volumio go-librespot[18478]: time="2025-10-27T13:27:31Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 13:27:31 volumio go-librespot[18478]: time="2025-10-27T13:27:31Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 27 13:27:31 volumio go-librespot[18478]: time="2025-10-27T13:27:31Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 27 13:27:31 volumio go-librespot[18478]: time="2025-10-27T13:27:31Z" level=info msg="zeroconf server listening on port 35083" Oct 27 13:27:31 volumio go-librespot[18478]: time="2025-10-27T13:27:31Z" level=debug msg="obtained new client token: AACjVl5pnhEmG/KFKC1+YZSC+NwtDGvqQOFE6F8e25H199naQTo0Tr1PL4f3BQOyROSRCHrNPXQBAM2xJtLiQBFt3ByOI6mQt6aoNVeq/h+tonSpk3TNxreGaggszHIpaTVeO8idHDCiBEVoZQfytG0T+aqMuWQw0PB/dAPnsq5HWvGwmtZay7gF++jtzPNmRQstt8nyuFA/I92+T21Imf9Fg6Xv5xxe6arTsFhglu1VgIj7yOTHDSA=" Oct 27 13:27:31 volumio go-librespot[18478]: time="2025-10-27T13:27:31Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:27:32 volumio go-librespot[18478]: time="2025-10-27T13:27:32Z" level=debug msg="completed keyexchange" Oct 27 13:27:32 volumio go-librespot[18478]: time="2025-10-27T13:27:32Z" level=debug msg="completed challenge" Oct 27 13:27:32 volumio go-librespot[18478]: time="2025-10-27T13:27:32Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:27:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:27:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:27:32 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:32 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:35 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:35 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 138. Oct 27 13:27:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:35 volumio go-librespot[18506]: go-librespot daemon starting... Oct 27 13:27:35 volumio go-librespot[18507]: time="2025-10-27T13:27:35Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:27:35 volumio go-librespot[18507]: time="2025-10-27T13:27:35Z" level=debug msg="app state loaded" Oct 27 13:27:35 volumio go-librespot[18507]: time="2025-10-27T13:27:35Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:27:35 volumio go-librespot[18507]: time="2025-10-27T13:27:35Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 27 13:27:35 volumio go-librespot[18507]: time="2025-10-27T13:27:35Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 27 13:27:35 volumio go-librespot[18507]: time="2025-10-27T13:27:35Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 27 13:27:35 volumio go-librespot[18507]: time="2025-10-27T13:27:35Z" level=info msg="zeroconf server listening on port 45075" Oct 27 13:27:35 volumio go-librespot[18507]: time="2025-10-27T13:27:35Z" level=debug msg="obtained new client token: AAAfqU3QH338VKMvWFfSeH24jqflgu8JdmgBiFKNfu8fPfjWOS9wnSsfXzvuZ4g4jsPBD4zsCOqr7VGuu+Gu2yvVcVLJfPbzA4OSttG6eVpt50QkttIL+SZHrNb4hEFBG5mZckJ/CP5lze7YgjEOl/teYQM1xcOHOCZhGH9Ngv44ppWdTy0Jb2uU0nk0TIbP41qi6oovZc4jKtJyQPnF4kWt6CLBxAl+r57JFuSeY5asKEQxKW32RxE=" Oct 27 13:27:35 volumio go-librespot[18507]: time="2025-10-27T13:27:35Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:27:35 volumio go-librespot[18507]: time="2025-10-27T13:27:35Z" level=debug msg="completed keyexchange" Oct 27 13:27:35 volumio go-librespot[18507]: time="2025-10-27T13:27:35Z" level=debug msg="completed challenge" Oct 27 13:27:35 volumio go-librespot[18507]: time="2025-10-27T13:27:35Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:27:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:27:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:27:38 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:38 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 139. Oct 27 13:27:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:38 volumio go-librespot[18514]: go-librespot daemon starting... Oct 27 13:27:38 volumio go-librespot[18515]: time="2025-10-27T13:27:38Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:27:38 volumio go-librespot[18515]: time="2025-10-27T13:27:38Z" level=debug msg="app state loaded" Oct 27 13:27:38 volumio go-librespot[18515]: time="2025-10-27T13:27:38Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:27:38 volumio go-librespot[18515]: time="2025-10-27T13:27:38Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 13:27:38 volumio go-librespot[18515]: time="2025-10-27T13:27:38Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 27 13:27:38 volumio go-librespot[18515]: time="2025-10-27T13:27:38Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 27 13:27:38 volumio go-librespot[18515]: time="2025-10-27T13:27:38Z" level=info msg="zeroconf server listening on port 40993" Oct 27 13:27:38 volumio go-librespot[18515]: time="2025-10-27T13:27:38Z" level=debug msg="obtained new client token: AACFmW9ao5oMqx+CE7pt6/eMqru3f6hFiSvPLxnH+oycfiYrdCioDqCDmnOtDad/zigIUDMgfCUiEK6ErCjrUxeS+7kshq+oEO1vpUT/iyqjeOLX/S+uE+J5N3VCVnAM1GHsMROSCj1kST2z7mZAe4aSsSZwYMkBTG5/T+DahR7zdEZbaRWpl2GFAyMJYuYrh8Ym+Kj08i/hWi7b2UIs5v71OPvzC5WgPjUknMOoVLhT7MUpoMrVfcQ=" Oct 27 13:27:38 volumio go-librespot[18515]: time="2025-10-27T13:27:38Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:27:39 volumio go-librespot[18515]: time="2025-10-27T13:27:39Z" level=debug msg="completed keyexchange" Oct 27 13:27:39 volumio go-librespot[18515]: time="2025-10-27T13:27:39Z" level=debug msg="completed challenge" Oct 27 13:27:39 volumio go-librespot[18515]: time="2025-10-27T13:27:39Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:27:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:27:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:27:41 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:41 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 140. Oct 27 13:27:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:42 volumio go-librespot[18522]: go-librespot daemon starting... Oct 27 13:27:42 volumio go-librespot[18523]: time="2025-10-27T13:27:42Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:27:42 volumio go-librespot[18523]: time="2025-10-27T13:27:42Z" level=debug msg="app state loaded" Oct 27 13:27:42 volumio go-librespot[18523]: time="2025-10-27T13:27:42Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:27:42 volumio go-librespot[18523]: time="2025-10-27T13:27:42Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 13:27:42 volumio go-librespot[18523]: time="2025-10-27T13:27:42Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 27 13:27:42 volumio go-librespot[18523]: time="2025-10-27T13:27:42Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 27 13:27:42 volumio go-librespot[18523]: time="2025-10-27T13:27:42Z" level=info msg="zeroconf server listening on port 33071" Oct 27 13:27:42 volumio go-librespot[18523]: time="2025-10-27T13:27:42Z" level=debug msg="obtained new client token: AABTUqpRiDaFYIh26uuXeheQEoMxdX7aME//yjsBXRV/ODk55H8cKdKLw92baQ3Ux7ZEn4nMJt49s8z7ThSAnLkWO+mJkiojCYDi1GOPcKWDHv6QiowzwZFKtrm5LmaMnrI+9QgWr5XfXZGkJ7b22Cs9h9kKfGUT5CQTy9pSVzHWc6Yfy0hri21F/4pyIG0iVwXMELCXOcENkvUe/7X21w78AAVQzKube4aClW0JGKoaFVFsEiSm8es=" Oct 27 13:27:42 volumio go-librespot[18523]: time="2025-10-27T13:27:42Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:27:42 volumio go-librespot[18523]: time="2025-10-27T13:27:42Z" level=debug msg="completed keyexchange" Oct 27 13:27:42 volumio go-librespot[18523]: time="2025-10-27T13:27:42Z" level=debug msg="completed challenge" Oct 27 13:27:42 volumio go-librespot[18523]: time="2025-10-27T13:27:42Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:27:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:27:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:27:44 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:44 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 141. Oct 27 13:27:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:45 volumio go-librespot[18544]: go-librespot daemon starting... Oct 27 13:27:45 volumio go-librespot[18545]: time="2025-10-27T13:27:45Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:27:45 volumio go-librespot[18545]: time="2025-10-27T13:27:45Z" level=debug msg="app state loaded" Oct 27 13:27:45 volumio go-librespot[18545]: time="2025-10-27T13:27:45Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:27:45 volumio go-librespot[18545]: time="2025-10-27T13:27:45Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 27 13:27:45 volumio go-librespot[18545]: time="2025-10-27T13:27:45Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 27 13:27:45 volumio go-librespot[18545]: time="2025-10-27T13:27:45Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 27 13:27:45 volumio go-librespot[18545]: time="2025-10-27T13:27:45Z" level=info msg="zeroconf server listening on port 38801" Oct 27 13:27:45 volumio go-librespot[18545]: time="2025-10-27T13:27:45Z" level=debug msg="obtained new client token: AAALwma06AW+SoDkBfO1yST/gZ1xrBqaj8Tj7f9NFFnCjvYI2Y7FCZQqVjnSmmTDhiZ+FJRaWq1tXCgzrW7Yff96IDEZVW3tfge+5IXX7wOcSOb2XhQ4iT9NbAkLgV7JpYaIl1gtp4xVMz7DNAU2BCFu3tZ3AX/vRoNzCJU0fEnCP+PO1sqoBEpA523IB5JyehdIaSV4nBHPmcbdXv3c4b1J3d5YJYFqSMmkxHo8qncm29wwtQ6WoXk=" Oct 27 13:27:45 volumio go-librespot[18545]: time="2025-10-27T13:27:45Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:27:46 volumio go-librespot[18545]: time="2025-10-27T13:27:46Z" level=debug msg="completed keyexchange" Oct 27 13:27:46 volumio go-librespot[18545]: time="2025-10-27T13:27:46Z" level=debug msg="completed challenge" Oct 27 13:27:46 volumio go-librespot[18545]: time="2025-10-27T13:27:46Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:27:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:27:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:27:47 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:47 volumio volumio[17889]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 142. Oct 27 13:27:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:49 volumio go-librespot[18561]: go-librespot daemon starting... Oct 27 13:27:49 volumio go-librespot[18562]: time="2025-10-27T13:27:49Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:27:49 volumio go-librespot[18562]: time="2025-10-27T13:27:49Z" level=debug msg="app state loaded" Oct 27 13:27:49 volumio go-librespot[18562]: time="2025-10-27T13:27:49Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:27:49 volumio go-librespot[18562]: time="2025-10-27T13:27:49Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 27 13:27:49 volumio go-librespot[18562]: time="2025-10-27T13:27:49Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 27 13:27:49 volumio go-librespot[18562]: time="2025-10-27T13:27:49Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 27 13:27:49 volumio go-librespot[18562]: time="2025-10-27T13:27:49Z" level=info msg="zeroconf server listening on port 33805" Oct 27 13:27:49 volumio go-librespot[18562]: time="2025-10-27T13:27:49Z" level=debug msg="obtained new client token: AACLKQt3QmIRwQseB+8MJmwC7yEHpEKAUt2RVuWumFtZEixyp89F7x9mRzpUudPB7a/swz2TTbxTg7sr+ZMTwPzQsNIG7f358AWGvVZMgtsQpt27lkEzftxI+LpdJF6bjmubbfesIRpOMMHyx4DRcePREDcYs8fyZHuspW14i+v09eRfwvJptE1zSEOI4AV1rjKNBfgzeMeisp76pYwUVBHJNAg7sV9qGwzC+AKFttN4FJdphwEjUog=" Oct 27 13:27:49 volumio go-librespot[18562]: time="2025-10-27T13:27:49Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Oct 27 13:27:50 volumio volumio[17889]: info: Initializing connection to go-librespot Websocket Oct 27 13:27:50 volumio go-librespot[18562]: time="2025-10-27T13:27:50Z" level=debug msg="new websocket client" Oct 27 13:27:50 volumio volumio[17889]: info: Connection to go-librespot Websocket established Oct 27 13:27:50 volumio go-librespot[18562]: time="2025-10-27T13:27:50Z" level=debug msg="completed keyexchange" Oct 27 13:27:50 volumio go-librespot[18562]: time="2025-10-27T13:27:50Z" level=debug msg="completed challenge" Oct 27 13:27:50 volumio go-librespot[18562]: time="2025-10-27T13:27:50Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Oct 27 13:27:50 volumio volumio[17889]: info: Connection to go-librespot Websocket closed Oct 27 13:27:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Oct 27 13:27:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Oct 27 13:27:53 volumio volumio[17889]: info: Getting Spotify volume Oct 27 13:27:53 volumio volumio[17889]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 27 13:27:53 volumio volumio[17889]: Error: connect ECONNREFUSED 127.0.0.1:9879 Oct 27 13:27:53 volumio volumio[17889]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Oct 27 13:27:53 volumio volumio[17889]: errno: -111, Oct 27 13:27:53 volumio volumio[17889]: code: 'ECONNREFUSED', Oct 27 13:27:53 volumio volumio[17889]: syscall: 'connect', Oct 27 13:27:53 volumio volumio[17889]: address: '127.0.0.1', Oct 27 13:27:53 volumio volumio[17889]: port: 9879, Oct 27 13:27:53 volumio volumio[17889]: response: undefined Oct 27 13:27:53 volumio volumio[17889]: } Oct 27 13:27:53 volumio volumio[17889]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 27 13:27:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 143. Oct 27 13:27:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Oct 27 13:27:53 volumio go-librespot[18596]: go-librespot daemon starting... Oct 27 13:27:53 volumio go-librespot[18597]: time="2025-10-27T13:27:53Z" level=info msg="running go-librespot 0.4.0" Oct 27 13:27:53 volumio go-librespot[18597]: time="2025-10-27T13:27:53Z" level=debug msg="app state loaded" Oct 27 13:27:53 volumio go-librespot[18597]: time="2025-10-27T13:27:53Z" level=info msg="api server listening on 127.0.0.1:9879" Oct 27 13:27:53 volumio sudo[18606]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-10-27 13:26' Oct 27 13:27:53 volumio sudo[18606]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 27 13:27:53 volumio go-librespot[18597]: time="2025-10-27T13:27:53Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 27 13:27:53 volumio go-librespot[18597]: time="2025-10-27T13:27:53Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 27 13:27:53 volumio go-librespot[18597]: time="2025-10-27T13:27:53Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 27 13:27:53 volumio go-librespot[18597]: time="2025-10-27T13:27:53Z" level=info msg="zeroconf server listening on port 37893" 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"