Mar 24 07:37:00 inside volumio[14939]: info: CoreCommandRouter::volumioGetState Mar 24 07:37:00 inside volumio[14939]: info: CorePlayQueue::getTrack 0 Mar 24 07:37:08 inside volumio[14939]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Mar 24 07:37:09 inside go-librespot[15642]: time="2026-03-24T07:37:09-04: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)" Mar 24 07:37:09 inside systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 07:37:09 inside systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 07:37:10 inside volumio[14939]: info: CoreCommandRouter::volumioGetState Mar 24 07:37:10 inside volumio[14939]: info: CorePlayQueue::getTrack 0 Mar 24 07:37:10 inside volumio[14939]: info: Listing playlists Mar 24 07:37:10 inside volumio[14939]: info: Listing playlists Mar 24 07:37:12 inside systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 24 07:37:12 inside systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 07:37:12 inside systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 07:37:12 inside go-librespot[15713]: go-librespot daemon starting... Mar 24 07:37:12 inside go-librespot[15714]: time="2026-03-24T07:37:12-04:00" level=info msg="running go-librespot 0.7.1" Mar 24 07:37:12 inside go-librespot[15714]: time="2026-03-24T07:37:12-04:00" level=debug msg="app state loaded" Mar 24 07:37:12 inside go-librespot[15714]: time="2026-03-24T07:37:12-04:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 07:37:20 inside volumio[14939]: info: CoreCommandRouter::volumioGetState Mar 24 07:37:20 inside volumio[14939]: info: CorePlayQueue::getTrack 0 Mar 24 07:37:29 inside bash[15402]: setdatetime-helper: all HTTPS Date fallbacks failed Mar 24 07:37:29 inside systemd[1]: setdatetime-helper.service: Deactivated successfully. Mar 24 07:37:29 inside systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Mar 24 07:37:30 inside volumio[14939]: info: CoreCommandRouter::volumioGetState Mar 24 07:37:30 inside volumio[14939]: info: CorePlayQueue::getTrack 0 Mar 24 07:37:30 inside volumio[14939]: info: Listing playlists Mar 24 07:37:30 inside volumio[14939]: info: Listing playlists Mar 24 07:37:40 inside volumio[14939]: info: CoreCommandRouter::volumioGetState Mar 24 07:37:40 inside volumio[14939]: info: CorePlayQueue::getTrack 0 Mar 24 07:37:42 inside go-librespot[15714]: time="2026-03-24T07:37:42-04: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\": dial tcp: lookup apresolve.spotify.com: i/o timeout (Client.Timeout exceeded while awaiting headers)" Mar 24 07:37:42 inside systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 07:37:42 inside systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 07:37:44 inside volumio[14939]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Mar 24 07:37:44 inside volumio[14939]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Mar 24 07:37:44 inside volumio[14939]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 07:37:44 inside volumio[14939]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 24 07:37:44 inside volumio[14939]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Mar 24 07:37:44 inside volumio[14939]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Mar 24 07:37:45 inside systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 24 07:37:45 inside systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 07:37:45 inside systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 07:37:45 inside go-librespot[15780]: go-librespot daemon starting... Mar 24 07:37:45 inside go-librespot[15781]: time="2026-03-24T07:37:45-04:00" level=info msg="running go-librespot 0.7.1" Mar 24 07:37:45 inside go-librespot[15781]: time="2026-03-24T07:37:45-04:00" level=debug msg="app state loaded" Mar 24 07:37:45 inside go-librespot[15781]: time="2026-03-24T07:37:45-04:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 07:37:47 inside volumio[14939]: info: Initializing connection to go-librespot Websocket Mar 24 07:37:48 inside dhcpcd[695]: eth0: failed to renew DHCP, rebinding Mar 24 07:37:48 inside dhcpcd[695]: eth0: leased 10.20.50.165 for 86400 seconds Mar 24 07:37:48 inside systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Mar 24 07:37:48 inside systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Mar 24 07:37:48 inside systemd[1]: welcome.service: Deactivated successfully. Mar 24 07:37:48 inside systemd[1]: Stopped welcome.service - Show a welcome message on console. Mar 24 07:37:48 inside systemd[1]: Stopping welcome.service - Show a welcome message on console... Mar 24 07:37:48 inside systemd[1]: Starting welcome.service - Show a welcome message on console... Mar 24 07:37:48 inside welcome[15818]: Resolved ip:[1] 10.20.50.165 Mar 24 07:37:48 inside systemd[1]: Finished welcome.service - Show a welcome message on console. Mar 24 07:37:48 inside systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Mar 24 07:37:48 inside volumio[14939]: info: Received Get System Info Mar 24 07:37:48 inside volumio[14939]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 07:37:48 inside volumio[14939]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 07:37:48 inside volumio[14939]: info: Discovery: Getting this device information Mar 24 07:37:48 inside volumio[14939]: info: CoreCommandRouter::volumioGetState Mar 24 07:37:48 inside volumio[14939]: info: CorePlayQueue::getTrack 0 Mar 24 07:37:48 inside volumio[14939]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 07:37:48 inside volumio[14939]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 07:37:48 inside volumio[14939]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 07:37:49 inside volumio5-onboarding[1577]: time=2026-03-24T07:37:49.672-04:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 24 07:37:50 inside volumio[14939]: info: CoreCommandRouter::volumioGetState Mar 24 07:37:50 inside volumio[14939]: info: CorePlayQueue::getTrack 0 Mar 24 07:37:50 inside volumio[14939]: info: Listing playlists Mar 24 07:37:50 inside volumio[14939]: info: Listing playlists Mar 24 07:38:00 inside volumio[14939]: info: CoreCommandRouter::volumioGetState Mar 24 07:38:00 inside volumio[14939]: info: CorePlayQueue::getTrack 0 Mar 24 07:38:10 inside volumio[14939]: info: CoreCommandRouter::volumioGetState Mar 24 07:38:10 inside volumio[14939]: info: CorePlayQueue::getTrack 0 Mar 24 07:38:10 inside volumio[14939]: info: Listing playlists Mar 24 07:38:10 inside volumio[14939]: info: Listing playlists Mar 24 07:38:12 inside volumio[14939]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Mar 24 07:38:12 inside volumio[14939]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Mar 24 07:38:12 inside volumio[14939]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Mar 24 07:38:12 inside go-librespot[15781]: time="2026-03-24T07:38:12-04:00" level=debug msg="new websocket client" Mar 24 07:38:12 inside volumio[14939]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Mar 24 07:38:12 inside volumio[14939]: info: Connection to go-librespot Websocket established Mar 24 07:38:12 inside volumio[14939]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Mar 24 07:38:12 inside volumio[14939]: info: CoreCommandRouter::volumioGetState Mar 24 07:38:12 inside volumio[14939]: info: CorePlayQueue::getTrack 0 Mar 24 07:38:15 inside volumio[14939]: info: Discovery: Disconnected from remote: 10.20.50.175 Mar 24 07:38:15 inside go-librespot[15781]: time="2026-03-24T07:38:15-04: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)" Mar 24 07:38:15 inside systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 07:38:15 inside systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 07:38:15 inside volumio[14939]: info: Connection to go-librespot Websocket closed Mar 24 07:38:15 inside volumio[14939]: info: Getting Spotify volume Mar 24 07:38:15 inside volumio[14939]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 07:38:15 inside volumio[14939]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 07:38:15 inside volumio[14939]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 24 07:38:15 inside volumio[14939]: errno: -111, Mar 24 07:38:15 inside volumio[14939]: code: 'ECONNREFUSED', Mar 24 07:38:15 inside volumio[14939]: syscall: 'connect', Mar 24 07:38:15 inside volumio[14939]: address: '127.0.0.1', Mar 24 07:38:15 inside volumio[14939]: port: 9879, Mar 24 07:38:15 inside volumio[14939]: response: undefined Mar 24 07:38:15 inside volumio[14939]: } Mar 24 07:38:15 inside volumio[14939]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 07:38:16 inside sudo[15874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 07:37' Mar 24 07:38:16 inside sudo[15874]: 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="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"