-- Logs begin at Fri 2025-10-31 10:07:06 CET, end at Sat 2025-11-01 09:28:56 CET. -- Nov 01 09:27:00 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Nov 01 09:27:00 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Nov 01 09:27:20 volumio go-librespot[1965]: time="2025-11-01T09:27:20+01: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)" Nov 01 09:27:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 09:27:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 09:27:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 01 09:27:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57. Nov 01 09:27:24 volumio systemd[1]: Stopped go-librespot Daemon. Nov 01 09:27:24 volumio systemd[1]: Started go-librespot Daemon. Nov 01 09:27:24 volumio go-librespot[2023]: go-librespot daemon starting... Nov 01 09:27:24 volumio go-librespot[2023]: time="2025-11-01T09:27:24+01:00" level=info msg="running go-librespot 0.3.2" Nov 01 09:27:24 volumio go-librespot[2023]: time="2025-11-01T09:27:24+01:00" level=debug msg="app state loaded" Nov 01 09:27:24 volumio go-librespot[2023]: time="2025-11-01T09:27:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 09:27:54 volumio go-librespot[2023]: time="2025-11-01T09:27:54+01: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)" Nov 01 09:27:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 09:27:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 09:27:56 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Nov 01 09:27:56 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Nov 01 09:27:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 01 09:27:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 58. Nov 01 09:27:57 volumio systemd[1]: Stopped go-librespot Daemon. Nov 01 09:27:57 volumio systemd[1]: Started go-librespot Daemon. Nov 01 09:27:57 volumio go-librespot[2117]: go-librespot daemon starting... Nov 01 09:27:57 volumio go-librespot[2117]: time="2025-11-01T09:27:57+01:00" level=info msg="running go-librespot 0.3.2" Nov 01 09:27:57 volumio go-librespot[2117]: time="2025-11-01T09:27:57+01:00" level=debug msg="app state loaded" Nov 01 09:27:57 volumio go-librespot[2117]: time="2025-11-01T09:27:57+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 09:28:00 volumio volumio[917]: info: CorePlayQueue::getTrack 1 Nov 01 09:28:00 volumio volumio[917]: info: CorePlayQueue::getTrack 3 Nov 01 09:28:00 volumio volumio[917]: info: Prefetching next song Nov 01 09:28:00 volumio volumio[917]: info: [1761985680797] ControllerSpotify::prefetch Nov 01 09:28:00 volumio volumio[917]: info: Sending Spotify command with payload to local API: /player/add_to_queue Nov 01 09:28:05 volumio volumio[917]: info: CoreStateMachine::startPlaybackTimer Nov 01 09:28:05 volumio volumio[917]: info: CorePlayQueue::getTrack 3 Nov 01 09:28:05 volumio volumio[917]: info: CoreStateMachine::pushState Nov 01 09:28:05 volumio volumio[917]: info: CorePlayQueue::getTrack 3 Nov 01 09:28:05 volumio volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 09:28:05 volumio volumio[917]: info: CoreCommandRouter::volumioPushState Nov 01 09:28:23 volumio sudo[2193]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 01 09:28:23 volumio sudo[2193]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 09:28:23 volumio sudo[2193]: pam_unix(sudo:session): session closed for user root Nov 01 09:28:23 volumio sudo[2196]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 01 09:28:23 volumio sudo[2196]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 09:28:23 volumio sudo[2196]: pam_unix(sudo:session): session closed for user root Nov 01 09:28:23 volumio volumio[917]: verbose: New Socket.io Connection to 10.10.10.170 from 10.10.10.10 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/141.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Nov 01 09:28:23 volumio volumio[917]: info: CoreCommandRouter::volumioGetState Nov 01 09:28:23 volumio volumio[917]: info: CorePlayQueue::getTrack 3 Nov 01 09:28:23 volumio volumio[917]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 01 09:28:23 volumio volumio[917]: info: CoreCommandRouter::volumioGetVisibleSources Nov 01 09:28:23 volumio volumio[917]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 01 09:28:23 volumio volumio[917]: info: Listing playlists Nov 01 09:28:23 volumio volumio[917]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Nov 01 09:28:23 volumio volumio[917]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 01 09:28:23 volumio volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 01 09:28:23 volumio volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Nov 01 09:28:24 volumio go-librespot[2117]: time="2025-11-01T09:28:24+01:00" level=debug msg="new websocket client" Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16 Nov 01 09:28:24 volumio volumio[917]: info: Connection to go-librespot Websocket established Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 17 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 18 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 19 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 20 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 21 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 22 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 23 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 24 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 25 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 26 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 27 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 28 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 29 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 30 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 31 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 32 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 33 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 34 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 35 Nov 01 09:28:24 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 36 Nov 01 09:28:24 volumio volumio[917]: info: CoreCommandRouter::volumioGetState Nov 01 09:28:24 volumio volumio[917]: info: CorePlayQueue::getTrack 3 Nov 01 09:28:24 volumio volumio[917]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 01 09:28:26 volumio volumio[917]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 01 09:28:26 volumio volumio[917]: info: Received Get System Info Nov 01 09:28:26 volumio volumio[917]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 01 09:28:26 volumio volumio[917]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 01 09:28:26 volumio volumio[917]: info: Discovery: Getting this device information Nov 01 09:28:26 volumio volumio[917]: info: CoreCommandRouter::volumioGetState Nov 01 09:28:26 volumio volumio[917]: info: CorePlayQueue::getTrack 3 Nov 01 09:28:26 volumio volumio[917]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 01 09:28:26 volumio volumio[917]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 01 09:28:27 volumio go-librespot[2117]: time="2025-11-01T09:28:27+01: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)" Nov 01 09:28:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 01 09:28:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 01 09:28:27 volumio volumio[917]: error: Failed to send command to Spotify local API: /player/add_to_queue: Error: socket hang up Nov 01 09:28:27 volumio volumio[917]: info: Connection to go-librespot Websocket closed Nov 01 09:28:27 volumio volumio[917]: info: Getting Spotify volume Nov 01 09:28:27 volumio volumio[917]: (node:917) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 09:28:27 volumio volumio[917]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Nov 01 09:28:27 volumio volumio[917]: (node:917) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 13) Nov 01 09:28:27 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 35 Nov 01 09:28:27 volumio volumio[917]: info: CoreCommandRouter::volumioGetState Nov 01 09:28:27 volumio volumio[917]: info: CorePlayQueue::getTrack 3 Nov 01 09:28:27 volumio volumio[917]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 01 09:28:30 volumio volumio[917]: info: Initializing connection to go-librespot Websocket Nov 01 09:28:30 volumio volumio[917]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 01 09:28:30 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Nov 01 09:28:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59. Nov 01 09:28:30 volumio systemd[1]: Stopped go-librespot Daemon. Nov 01 09:28:30 volumio systemd[1]: Started go-librespot Daemon. Nov 01 09:28:30 volumio go-librespot[2212]: go-librespot daemon starting... Nov 01 09:28:30 volumio go-librespot[2212]: time="2025-11-01T09:28:30+01:00" level=info msg="running go-librespot 0.3.2" Nov 01 09:28:30 volumio go-librespot[2212]: time="2025-11-01T09:28:30+01:00" level=debug msg="app state loaded" Nov 01 09:28:30 volumio go-librespot[2212]: time="2025-11-01T09:28:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 01 09:28:33 volumio volumio[917]: info: Initializing connection to go-librespot Websocket Nov 01 09:28:33 volumio go-librespot[2212]: time="2025-11-01T09:28:33+01:00" level=debug msg="new websocket client" Nov 01 09:28:33 volumio volumio[917]: info: Connection to go-librespot Websocket established Nov 01 09:28:36 volumio volumio[917]: info: Getting Spotify volume Nov 01 09:28:36 volumio volumio[917]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 35 Nov 01 09:28:36 volumio volumio[917]: info: CoreCommandRouter::volumioGetState Nov 01 09:28:36 volumio volumio[917]: info: CorePlayQueue::getTrack 3 Nov 01 09:28:36 volumio volumio[917]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 01 09:28:56 volumio volumio[917]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 09:28:56 volumio volumio[917]: [t [Error]: A network error (such as timeout, interrupted connection or unreachable host) has occurred.] { Nov 01 09:28:56 volumio volumio[917]: code: 'auth/network-request-failed', Nov 01 09:28:56 volumio volumio[917]: a: null Nov 01 09:28:56 volumio volumio[917]: } Nov 01 09:28:56 volumio volumio[917]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 09:28:56 volumio sudo[2324]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-11-01 09:27 Nov 01 09:28:56 volumio sudo[2324]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"