Feb 25 10:31:00 volumio volumio[5374]: info: Initializing connection to go-librespot Websocket Feb 25 10:31:01 volumio volumio[5374]: info: Cannot mount NAS NAS at system boot, trial number 3 ,retrying in 5 seconds Feb 25 10:31:02 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 47. Feb 25 10:31:02 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 10:31:02 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 10:31:02 volumio upmpdcli[5703]: Could not open config: /tmp/upmpdcli.conf Feb 25 10:31:02 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 25 10:31:02 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 25 10:31:06 volumio ntpd[1205]: PROTO: 162.159.200.1 unlink local addr 192.168.0.75 -> Feb 25 10:31:06 volumio volumio[5374]: info: Cannot mount NAS NAS at system boot, trial number 4 ,retrying in 5 seconds Feb 25 10:31:11 volumio volumio[5374]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Feb 25 10:31:14 volumio volumio[5374]: error: MyVolumio Plugin failed to start in a timely fashion Feb 25 10:31:14 volumio volumio[5374]: [Metrics] CommandRouter: 23s 678.49ms Feb 25 10:31:14 volumio volumio[5374]: info: CoreCommandRouter::volumiosetStartupVolume Feb 25 10:31:14 volumio volumio[5374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 10:31:14 volumio volumio[5374]: info: VolumeController:: Setting startup Volume 35 Feb 25 10:31:14 volumio volumio[5374]: info: VolumeController::SetAlsaVolume35 Feb 25 10:31:14 volumio volumio[5374]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 10:31:14 volumio volumio[5374]: info: CoreCommandRouter::Close All Modals sent Feb 25 10:31:14 volumio volumio[5374]: info: CoreCommandRouter::Close All Modals sent Feb 25 10:31:14 volumio volumio[5374]: info: CoreStateMachine::pushState Feb 25 10:31:14 volumio volumio[5374]: info: CorePlayQueue::getTrack 0 Feb 25 10:31:14 volumio volumio[5374]: info: CoreCommandRouter::volumioPushState Feb 25 10:31:15 volumio volumio[5374]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Feb 25 10:31:15 volumio volumio[5374]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 25 10:31:15 volumio volumio[5374]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Feb 25 10:31:17 volumio ntpd[1205]: PROTO: 162.19.170.154 unlink local addr 192.168.0.75 -> Feb 25 10:31:17 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 48. Feb 25 10:31:17 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 10:31:17 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 10:31:17 volumio upmpdcli[5731]: Could not open config: /tmp/upmpdcli.conf Feb 25 10:31:17 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 25 10:31:17 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 25 10:31:18 volumio go-librespot[5630]: time="2026-02-25T10:31:18+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": net/http: TLS handshake timeout" Feb 25 10:31:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 10:31:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 10:31:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 25 10:31:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 10:31:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 10:31:21 volumio go-librespot[5737]: go-librespot daemon starting... Feb 25 10:31:21 volumio go-librespot[5738]: time="2026-02-25T10:31:21+02:00" level=info msg="running go-librespot 0.6.2" Feb 25 10:31:21 volumio go-librespot[5738]: time="2026-02-25T10:31:21+02:00" level=debug msg="app state loaded" Feb 25 10:31:21 volumio go-librespot[5738]: time="2026-02-25T10:31:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 10:31:21 volumio volumio[5374]: info: BOOT COMPLETED Feb 25 10:31:23 volumio volumio[5374]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 10:31:23 volumio volumio[5374]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 10:31:23 volumio volumio[5374]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 25 10:31:32 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 49. Feb 25 10:31:32 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 10:31:32 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 10:31:32 volumio upmpdcli[5788]: Could not open config: /tmp/upmpdcli.conf Feb 25 10:31:32 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 25 10:31:32 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 25 10:31:38 volumio bash[5238]: setdatetime-helper: all HTTPS Date fallbacks failed Feb 25 10:31:38 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 25 10:31:38 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 25 10:31:48 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 50. Feb 25 10:31:48 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 10:31:48 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 10:31:48 volumio upmpdcli[5804]: Could not open config: /tmp/upmpdcli.conf Feb 25 10:31:48 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 25 10:31:48 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 25 10:31:51 volumio go-librespot[5738]: time="2026-02-25T10:31:51+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": net/http: TLS handshake timeout" Feb 25 10:31:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 10:31:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 10:31:51 volumio volumio[5374]: info: Discovery: adding 8d561a0d-d093-4cd1-b5dd-6b404d764309 Feb 25 10:31:51 volumio volumio[5374]: info: Discovery: Found device Volumio Feb 25 10:31:51 volumio volumio[5374]: info: CoreCommandRouter::volumioGetState Feb 25 10:31:51 volumio volumio[5374]: info: CorePlayQueue::getTrack 0 Feb 25 10:31:51 volumio volumio[5374]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 10:31:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 25 10:31:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 10:31:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 10:31:54 volumio go-librespot[5820]: go-librespot daemon starting... Feb 25 10:31:54 volumio go-librespot[5821]: time="2026-02-25T10:31:54+02:00" level=info msg="running go-librespot 0.6.2" Feb 25 10:31:54 volumio go-librespot[5821]: time="2026-02-25T10:31:54+02:00" level=debug msg="app state loaded" Feb 25 10:31:54 volumio go-librespot[5821]: time="2026-02-25T10:31:54+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 10:31:54 volumio volumio[5374]: info: Initializing connection to go-librespot Websocket Feb 25 10:32:03 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 51. Feb 25 10:32:03 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 10:32:03 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 10:32:03 volumio upmpdcli[5842]: Could not open config: /tmp/upmpdcli.conf Feb 25 10:32:03 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 25 10:32:03 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 25 10:32:10 volumio volumio[5374]: info: Discovery: this is already registered, 8d561a0d-d093-4cd1-b5dd-6b404d764309 Feb 25 10:32:10 volumio volumio[5374]: info: Discovery: Found device Volumio Feb 25 10:32:10 volumio volumio[5374]: info: CoreCommandRouter::volumioGetState Feb 25 10:32:10 volumio volumio[5374]: info: CorePlayQueue::getTrack 0 Feb 25 10:32:15 volumio volumio[5374]: info: CoreCommandRouter::volumioGetState Feb 25 10:32:15 volumio volumio[5374]: info: CorePlayQueue::getTrack 0 Feb 25 10:32:18 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 52. Feb 25 10:32:18 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 10:32:18 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 10:32:18 volumio upmpdcli[5858]: Could not open config: /tmp/upmpdcli.conf Feb 25 10:32:18 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 25 10:32:18 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 25 10:32:24 volumio go-librespot[5821]: time="2026-02-25T10:32:24+02:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)" Feb 25 10:32:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 10:32:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 10:32:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 25 10:32:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 10:32:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 10:32:27 volumio go-librespot[5874]: go-librespot daemon starting... Feb 25 10:32:27 volumio go-librespot[5875]: time="2026-02-25T10:32:27+02:00" level=info msg="running go-librespot 0.6.2" Feb 25 10:32:27 volumio go-librespot[5875]: time="2026-02-25T10:32:27+02:00" level=debug msg="app state loaded" Feb 25 10:32:27 volumio go-librespot[5875]: time="2026-02-25T10:32:27+02:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 10:32:33 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 53. Feb 25 10:32:33 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 10:32:33 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 10:32:33 volumio upmpdcli[5896]: Could not open config: /tmp/upmpdcli.conf Feb 25 10:32:33 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 25 10:32:33 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 25 10:32:42 volumio go-librespot[5875]: time="2026-02-25T10:32:42+02:00" 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]" Feb 25 10:32:42 volumio go-librespot[5875]: time="2026-02-25T10:32:42+02:00" 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]" Feb 25 10:32:42 volumio go-librespot[5875]: time="2026-02-25T10:32:42+02:00" 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]" Feb 25 10:32:42 volumio go-librespot[5875]: time="2026-02-25T10:32:42+02:00" level=info msg="zeroconf server listening on port 40961" Feb 25 10:32:49 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 54. Feb 25 10:32:49 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 10:32:49 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Feb 25 10:32:49 volumio upmpdcli[5916]: Could not open config: /tmp/upmpdcli.conf Feb 25 10:32:49 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Feb 25 10:32:49 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Feb 25 10:32:49 volumio volumio[5374]: info: Connection to go-librespot Websocket established Feb 25 10:32:49 volumio go-librespot[5875]: time="2026-02-25T10:32:49+02:00" level=debug msg="new websocket client" Feb 25 10:32:51 volumio volumio[5374]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Feb 25 10:32:51 volumio volumio[5374]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Feb 25 10:32:52 volumio go-librespot[5875]: time="2026-02-25T10:32:52+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": net/http: TLS handshake timeout" Feb 25 10:32:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 10:32:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 10:32:52 volumio volumio[5374]: info: Connection to go-librespot Websocket closed Feb 25 10:32:52 volumio volumio[5374]: info: Getting Spotify volume Feb 25 10:32:52 volumio volumio[5374]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 10:32:52 volumio volumio[5374]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 10:32:52 volumio volumio[5374]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 25 10:32:52 volumio volumio[5374]: errno: -111, Feb 25 10:32:52 volumio volumio[5374]: code: 'ECONNREFUSED', Feb 25 10:32:52 volumio volumio[5374]: syscall: 'connect', Feb 25 10:32:52 volumio volumio[5374]: address: '127.0.0.1', Feb 25 10:32:52 volumio volumio[5374]: port: 9879, Feb 25 10:32:52 volumio volumio[5374]: response: undefined Feb 25 10:32:52 volumio volumio[5374]: } Feb 25 10:32:52 volumio volumio[5374]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 10:32:52 volumio sudo[5946]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-25 10:31' Feb 25 10:32:52 volumio sudo[5946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"