May 05 09:04:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. May 05 09:04:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:01 volumio go-librespot[1731]: go-librespot daemon starting... May 05 09:04:01 volumio go-librespot[1732]: time="2026-05-05T09:04:01+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:01 volumio go-librespot[1732]: time="2026-05-05T09:04:01+02:00" level=debug msg="app state loaded" May 05 09:04:01 volumio go-librespot[1732]: time="2026-05-05T09:04:01+02:00" level=debug msg="stored credentials not found" May 05 09:04:01 volumio go-librespot[1732]: time="2026-05-05T09:04:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:01 volumio go-librespot[1732]: time="2026-05-05T09:04:01+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:02 volumio wpa_supplicant[1128]: wlan0: Failed to initiate sched scan May 05 09:04:02 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:02 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:03 volumio volumio[1166]: info: Received Get System Info May 05 09:04:03 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 05 09:04:03 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 05 09:04:03 volumio volumio[1166]: info: Discovery: Getting this device information May 05 09:04:03 volumio volumio[1166]: info: CoreCommandRouter::volumioGetState May 05 09:04:03 volumio volumio[1166]: info: CorePlayQueue::getTrack 0 May 05 09:04:03 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 05 09:04:03 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 05 09:04:03 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 05 09:04:03 volumio volumio[1166]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.119&uuid=af77425ffd98dabb369b4ccc227b807f" http://updates.volumio.org/downloader-v1/track-device May 05 09:04:03 volumio volumio[1166]: % Total % Received % Xferd Average Speed Time Time Time Current May 05 09:04:03 volumio volumio[1166]: Dload Upload Total Spent Left Speed May 05 09:04:03 volumio volumio[1166]: [132B blob data] May 05 09:04:03 volumio volumio[1166]: retrying in 5 seconds, trial 1 May 05 09:04:03 volumio volumio[1166]: info: Volumio Calling Home May 05 09:04:04 volumio volumio5-onboarding[1498]: time=2026-05-05T09:04:04.160+02:00 level=INFO msg="service successfully established" component=discovery/localnet May 05 09:04:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. May 05 09:04:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:04 volumio go-librespot[1745]: go-librespot daemon starting... May 05 09:04:04 volumio go-librespot[1746]: time="2026-05-05T09:04:04+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:04 volumio go-librespot[1746]: time="2026-05-05T09:04:04+02:00" level=debug msg="app state loaded" May 05 09:04:04 volumio go-librespot[1746]: time="2026-05-05T09:04:04+02:00" level=debug msg="stored credentials not found" May 05 09:04:04 volumio go-librespot[1746]: time="2026-05-05T09:04:04+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:04 volumio go-librespot[1746]: time="2026-05-05T09:04:04+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:04 volumio volumio[1166]: error: MyVolumio Plugin failed to start in a timely fashion May 05 09:04:04 volumio volumio[1166]: [Metrics] CommandRouter: 50s 302.49ms May 05 09:04:04 volumio volumio[1166]: info: CoreCommandRouter::volumiosetStartupVolume May 05 09:04:04 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 05 09:04:04 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 05 09:04:05 volumio volumio[1166]: info: CoreCommandRouter::Close All Modals sent May 05 09:04:05 volumio volumio[1166]: info: CoreCommandRouter::Close All Modals sent May 05 09:04:05 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 05 09:04:05 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 05 09:04:05 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 05 09:04:05 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:05 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:06 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 05 09:04:06 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 05 09:04:06 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 05 09:04:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. May 05 09:04:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:07 volumio go-librespot[1758]: go-librespot daemon starting... May 05 09:04:07 volumio go-librespot[1759]: time="2026-05-05T09:04:07+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:07 volumio go-librespot[1759]: time="2026-05-05T09:04:07+02:00" level=debug msg="app state loaded" May 05 09:04:07 volumio go-librespot[1759]: time="2026-05-05T09:04:07+02:00" level=debug msg="stored credentials not found" May 05 09:04:08 volumio go-librespot[1759]: time="2026-05-05T09:04:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:08 volumio go-librespot[1759]: time="2026-05-05T09:04:08+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:08 volumio wpa_supplicant[1128]: wlan0: Failed to initiate sched scan May 05 09:04:08 volumio volumio[1166]: info: Received Get System Info May 05 09:04:08 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 05 09:04:08 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 05 09:04:08 volumio volumio[1166]: info: Discovery: Getting this device information May 05 09:04:08 volumio volumio[1166]: info: CoreCommandRouter::volumioGetState May 05 09:04:08 volumio volumio[1166]: info: CorePlayQueue::getTrack 0 May 05 09:04:08 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 05 09:04:08 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 05 09:04:08 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 05 09:04:08 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:09 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:09 volumio volumio5-onboarding[1498]: time=2026-05-05T09:04:09.721+02:00 level=INFO msg="service successfully established" component=discovery/localnet May 05 09:04:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. May 05 09:04:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:11 volumio go-librespot[1780]: go-librespot daemon starting... May 05 09:04:11 volumio go-librespot[1781]: time="2026-05-05T09:04:11+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:11 volumio go-librespot[1781]: time="2026-05-05T09:04:11+02:00" level=debug msg="app state loaded" May 05 09:04:11 volumio go-librespot[1781]: time="2026-05-05T09:04:11+02:00" level=debug msg="stored credentials not found" May 05 09:04:11 volumio go-librespot[1781]: time="2026-05-05T09:04:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:11 volumio go-librespot[1781]: time="2026-05-05T09:04:11+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:12 volumio volumio[1166]: info: BOOT COMPLETED May 05 09:04:12 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:12 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:13 volumio volumio[1166]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.119&uuid=af77425ffd98dabb369b4ccc227b807f" http://updates.volumio.org/downloader-v1/track-device May 05 09:04:13 volumio volumio[1166]: % Total % Received % Xferd Average Speed Time Time Time Current May 05 09:04:13 volumio volumio[1166]: Dload Upload Total Spent Left Speed May 05 09:04:13 volumio volumio[1166]: [132B blob data] May 05 09:04:13 volumio volumio[1166]: retrying in 5 seconds, trial 2 May 05 09:04:13 volumio volumio[1166]: info: Volumio Calling Home May 05 09:04:13 volumio wpa_supplicant[1128]: wlan0: Failed to initiate sched scan May 05 09:04:14 volumio volumio[1166]: info: Received Get System Info May 05 09:04:14 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 05 09:04:14 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 05 09:04:14 volumio volumio[1166]: info: Discovery: Getting this device information May 05 09:04:14 volumio volumio[1166]: info: CoreCommandRouter::volumioGetState May 05 09:04:14 volumio volumio[1166]: info: CorePlayQueue::getTrack 0 May 05 09:04:14 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 05 09:04:14 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 05 09:04:14 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 05 09:04:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. May 05 09:04:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:14 volumio go-librespot[1793]: go-librespot daemon starting... May 05 09:04:14 volumio go-librespot[1794]: time="2026-05-05T09:04:14+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:14 volumio go-librespot[1794]: time="2026-05-05T09:04:14+02:00" level=debug msg="app state loaded" May 05 09:04:14 volumio go-librespot[1794]: time="2026-05-05T09:04:14+02:00" level=debug msg="stored credentials not found" May 05 09:04:14 volumio go-librespot[1794]: time="2026-05-05T09:04:14+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:14 volumio go-librespot[1794]: time="2026-05-05T09:04:14+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:15 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:15 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:15 volumio volumio5-onboarding[1498]: time=2026-05-05T09:04:15.344+02:00 level=INFO msg="service successfully established" component=discovery/localnet May 05 09:04:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. May 05 09:04:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:18 volumio go-librespot[1802]: go-librespot daemon starting... May 05 09:04:18 volumio go-librespot[1803]: time="2026-05-05T09:04:18+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:18 volumio go-librespot[1803]: time="2026-05-05T09:04:18+02:00" level=debug msg="app state loaded" May 05 09:04:18 volumio go-librespot[1803]: time="2026-05-05T09:04:18+02:00" level=debug msg="stored credentials not found" May 05 09:04:18 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:18 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:18 volumio go-librespot[1803]: time="2026-05-05T09:04:18+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:18 volumio go-librespot[1803]: time="2026-05-05T09:04:18+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:19 volumio wpa_supplicant[1128]: wlan0: Failed to initiate sched scan May 05 09:04:19 volumio volumio[1166]: info: Received Get System Info May 05 09:04:19 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 05 09:04:20 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 05 09:04:20 volumio volumio[1166]: info: Discovery: Getting this device information May 05 09:04:20 volumio volumio[1166]: info: CoreCommandRouter::volumioGetState May 05 09:04:20 volumio volumio[1166]: info: CorePlayQueue::getTrack 0 May 05 09:04:20 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 05 09:04:20 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 05 09:04:20 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 05 09:04:21 volumio volumio5-onboarding[1498]: time=2026-05-05T09:04:21.013+02:00 level=INFO msg="service successfully established" component=discovery/localnet May 05 09:04:21 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:21 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. May 05 09:04:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:21 volumio go-librespot[1825]: go-librespot daemon starting... May 05 09:04:21 volumio go-librespot[1826]: time="2026-05-05T09:04:21+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:21 volumio go-librespot[1826]: time="2026-05-05T09:04:21+02:00" level=debug msg="app state loaded" May 05 09:04:21 volumio go-librespot[1826]: time="2026-05-05T09:04:21+02:00" level=debug msg="stored credentials not found" May 05 09:04:21 volumio go-librespot[1826]: time="2026-05-05T09:04:21+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:21 volumio go-librespot[1826]: time="2026-05-05T09:04:21+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:24 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:24 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. May 05 09:04:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:24 volumio go-librespot[1834]: go-librespot daemon starting... May 05 09:04:24 volumio go-librespot[1835]: time="2026-05-05T09:04:24+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:24 volumio go-librespot[1835]: time="2026-05-05T09:04:24+02:00" level=debug msg="app state loaded" May 05 09:04:24 volumio go-librespot[1835]: time="2026-05-05T09:04:24+02:00" level=debug msg="stored credentials not found" May 05 09:04:24 volumio go-librespot[1835]: time="2026-05-05T09:04:24+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:24 volumio go-librespot[1835]: time="2026-05-05T09:04:24+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:25 volumio wpa_supplicant[1128]: wlan0: Failed to initiate sched scan May 05 09:04:25 volumio volumio[1166]: info: Received Get System Info May 05 09:04:25 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 05 09:04:25 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 05 09:04:25 volumio volumio[1166]: info: Discovery: Getting this device information May 05 09:04:25 volumio volumio[1166]: info: CoreCommandRouter::volumioGetState May 05 09:04:25 volumio volumio[1166]: info: CorePlayQueue::getTrack 0 May 05 09:04:25 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 05 09:04:25 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 05 09:04:25 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 05 09:04:26 volumio volumio5-onboarding[1498]: time=2026-05-05T09:04:26.583+02:00 level=INFO msg="service successfully established" component=discovery/localnet May 05 09:04:26 volumio nmbd[1041]: [2026/05/05 09:04:26.880193, 0] ../../source3/libsmb/nmblib.c:923(send_udp) May 05 09:04:26 volumio nmbd[1041]: Packet send failed to 192.168.4.255(138) ERRNO=Network is unreachable May 05 09:04:27 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:27 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. May 05 09:04:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:27 volumio go-librespot[1843]: go-librespot daemon starting... May 05 09:04:28 volumio go-librespot[1844]: time="2026-05-05T09:04:28+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:28 volumio go-librespot[1844]: time="2026-05-05T09:04:28+02:00" level=debug msg="app state loaded" May 05 09:04:28 volumio go-librespot[1844]: time="2026-05-05T09:04:28+02:00" level=debug msg="stored credentials not found" May 05 09:04:28 volumio go-librespot[1844]: time="2026-05-05T09:04:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:28 volumio go-librespot[1844]: time="2026-05-05T09:04:28+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:30 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:30 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:30 volumio wpa_supplicant[1128]: wlan0: Failed to initiate sched scan May 05 09:04:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. May 05 09:04:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:31 volumio go-librespot[1853]: go-librespot daemon starting... May 05 09:04:31 volumio volumio[1166]: info: Received Get System Info May 05 09:04:31 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 05 09:04:31 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 05 09:04:31 volumio volumio[1166]: info: Discovery: Getting this device information May 05 09:04:31 volumio volumio[1166]: info: CoreCommandRouter::volumioGetState May 05 09:04:31 volumio volumio[1166]: info: CorePlayQueue::getTrack 0 May 05 09:04:31 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 05 09:04:31 volumio go-librespot[1857]: time="2026-05-05T09:04:31+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:31 volumio go-librespot[1857]: time="2026-05-05T09:04:31+02:00" level=debug msg="app state loaded" May 05 09:04:31 volumio go-librespot[1857]: time="2026-05-05T09:04:31+02:00" level=debug msg="stored credentials not found" May 05 09:04:31 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 05 09:04:31 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 05 09:04:31 volumio go-librespot[1857]: time="2026-05-05T09:04:31+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:31 volumio go-librespot[1857]: time="2026-05-05T09:04:31+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:32 volumio volumio5-onboarding[1498]: time=2026-05-05T09:04:32.302+02:00 level=INFO msg="service successfully established" component=discovery/localnet May 05 09:04:33 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:33 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. May 05 09:04:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:34 volumio go-librespot[1876]: go-librespot daemon starting... May 05 09:04:34 volumio go-librespot[1877]: time="2026-05-05T09:04:34+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:34 volumio go-librespot[1877]: time="2026-05-05T09:04:34+02:00" level=debug msg="app state loaded" May 05 09:04:34 volumio go-librespot[1877]: time="2026-05-05T09:04:34+02:00" level=debug msg="stored credentials not found" May 05 09:04:34 volumio go-librespot[1877]: time="2026-05-05T09:04:34+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:34 volumio go-librespot[1877]: time="2026-05-05T09:04:34+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:36 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:36 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:36 volumio wpa_supplicant[1128]: wlan0: Failed to initiate sched scan May 05 09:04:36 volumio volumio[1166]: info: Received Get System Info May 05 09:04:36 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 05 09:04:36 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 05 09:04:36 volumio volumio[1166]: info: Discovery: Getting this device information May 05 09:04:36 volumio volumio[1166]: info: CoreCommandRouter::volumioGetState May 05 09:04:36 volumio volumio[1166]: info: CorePlayQueue::getTrack 0 May 05 09:04:36 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 05 09:04:36 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 05 09:04:36 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 05 09:04:37 volumio volumio5-onboarding[1498]: time=2026-05-05T09:04:37.787+02:00 level=INFO msg="service successfully established" component=discovery/localnet May 05 09:04:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. May 05 09:04:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:38 volumio go-librespot[1885]: go-librespot daemon starting... May 05 09:04:38 volumio go-librespot[1886]: time="2026-05-05T09:04:38+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:38 volumio go-librespot[1886]: time="2026-05-05T09:04:38+02:00" level=debug msg="app state loaded" May 05 09:04:38 volumio go-librespot[1886]: time="2026-05-05T09:04:38+02:00" level=debug msg="stored credentials not found" May 05 09:04:38 volumio go-librespot[1886]: time="2026-05-05T09:04:38+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:38 volumio go-librespot[1886]: time="2026-05-05T09:04:38+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:39 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:39 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:40 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:40 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. May 05 09:04:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. May 05 09:04:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:41 volumio go-librespot[1894]: go-librespot daemon starting... May 05 09:04:41 volumio go-librespot[1899]: time="2026-05-05T09:04:41+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:41 volumio go-librespot[1899]: time="2026-05-05T09:04:41+02:00" level=debug msg="app state loaded" May 05 09:04:41 volumio go-librespot[1899]: time="2026-05-05T09:04:41+02:00" level=debug msg="stored credentials not found" May 05 09:04:41 volumio go-librespot[1899]: time="2026-05-05T09:04:41+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:41 volumio go-librespot[1899]: time="2026-05-05T09:04:41+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:41 volumio wpa_supplicant[1128]: wlan0: Failed to initiate sched scan May 05 09:04:42 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:42 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:42 volumio volumio[1166]: info: Received Get System Info May 05 09:04:42 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 05 09:04:42 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 05 09:04:42 volumio volumio[1166]: info: Discovery: Getting this device information May 05 09:04:42 volumio volumio[1166]: info: CoreCommandRouter::volumioGetState May 05 09:04:42 volumio volumio[1166]: info: CorePlayQueue::getTrack 0 May 05 09:04:42 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 05 09:04:42 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 05 09:04:42 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 05 09:04:43 volumio volumio5-onboarding[1498]: time=2026-05-05T09:04:43.555+02:00 level=INFO msg="service successfully established" component=discovery/localnet May 05 09:04:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. May 05 09:04:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:44 volumio go-librespot[1917]: go-librespot daemon starting... May 05 09:04:44 volumio go-librespot[1918]: time="2026-05-05T09:04:44+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:44 volumio go-librespot[1918]: time="2026-05-05T09:04:44+02:00" level=debug msg="app state loaded" May 05 09:04:44 volumio go-librespot[1918]: time="2026-05-05T09:04:44+02:00" level=debug msg="stored credentials not found" May 05 09:04:44 volumio go-librespot[1918]: time="2026-05-05T09:04:44+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:44 volumio go-librespot[1918]: time="2026-05-05T09:04:44+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:45 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:45 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:47 volumio wpa_supplicant[1128]: wlan0: Failed to initiate sched scan May 05 09:04:48 volumio volumio[1166]: info: Received Get System Info May 05 09:04:48 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 05 09:04:48 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 05 09:04:48 volumio volumio[1166]: info: Discovery: Getting this device information May 05 09:04:48 volumio volumio[1166]: info: CoreCommandRouter::volumioGetState May 05 09:04:48 volumio volumio[1166]: info: CorePlayQueue::getTrack 0 May 05 09:04:48 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 05 09:04:48 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 05 09:04:48 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 05 09:04:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. May 05 09:04:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:48 volumio go-librespot[1926]: go-librespot daemon starting... May 05 09:04:48 volumio go-librespot[1927]: time="2026-05-05T09:04:48+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:48 volumio go-librespot[1927]: time="2026-05-05T09:04:48+02:00" level=debug msg="app state loaded" May 05 09:04:48 volumio go-librespot[1927]: time="2026-05-05T09:04:48+02:00" level=debug msg="stored credentials not found" May 05 09:04:48 volumio go-librespot[1927]: time="2026-05-05T09:04:48+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:48 volumio go-librespot[1927]: time="2026-05-05T09:04:48+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:48 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:48 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:49 volumio volumio5-onboarding[1498]: time=2026-05-05T09:04:49.093+02:00 level=INFO msg="service successfully established" component=discovery/localnet May 05 09:04:51 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:51 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. May 05 09:04:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:51 volumio go-librespot[1935]: go-librespot daemon starting... May 05 09:04:51 volumio go-librespot[1944]: time="2026-05-05T09:04:51+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:51 volumio go-librespot[1944]: time="2026-05-05T09:04:51+02:00" level=debug msg="app state loaded" May 05 09:04:51 volumio go-librespot[1944]: time="2026-05-05T09:04:51+02:00" level=debug msg="stored credentials not found" May 05 09:04:51 volumio go-librespot[1944]: time="2026-05-05T09:04:51+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:51 volumio go-librespot[1944]: time="2026-05-05T09:04:51+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:53 volumio wpa_supplicant[1128]: wlan0: Trying to associate with 3a:07:16:09:08:c0 (SSID='wifi_annouche' freq=2462 MHz) May 05 09:04:53 volumio wpa_supplicant[1128]: wlan0: Associated with 3a:07:16:09:08:c0 May 05 09:04:53 volumio wpa_supplicant[1128]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 May 05 09:04:53 volumio wpa_supplicant[1128]: wlan0: WPA: Key negotiation completed with 3a:07:16:09:08:c0 [PTK=CCMP GTK=CCMP] May 05 09:04:53 volumio wpa_supplicant[1128]: wlan0: CTRL-EVENT-CONNECTED - Connection to 3a:07:16:09:08:c0 completed [id=0 id_str=] May 05 09:04:53 volumio dhcpcd[774]: wlan0: carrier acquired May 05 09:04:53 volumio dhcpcd[774]: wlan0: IAID eb:3b:76:ea May 05 09:04:54 volumio volumio[1166]: info: Received Get System Info May 05 09:04:54 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 05 09:04:54 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 05 09:04:54 volumio volumio[1166]: info: Discovery: Getting this device information May 05 09:04:54 volumio volumio[1166]: info: CoreCommandRouter::volumioGetState May 05 09:04:54 volumio volumio[1166]: info: CorePlayQueue::getTrack 0 May 05 09:04:54 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 05 09:04:54 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 05 09:04:54 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 05 09:04:54 volumio dhcpcd[774]: wlan0: soliciting an IPv6 router May 05 09:04:54 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:54 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. May 05 09:04:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:54 volumio volumio5-onboarding[1498]: time=2026-05-05T09:04:54.984+02:00 level=INFO msg="service successfully established" component=discovery/localnet May 05 09:04:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:55 volumio go-librespot[1960]: go-librespot daemon starting... May 05 09:04:55 volumio go-librespot[1961]: time="2026-05-05T09:04:55+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:55 volumio go-librespot[1961]: time="2026-05-05T09:04:55+02:00" level=debug msg="app state loaded" May 05 09:04:55 volumio go-librespot[1961]: time="2026-05-05T09:04:55+02:00" level=debug msg="stored credentials not found" May 05 09:04:55 volumio go-librespot[1961]: time="2026-05-05T09:04:55+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:55 volumio go-librespot[1961]: time="2026-05-05T09:04:55+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:04:55 volumio dhcpcd[774]: wlan0: rebinding lease of 192.168.4.200 May 05 09:04:55 volumio dhcpcd[774]: wlan0: probing address 192.168.4.200/24 May 05 09:04:55 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. May 05 09:04:55 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. May 05 09:04:55 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. May 05 09:04:57 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:04:57 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: AggregateError May 05 09:04:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. May 05 09:04:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:04:58 volumio go-librespot[1979]: go-librespot daemon starting... May 05 09:04:58 volumio go-librespot[1980]: time="2026-05-05T09:04:58+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:04:58 volumio go-librespot[1980]: time="2026-05-05T09:04:58+02:00" level=debug msg="app state loaded" May 05 09:04:58 volumio go-librespot[1980]: time="2026-05-05T09:04:58+02:00" level=debug msg="stored credentials not found" May 05 09:04:58 volumio go-librespot[1980]: time="2026-05-05T09:04:58+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:04:58 volumio go-librespot[1980]: time="2026-05-05T09:04:58+02:00" level=fatal msg="failed running zeroconf" 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: device or resource busy" May 05 09:04:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:04:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:05:00 volumio dhcpcd[774]: wlan0: leased 192.168.4.200 for 43200 seconds May 05 09:05:00 volumio avahi-daemon[1302]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.4.200. May 05 09:05:00 volumio avahi-daemon[1302]: New relevant interface wlan0.IPv4 for mDNS. May 05 09:05:00 volumio dhcpcd[774]: wlan0: adding route to 192.168.4.0/24 May 05 09:05:00 volumio avahi-daemon[1302]: Registering new address record for 192.168.4.200 on wlan0.IPv4. May 05 09:05:00 volumio dhcpcd[774]: wlan0: adding default route via 192.168.4.254 May 05 09:05:00 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. May 05 09:05:00 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... May 05 09:05:00 volumio systemd[1]: welcome.service: Deactivated successfully. May 05 09:05:00 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. May 05 09:05:00 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... May 05 09:05:00 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... May 05 09:05:00 volumio welcome[1998]: Resolved ip:[1] 192.168.4.200 May 05 09:05:00 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. May 05 09:05:00 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. May 05 09:05:00 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:05:00 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 05 09:05:00 volumio volumio[1166]: info: Received Get System Info May 05 09:05:00 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 05 09:05:00 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 05 09:05:00 volumio volumio[1166]: info: Discovery: Getting this device information May 05 09:05:00 volumio volumio[1166]: info: CoreCommandRouter::volumioGetState May 05 09:05:00 volumio volumio[1166]: info: CorePlayQueue::getTrack 0 May 05 09:05:00 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 05 09:05:00 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 05 09:05:00 volumio volumio[1166]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 05 09:05:01 volumio volumio[1166]: info: Discovery: adding 5045bc37-05be-44f4-9749-d286d23291cf May 05 09:05:01 volumio volumio[1166]: info: Discovery: Found device Volumio May 05 09:05:01 volumio volumio[1166]: info: CoreCommandRouter::volumioGetState May 05 09:05:01 volumio volumio[1166]: info: CorePlayQueue::getTrack 0 May 05 09:05:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. May 05 09:05:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:05:01 volumio ntpd[929]: IO: Listen normally on 4 wlan0 192.168.4.200:123 May 05 09:05:01 volumio ntpd[929]: IO: new interface(s) found: waking up resolver May 05 09:05:01 volumio ntpd[929]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 May 05 09:05:01 volumio ntpd[929]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 May 05 09:05:01 volumio ntpd[929]: DNS: Pool skipping: 212.27.38.252 May 05 09:05:01 volumio ntpd[929]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 May 05 09:05:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:05:01 volumio go-librespot[2013]: go-librespot daemon starting... May 05 09:05:01 volumio go-librespot[2015]: time="2026-05-05T09:05:01+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:05:01 volumio go-librespot[2015]: time="2026-05-05T09:05:01+02:00" level=debug msg="app state loaded" May 05 09:05:01 volumio go-librespot[2015]: time="2026-05-05T09:05:01+02:00" level=debug msg="stored credentials not found" May 05 09:05:01 volumio go-librespot[2015]: time="2026-05-05T09:05:01+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:05:01 volumio go-librespot[2015]: time="2026-05-05T09:05:01+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp 212.27.38.252:443: connect: network is unreachable" May 05 09:05:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:05:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:05:01 volumio volumio5-onboarding[1498]: time=2026-05-05T09:05:01.904+02:00 level=INFO msg="service successfully established" component=discovery/localnet May 05 09:05:02 volumio volumio[1166]: info: Volumio Network Manager: Network status updated: 2 May 05 09:05:02 volumio ntpd[929]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 May 05 09:05:02 volumio ntpd[929]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 May 05 09:05:02 volumio ntpd[929]: DNS: Pool skipping: 212.27.38.252 May 05 09:05:02 volumio ntpd[929]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 May 05 09:05:03 volumio ntpd[929]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 May 05 09:05:03 volumio ntpd[929]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 May 05 09:05:03 volumio ntpd[929]: DNS: Pool skipping: 212.27.38.252 May 05 09:05:03 volumio ntpd[929]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 May 05 09:05:03 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:05:03 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 05 09:05:04 volumio ntpd[929]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 May 05 09:05:04 volumio ntpd[929]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 May 05 09:05:04 volumio ntpd[929]: DNS: Pool skipping: 212.27.38.252 May 05 09:05:04 volumio ntpd[929]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 May 05 09:05:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. May 05 09:05:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:05:05 volumio go-librespot[2049]: go-librespot daemon starting... May 05 09:05:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:05:05 volumio go-librespot[2050]: time="2026-05-05T09:05:05+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:05:05 volumio go-librespot[2050]: time="2026-05-05T09:05:05+02:00" level=debug msg="app state loaded" May 05 09:05:05 volumio go-librespot[2050]: time="2026-05-05T09:05:05+02:00" level=debug msg="stored credentials not found" May 05 09:05:05 volumio go-librespot[2050]: time="2026-05-05T09:05:05+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:05:05 volumio go-librespot[2050]: time="2026-05-05T09:05:05+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp 212.27.38.252:443: connect: network is unreachable" May 05 09:05:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:05:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:05:06 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:05:06 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 05 09:05:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. May 05 09:05:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:05:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:05:08 volumio go-librespot[2058]: go-librespot daemon starting... May 05 09:05:08 volumio go-librespot[2059]: time="2026-05-05T09:05:08+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:05:08 volumio go-librespot[2059]: time="2026-05-05T09:05:08+02:00" level=debug msg="app state loaded" May 05 09:05:08 volumio go-librespot[2059]: time="2026-05-05T09:05:08+02:00" level=debug msg="stored credentials not found" May 05 09:05:08 volumio go-librespot[2059]: time="2026-05-05T09:05:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:05:08 volumio go-librespot[2059]: time="2026-05-05T09:05:08+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp 212.27.38.252:443: connect: network is unreachable" May 05 09:05:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:05:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:05:09 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:05:09 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 05 09:05:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. May 05 09:05:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:05:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:05:11 volumio go-librespot[2067]: go-librespot daemon starting... May 05 09:05:11 volumio go-librespot[2068]: time="2026-05-05T09:05:11+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:05:11 volumio go-librespot[2068]: time="2026-05-05T09:05:11+02:00" level=debug msg="app state loaded" May 05 09:05:11 volumio go-librespot[2068]: time="2026-05-05T09:05:11+02:00" level=debug msg="stored credentials not found" May 05 09:05:11 volumio go-librespot[2068]: time="2026-05-05T09:05:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:05:12 volumio go-librespot[2068]: time="2026-05-05T09:05:12+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2026-05-05T09:05:11+02:00 is before 2026-07-09T00:00:00Z" May 05 09:05:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:05:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:05:12 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:05:13 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 05 09:05:14 volumio upmpdcli[2091]: writing RSA key May 05 09:05:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. May 05 09:05:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:05:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:05:15 volumio go-librespot[2097]: go-librespot daemon starting... May 05 09:05:15 volumio go-librespot[2098]: time="2026-05-05T09:05:15+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:05:15 volumio go-librespot[2098]: time="2026-05-05T09:05:15+02:00" level=debug msg="app state loaded" May 05 09:05:15 volumio go-librespot[2098]: time="2026-05-05T09:05:15+02:00" level=debug msg="stored credentials not found" May 05 09:05:15 volumio go-librespot[2098]: time="2026-05-05T09:05:15+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:05:15 volumio go-librespot[2098]: time="2026-05-05T09:05:15+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2026-05-05T09:05:15+02:00 is before 2026-07-09T00:00:00Z" May 05 09:05:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:05:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:05:16 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:05:16 volumio volumio[1166]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 May 05 09:05:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. May 05 09:05:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:05:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:05:18 volumio go-librespot[2108]: go-librespot daemon starting... May 05 09:05:18 volumio go-librespot[2109]: time="2026-05-05T09:05:18+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:05:18 volumio go-librespot[2109]: time="2026-05-05T09:05:18+02:00" level=debug msg="app state loaded" May 05 09:05:18 volumio go-librespot[2109]: time="2026-05-05T09:05:18+02:00" level=debug msg="stored credentials not found" May 05 09:05:19 volumio go-librespot[2109]: time="2026-05-05T09:05:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:05:19 volumio volumio[1166]: info: Initializing connection to go-librespot Websocket May 05 09:05:19 volumio go-librespot[2109]: time="2026-05-05T09:05:19+02:00" level=debug msg="new websocket client" May 05 09:05:19 volumio volumio[1166]: info: Connection to go-librespot Websocket established May 05 09:05:19 volumio go-librespot[2109]: time="2026-05-05T09:05:19+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2026-05-05T09:05:19+02:00 is before 2026-07-09T00:00:00Z" May 05 09:05:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:05:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:05:19 volumio volumio[1166]: info: Connection to go-librespot Websocket closed May 05 09:05:22 volumio volumio[1166]: info: Getting Spotify volume May 05 09:05:22 volumio volumio[1166]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 05 09:05:22 volumio volumio[1166]: Error: connect ECONNREFUSED 127.0.0.1:9879 May 05 09:05:22 volumio volumio[1166]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { May 05 09:05:22 volumio volumio[1166]: errno: -111, May 05 09:05:22 volumio volumio[1166]: code: 'ECONNREFUSED', May 05 09:05:22 volumio volumio[1166]: syscall: 'connect', May 05 09:05:22 volumio volumio[1166]: address: '127.0.0.1', May 05 09:05:22 volumio volumio[1166]: port: 9879, May 05 09:05:22 volumio volumio[1166]: response: undefined May 05 09:05:22 volumio volumio[1166]: } May 05 09:05:22 volumio volumio[1166]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 05 09:05:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. May 05 09:05:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:05:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:05:22 volumio go-librespot[2121]: go-librespot daemon starting... May 05 09:05:22 volumio go-librespot[2123]: time="2026-05-05T09:05:22+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:05:22 volumio go-librespot[2123]: time="2026-05-05T09:05:22+02:00" level=debug msg="app state loaded" May 05 09:05:22 volumio go-librespot[2123]: time="2026-05-05T09:05:22+02:00" level=debug msg="stored credentials not found" May 05 09:05:22 volumio go-librespot[2123]: time="2026-05-05T09:05:22+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:05:23 volumio go-librespot[2123]: time="2026-05-05T09:05:23+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2026-05-05T09:05:22+02:00 is before 2026-07-09T00:00:00Z" May 05 09:05:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:05:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:05:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. May 05 09:05:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 05 09:05:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 05 09:05:26 volumio go-librespot[2155]: go-librespot daemon starting... May 05 09:05:26 volumio go-librespot[2156]: time="2026-05-05T09:05:26+02:00" level=info msg="running go-librespot 0.7.1" May 05 09:05:26 volumio go-librespot[2156]: time="2026-05-05T09:05:26+02:00" level=debug msg="app state loaded" May 05 09:05:26 volumio go-librespot[2156]: time="2026-05-05T09:05:26+02:00" level=debug msg="stored credentials not found" May 05 09:05:26 volumio go-librespot[2156]: time="2026-05-05T09:05:26+02:00" level=info msg="api server listening on 127.0.0.1:9879" May 05 09:05:26 volumio go-librespot[2156]: time="2026-05-05T09:05:26+02:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2026-05-05T09:05:26+02:00 is before 2026-07-09T00:00:00Z" May 05 09:05:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 05 09:05:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 05 09:05:27 volumio sudo[2167]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-05 09:04' May 05 09:05:27 volumio sudo[2167]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"