Mar 28 12:12:02 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:02 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:03 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 28 12:12:03 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:03 hudba volumio[8242]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=4.119&uuid=ee3102c61c99d2809dc3d08548163f67" http://updates.volumio.org/downloader-v1/track-device Mar 28 12:12:03 hudba volumio[8242]: curl: (6) Could not resolve host: updates.volumio.org Mar 28 12:12:03 hudba volumio[8242]: retrying in 5 seconds, trial 0 Mar 28 12:12:03 hudba volumio[8242]: info: Volumio Calling Home Mar 28 12:12:03 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:03 hudba go-librespot[8571]: go-librespot daemon starting... Mar 28 12:12:03 hudba go-librespot[8573]: time="2026-03-28T12:12:03+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:03 hudba go-librespot[8573]: time="2026-03-28T12:12:03+01:00" level=debug msg="app state loaded" Mar 28 12:12:03 hudba go-librespot[8573]: time="2026-03-28T12:12:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:03 hudba go-librespot[8573]: time="2026-03-28T12:12:03+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:03 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:03 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:03 hudba volumio[8242]: info: Received Get System Info Mar 28 12:12:03 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 12:12:03 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 12:12:03 hudba volumio[8242]: info: Discovery: Getting this device information Mar 28 12:12:03 hudba volumio[8242]: info: CoreCommandRouter::volumioGetState Mar 28 12:12:03 hudba volumio[8242]: info: CorePlayQueue::getTrack 0 Mar 28 12:12:03 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 12:12:03 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 28 12:12:03 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 28 12:12:03 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:03.571+01:00 level=INFO msg="enabling BLE discovery" Mar 28 12:12:03 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:03.573+01:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Mar 28 12:12:04 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:04.325+01:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 28 12:12:05 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:05 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:06 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 28 12:12:06 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:06 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:06 hudba go-librespot[8586]: go-librespot daemon starting... Mar 28 12:12:06 hudba go-librespot[8587]: time="2026-03-28T12:12:06+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:06 hudba go-librespot[8587]: time="2026-03-28T12:12:06+01:00" level=debug msg="app state loaded" Mar 28 12:12:06 hudba go-librespot[8587]: time="2026-03-28T12:12:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:06 hudba go-librespot[8587]: time="2026-03-28T12:12:06+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:06 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:06 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:08 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:08 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:09 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 28 12:12:09 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:09 hudba volumio[8242]: info: Received Get System Info Mar 28 12:12:09 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 12:12:09 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 12:12:09 hudba volumio[8242]: info: Discovery: Getting this device information Mar 28 12:12:09 hudba volumio[8242]: info: CoreCommandRouter::volumioGetState Mar 28 12:12:09 hudba volumio[8242]: info: CorePlayQueue::getTrack 0 Mar 28 12:12:09 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 12:12:09 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 28 12:12:09 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 28 12:12:09 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:09 hudba go-librespot[8613]: go-librespot daemon starting... Mar 28 12:12:09 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:09.586+01:00 level=INFO msg="enabling BLE discovery" Mar 28 12:12:09 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:09.589+01:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Mar 28 12:12:09 hudba go-librespot[8614]: time="2026-03-28T12:12:09+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:09 hudba go-librespot[8614]: time="2026-03-28T12:12:09+01:00" level=debug msg="app state loaded" Mar 28 12:12:09 hudba go-librespot[8614]: time="2026-03-28T12:12:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:09 hudba go-librespot[8614]: time="2026-03-28T12:12:09+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:09 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:09 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:10 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:10.341+01:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 28 12:12:11 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:11 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:12 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 28 12:12:12 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:12 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:12 hudba go-librespot[8625]: go-librespot daemon starting... Mar 28 12:12:12 hudba go-librespot[8626]: time="2026-03-28T12:12:12+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:12 hudba go-librespot[8626]: time="2026-03-28T12:12:12+01:00" level=debug msg="app state loaded" Mar 28 12:12:12 hudba go-librespot[8626]: time="2026-03-28T12:12:12+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:12 hudba go-librespot[8626]: time="2026-03-28T12:12:12+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:12 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:12 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:13 hudba volumio[8242]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=4.119&uuid=ee3102c61c99d2809dc3d08548163f67" http://updates.volumio.org/downloader-v1/track-device Mar 28 12:12:13 hudba volumio[8242]: % Total % Received % Xferd Average Speed Time Time Time Current Mar 28 12:12:13 hudba volumio[8242]: Dload Upload Total Spent Left Speed Mar 28 12:12:13 hudba volumio[8242]: [132B blob data] Mar 28 12:12:13 hudba volumio[8242]: retrying in 5 seconds, trial 1 Mar 28 12:12:13 hudba volumio[8242]: info: Volumio Calling Home Mar 28 12:12:13 hudba volumio[8242]: error: MyVolumio Plugin failed to start in a timely fashion Mar 28 12:12:13 hudba volumio[8242]: [Metrics] CommandRouter: 27s 747.27ms Mar 28 12:12:13 hudba volumio[8242]: info: CoreCommandRouter::volumiosetStartupVolume Mar 28 12:12:13 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 28 12:12:13 hudba volumio[8242]: info: VolumeController:: Setting startup Volume 40 Mar 28 12:12:13 hudba volumio[8242]: info: VolumeController::SetAlsaVolume40 Mar 28 12:12:13 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 12:12:13 hudba volumio[8242]: info: CoreCommandRouter::Close All Modals sent Mar 28 12:12:13 hudba volumio[8242]: info: CoreCommandRouter::Close All Modals sent Mar 28 12:12:13 hudba volumio[8242]: info: CoreStateMachine::pushState Mar 28 12:12:13 hudba volumio[8242]: info: CorePlayQueue::getTrack 0 Mar 28 12:12:13 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 12:12:13 hudba volumio[8242]: info: CoreCommandRouter::volumioPushState Mar 28 12:12:14 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:14 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:14 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 28 12:12:14 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 28 12:12:15 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 28 12:12:15 hudba volumio[8242]: info: Received Get System Info Mar 28 12:12:15 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 12:12:15 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 12:12:15 hudba volumio[8242]: info: Discovery: Getting this device information Mar 28 12:12:15 hudba volumio[8242]: info: CoreCommandRouter::volumioGetState Mar 28 12:12:15 hudba volumio[8242]: info: CorePlayQueue::getTrack 0 Mar 28 12:12:15 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 12:12:15 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 28 12:12:15 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 28 12:12:15 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:15.580+01:00 level=INFO msg="enabling BLE discovery" Mar 28 12:12:15 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:15.582+01:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Mar 28 12:12:16 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 28 12:12:16 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:16 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:16 hudba go-librespot[8648]: go-librespot daemon starting... Mar 28 12:12:16 hudba go-librespot[8649]: time="2026-03-28T12:12:16+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:16 hudba go-librespot[8649]: time="2026-03-28T12:12:16+01:00" level=debug msg="app state loaded" Mar 28 12:12:16 hudba go-librespot[8649]: time="2026-03-28T12:12:16+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:16 hudba go-librespot[8649]: time="2026-03-28T12:12:16+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:16 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:16 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:16 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:16.555+01:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 28 12:12:17 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:17 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:19 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 28 12:12:19 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:19 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:19 hudba go-librespot[8674]: go-librespot daemon starting... Mar 28 12:12:19 hudba go-librespot[8675]: time="2026-03-28T12:12:19+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:19 hudba go-librespot[8675]: time="2026-03-28T12:12:19+01:00" level=debug msg="app state loaded" Mar 28 12:12:19 hudba go-librespot[8675]: time="2026-03-28T12:12:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:19 hudba go-librespot[8675]: time="2026-03-28T12:12:19+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:19 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:19 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:20 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:20 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:20 hudba volumio[8242]: info: BOOT COMPLETED Mar 28 12:12:21 hudba volumio[8242]: info: Received Get System Info Mar 28 12:12:21 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 12:12:21 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 12:12:21 hudba volumio[8242]: info: Discovery: Getting this device information Mar 28 12:12:21 hudba volumio[8242]: info: CoreCommandRouter::volumioGetState Mar 28 12:12:21 hudba volumio[8242]: info: CorePlayQueue::getTrack 0 Mar 28 12:12:21 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 12:12:21 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 28 12:12:21 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 28 12:12:21 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:21.556+01:00 level=INFO msg="enabling BLE discovery" Mar 28 12:12:21 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:21.558+01:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Mar 28 12:12:22 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:22.532+01:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 28 12:12:22 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 28 12:12:22 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:22 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:22 hudba go-librespot[8687]: go-librespot daemon starting... Mar 28 12:12:22 hudba go-librespot[8688]: time="2026-03-28T12:12:22+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:22 hudba go-librespot[8688]: time="2026-03-28T12:12:22+01:00" level=debug msg="app state loaded" Mar 28 12:12:22 hudba go-librespot[8688]: time="2026-03-28T12:12:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:22 hudba go-librespot[8688]: time="2026-03-28T12:12:22+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:22 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:22 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:22 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 28 12:12:22 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 12:12:22 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 28 12:12:23 hudba volumio[8242]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=x86_amd64&variante=volumio&version=4.119&uuid=ee3102c61c99d2809dc3d08548163f67" http://updates.volumio.org/downloader-v1/track-device Mar 28 12:12:23 hudba volumio[8242]: % Total % Received % Xferd Average Speed Time Time Time Current Mar 28 12:12:23 hudba volumio[8242]: Dload Upload Total Spent Left Speed Mar 28 12:12:23 hudba volumio[8242]: [132B blob data] Mar 28 12:12:23 hudba volumio[8242]: retrying in 5 seconds, trial 2 Mar 28 12:12:23 hudba volumio[8242]: info: Volumio Calling Home Mar 28 12:12:23 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:23 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:25 hudba systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Mar 28 12:12:25 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 28 12:12:25 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:25 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:25 hudba go-librespot[8726]: go-librespot daemon starting... Mar 28 12:12:25 hudba go-librespot[8727]: time="2026-03-28T12:12:25+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:25 hudba go-librespot[8727]: time="2026-03-28T12:12:25+01:00" level=debug msg="app state loaded" Mar 28 12:12:25 hudba go-librespot[8727]: time="2026-03-28T12:12:25+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:25 hudba go-librespot[8727]: time="2026-03-28T12:12:25+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:25 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:25 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:26 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:26 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:27 hudba volumio[8242]: info: Received Get System Info Mar 28 12:12:27 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 12:12:27 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 12:12:27 hudba volumio[8242]: info: Discovery: Getting this device information Mar 28 12:12:27 hudba volumio[8242]: info: CoreCommandRouter::volumioGetState Mar 28 12:12:27 hudba volumio[8242]: info: CorePlayQueue::getTrack 0 Mar 28 12:12:27 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 12:12:27 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 28 12:12:27 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 28 12:12:27 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:27.548+01:00 level=INFO msg="enabling BLE discovery" Mar 28 12:12:27 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:27.550+01:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Mar 28 12:12:28 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:28.419+01:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 28 12:12:29 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 28 12:12:29 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:29 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:29 hudba go-librespot[8771]: go-librespot daemon starting... Mar 28 12:12:29 hudba go-librespot[8772]: time="2026-03-28T12:12:29+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:29 hudba go-librespot[8772]: time="2026-03-28T12:12:29+01:00" level=debug msg="app state loaded" Mar 28 12:12:29 hudba go-librespot[8772]: time="2026-03-28T12:12:29+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:29 hudba go-librespot[8772]: time="2026-03-28T12:12:29+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:29 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:29 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:29 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:29 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:30 hudba bash[8705]: setdatetime-helper: all HTTPS Date fallbacks failed Mar 28 12:12:30 hudba systemd[1]: setdatetime-helper.service: Deactivated successfully. Mar 28 12:12:30 hudba systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Mar 28 12:12:32 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Mar 28 12:12:32 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:32 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:32 hudba go-librespot[8791]: go-librespot daemon starting... Mar 28 12:12:32 hudba go-librespot[8792]: time="2026-03-28T12:12:32+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:32 hudba go-librespot[8792]: time="2026-03-28T12:12:32+01:00" level=debug msg="app state loaded" Mar 28 12:12:32 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:32 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:32 hudba go-librespot[8792]: time="2026-03-28T12:12:32+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:32 hudba go-librespot[8792]: time="2026-03-28T12:12:32+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:32 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:32 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:33 hudba volumio[8242]: info: Received Get System Info Mar 28 12:12:33 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 12:12:33 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 12:12:33 hudba volumio[8242]: info: Discovery: Getting this device information Mar 28 12:12:33 hudba volumio[8242]: info: CoreCommandRouter::volumioGetState Mar 28 12:12:33 hudba volumio[8242]: info: CorePlayQueue::getTrack 0 Mar 28 12:12:33 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 12:12:33 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 28 12:12:33 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 28 12:12:33 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:33.528+01:00 level=INFO msg="enabling BLE discovery" Mar 28 12:12:33 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:33.530+01:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Mar 28 12:12:34 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:34.432+01:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 28 12:12:35 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:35 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:35 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Mar 28 12:12:35 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:35 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:35 hudba go-librespot[8805]: go-librespot daemon starting... Mar 28 12:12:35 hudba go-librespot[8806]: time="2026-03-28T12:12:35+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:35 hudba go-librespot[8806]: time="2026-03-28T12:12:35+01:00" level=debug msg="app state loaded" Mar 28 12:12:35 hudba go-librespot[8806]: time="2026-03-28T12:12:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:35 hudba go-librespot[8806]: time="2026-03-28T12:12:35+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:35 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:35 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:38 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:38 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:38 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Mar 28 12:12:38 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:38 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:38 hudba go-librespot[8832]: go-librespot daemon starting... Mar 28 12:12:38 hudba go-librespot[8833]: time="2026-03-28T12:12:38+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:38 hudba go-librespot[8833]: time="2026-03-28T12:12:38+01:00" level=debug msg="app state loaded" Mar 28 12:12:38 hudba go-librespot[8833]: time="2026-03-28T12:12:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:38 hudba go-librespot[8833]: time="2026-03-28T12:12:38+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:38 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:38 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:39 hudba volumio[8242]: info: Received Get System Info Mar 28 12:12:39 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 12:12:39 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 12:12:39 hudba volumio[8242]: info: Discovery: Getting this device information Mar 28 12:12:39 hudba volumio[8242]: info: CoreCommandRouter::volumioGetState Mar 28 12:12:39 hudba volumio[8242]: info: CorePlayQueue::getTrack 0 Mar 28 12:12:39 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 12:12:39 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 28 12:12:39 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 28 12:12:39 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:39.540+01:00 level=INFO msg="enabling BLE discovery" Mar 28 12:12:39 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:39.543+01:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Mar 28 12:12:40 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:40.445+01:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 28 12:12:41 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:41 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:42 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Mar 28 12:12:42 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:42 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:42 hudba go-librespot[8844]: go-librespot daemon starting... Mar 28 12:12:42 hudba go-librespot[8845]: time="2026-03-28T12:12:42+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:42 hudba go-librespot[8845]: time="2026-03-28T12:12:42+01:00" level=debug msg="app state loaded" Mar 28 12:12:42 hudba go-librespot[8845]: time="2026-03-28T12:12:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:42 hudba go-librespot[8845]: time="2026-03-28T12:12:42+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:42 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:42 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:44 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:44 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:44 hudba wpa_supplicant[1243]: wlan0: SME: Trying to authenticate with 30:68:93:02:fa:75 (SSID='TP-Link_FA75' freq=2417 MHz) Mar 28 12:12:45 hudba kernel: wlan0: authenticate with 30:68:93:02:fa:75 (local address=c0:18:85:79:67:ab) Mar 28 12:12:45 hudba kernel: wlan0: send auth to 30:68:93:02:fa:75 (try 1/3) Mar 28 12:12:45 hudba kernel: wlan0: authenticated Mar 28 12:12:45 hudba wpa_supplicant[1243]: wlan0: Trying to associate with 30:68:93:02:fa:75 (SSID='TP-Link_FA75' freq=2417 MHz) Mar 28 12:12:45 hudba kernel: wlan0: associate with 30:68:93:02:fa:75 (try 1/3) Mar 28 12:12:45 hudba wpa_supplicant[1243]: wlan0: Associated with 30:68:93:02:fa:75 Mar 28 12:12:45 hudba wpa_supplicant[1243]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Mar 28 12:12:45 hudba kernel: wlan0: RX AssocResp from 30:68:93:02:fa:75 (capab=0x411 status=0 aid=2) Mar 28 12:12:45 hudba kernel: wlan0: associated Mar 28 12:12:45 hudba wpa_supplicant[1243]: RRM: Ignoring radio measurement request: Not associated Mar 28 12:12:45 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Mar 28 12:12:45 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:45 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:45 hudba go-librespot[8857]: go-librespot daemon starting... Mar 28 12:12:45 hudba go-librespot[8858]: time="2026-03-28T12:12:45+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:45 hudba go-librespot[8858]: time="2026-03-28T12:12:45+01:00" level=debug msg="app state loaded" Mar 28 12:12:45 hudba go-librespot[8858]: time="2026-03-28T12:12:45+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:45 hudba go-librespot[8858]: time="2026-03-28T12:12:45+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:45 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:45 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:45 hudba volumio[8242]: info: Received Get System Info Mar 28 12:12:45 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 12:12:45 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 12:12:45 hudba volumio[8242]: info: Discovery: Getting this device information Mar 28 12:12:45 hudba volumio[8242]: info: CoreCommandRouter::volumioGetState Mar 28 12:12:45 hudba volumio[8242]: info: CorePlayQueue::getTrack 0 Mar 28 12:12:45 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 12:12:45 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 28 12:12:45 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 28 12:12:45 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:45.551+01:00 level=INFO msg="enabling BLE discovery" Mar 28 12:12:45 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:45.553+01:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Mar 28 12:12:45 hudba nmbd[1164]: [2026/03/28 12:12:45.604777, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Mar 28 12:12:45 hudba nmbd[1164]: Packet send failed to 192.168.0.255(138) ERRNO=Network is unreachable Mar 28 12:12:45 hudba nmbd[1164]: [2026/03/28 12:12:45.612142, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Mar 28 12:12:45 hudba nmbd[1164]: Packet send failed to 192.168.0.255(137) ERRNO=Network is unreachable Mar 28 12:12:45 hudba nmbd[1164]: [2026/03/28 12:12:45.612377, 0] ../../source3/nmbd/nmbd_packets.c:180(send_netbios_packet) Mar 28 12:12:45 hudba nmbd[1164]: send_netbios_packet: send_packet() to IP 192.168.0.255 port 137 failed Mar 28 12:12:45 hudba nmbd[1164]: [2026/03/28 12:12:45.612485, 0] ../../source3/nmbd/nmbd_namequery.c:245(query_name) Mar 28 12:12:45 hudba nmbd[1164]: query_name: Failed to send packet trying to query name WORKGROUP<1d> Mar 28 12:12:46 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:46.420+01:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 28 12:12:47 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:47 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:48 hudba wpa_supplicant[1243]: wlan0: WPA: Key negotiation completed with 30:68:93:02:fa:75 [PTK=CCMP GTK=CCMP] Mar 28 12:12:48 hudba wpa_supplicant[1243]: wlan0: CTRL-EVENT-CONNECTED - Connection to 30:68:93:02:fa:75 completed [id=0 id_str=] Mar 28 12:12:48 hudba dhcpcd[806]: wlan0: carrier acquired Mar 28 12:12:48 hudba dhcpcd[806]: wlan0: IAID 85:79:67:ab Mar 28 12:12:48 hudba dhcpcd[806]: wlan0: rebinding lease of 192.168.0.105 Mar 28 12:12:48 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Mar 28 12:12:48 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:48 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:48 hudba go-librespot[8888]: go-librespot daemon starting... Mar 28 12:12:48 hudba go-librespot[8889]: time="2026-03-28T12:12:48+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:48 hudba go-librespot[8889]: time="2026-03-28T12:12:48+01:00" level=debug msg="app state loaded" Mar 28 12:12:48 hudba go-librespot[8889]: time="2026-03-28T12:12:48+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:48 hudba go-librespot[8889]: time="2026-03-28T12:12:48+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:48 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:48 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:48 hudba volumio[8242]: info: Received Get System Info Mar 28 12:12:48 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 12:12:48 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 12:12:48 hudba volumio[8242]: info: Discovery: Getting this device information Mar 28 12:12:48 hudba volumio[8242]: info: CoreCommandRouter::volumioGetState Mar 28 12:12:48 hudba volumio[8242]: info: CorePlayQueue::getTrack 0 Mar 28 12:12:48 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 12:12:48 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 28 12:12:48 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 28 12:12:48 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:48.814+01:00 level=INFO msg="enabling BLE discovery" Mar 28 12:12:48 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:48.816+01:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Mar 28 12:12:49 hudba dhcpcd[806]: wlan0: soliciting an IPv6 router Mar 28 12:12:49 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:49.684+01:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 28 12:12:50 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:50 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:51 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Mar 28 12:12:51 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:51 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:51 hudba go-librespot[8900]: go-librespot daemon starting... Mar 28 12:12:51 hudba go-librespot[8901]: time="2026-03-28T12:12:51+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:51 hudba go-librespot[8901]: time="2026-03-28T12:12:51+01:00" level=debug msg="app state loaded" Mar 28 12:12:51 hudba go-librespot[8901]: time="2026-03-28T12:12:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:51 hudba go-librespot[8901]: time="2026-03-28T12:12:51+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:51 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:51 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:52 hudba wpa_supplicant[1243]: wlan0: CTRL-EVENT-BEACON-LOSS Mar 28 12:12:53 hudba dhcpcd[806]: wlan0: probing address 192.168.0.105/24 Mar 28 12:12:53 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:53 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:55 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Mar 28 12:12:55 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:55 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:55 hudba go-librespot[8912]: go-librespot daemon starting... Mar 28 12:12:55 hudba go-librespot[8913]: time="2026-03-28T12:12:55+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:55 hudba go-librespot[8913]: time="2026-03-28T12:12:55+01:00" level=debug msg="app state loaded" Mar 28 12:12:55 hudba go-librespot[8913]: time="2026-03-28T12:12:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:55 hudba go-librespot[8913]: time="2026-03-28T12:12:55+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\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 28 12:12:55 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:12:55 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:12:56 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:56 hudba volumio[8242]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 28 12:12:57 hudba dhcpcd[806]: wlan0: leased 192.168.0.105 for 7200 seconds Mar 28 12:12:57 hudba avahi-daemon[1510]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.105. Mar 28 12:12:57 hudba avahi-daemon[1510]: New relevant interface wlan0.IPv4 for mDNS. Mar 28 12:12:57 hudba avahi-daemon[1510]: Registering new address record for 192.168.0.105 on wlan0.IPv4. Mar 28 12:12:57 hudba dhcpcd[806]: wlan0: adding route to 192.168.0.0/24 Mar 28 12:12:57 hudba dhcpcd[806]: wlan0: adding default route via 192.168.0.1 Mar 28 12:12:57 hudba systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Mar 28 12:12:57 hudba systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Mar 28 12:12:57 hudba systemd[1]: welcome.service: Deactivated successfully. Mar 28 12:12:57 hudba systemd[1]: Stopped welcome.service - Show a welcome message on console. Mar 28 12:12:57 hudba systemd[1]: Stopping welcome.service - Show a welcome message on console... Mar 28 12:12:57 hudba systemd[1]: Starting welcome.service - Show a welcome message on console... Mar 28 12:12:57 hudba welcome[8939]: Resolved ip:[1] 192.168.0.105 Mar 28 12:12:58 hudba systemd[1]: Finished welcome.service - Show a welcome message on console. Mar 28 12:12:58 hudba systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Mar 28 12:12:58 hudba volumio[8242]: info: Volumio Network Manager: Network status updated: 2 Mar 28 12:12:58 hudba systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Mar 28 12:12:58 hudba systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:58 hudba systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 28 12:12:58 hudba go-librespot[8963]: go-librespot daemon starting... Mar 28 12:12:58 hudba go-librespot[8964]: time="2026-03-28T12:12:58+01:00" level=info msg="running go-librespot 0.7.1" Mar 28 12:12:58 hudba go-librespot[8964]: time="2026-03-28T12:12:58+01:00" level=debug msg="app state loaded" Mar 28 12:12:58 hudba go-librespot[8964]: time="2026-03-28T12:12:58+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 28 12:12:58 hudba volumio[8242]: info: Received Get System Info Mar 28 12:12:58 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 28 12:12:58 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 28 12:12:58 hudba volumio[8242]: info: Discovery: Getting this device information Mar 28 12:12:58 hudba volumio[8242]: info: CoreCommandRouter::volumioGetState Mar 28 12:12:58 hudba volumio[8242]: info: CorePlayQueue::getTrack 0 Mar 28 12:12:58 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 28 12:12:58 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 28 12:12:58 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 28 12:12:58 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:58.404+01:00 level=INFO msg="enabling BLE discovery" Mar 28 12:12:58 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:58.406+01:00 level=ERROR msg="failed to enable BLE discovery" error="failed to listen for BLE connections: failed to add service to adapter: Method \"RegisterApplication\" with signature \"oa{sv}\" on interface \"org.bluez.GattManager1\" doesn't exist\n" Mar 28 12:12:58 hudba wpa_supplicant[1243]: wlan0: CTRL-EVENT-BEACON-LOSS Mar 28 12:12:59 hudba volumio[8242]: info: Initializing connection to go-librespot Websocket Mar 28 12:12:59 hudba go-librespot[8964]: time="2026-03-28T12:12:59+01:00" level=debug msg="new websocket client" Mar 28 12:12:59 hudba volumio5-onboarding[2325]: time=2026-03-28T12:12:59.406+01:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 28 12:12:59 hudba volumio[8242]: info: Connection to go-librespot Websocket established Mar 28 12:12:59 hudba ntpd[1119]: IO: Listen normally on 16 wlan0 192.168.0.105:123 Mar 28 12:12:59 hudba ntpd[1119]: IO: new interface(s) found: waking up resolver Mar 28 12:13:02 hudba volumio[8242]: info: Getting Spotify volume Mar 28 12:13:02 hudba volumio[8242]: 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 28 12:13:02 hudba volumio[8242]: info: CoreCommandRouter::volumioGetState Mar 28 12:13:02 hudba volumio[8242]: info: CorePlayQueue::getTrack 0 Mar 28 12:13:02 hudba volumio[8242]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Mar 28 12:13:02 hudba volumio[8242]: SPOTIFY: SPOTIFY VOLUME undefined Mar 28 12:13:02 hudba volumio[8242]: SPOTIFY: VOLUMIO VOLUME 40 Mar 28 12:13:02 hudba volumio[8242]: info: Aligning Spotify Volume to Volumio Volume Mar 28 12:13:02 hudba volumio[8242]: info: CoreCommandRouter::volumioGetState Mar 28 12:13:02 hudba volumio[8242]: info: CorePlayQueue::getTrack 0 Mar 28 12:13:02 hudba volumio[8242]: info: Setting Spotify Volume from Volumio: 40 Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 28 12:13:03 hudba volumio[8242]: info: Adding plugin bluetooth to MyMusic Plugins Mar 28 12:13:03 hudba volumio[8242]: info: Adding plugin multiroom to MyMusic Plugins Mar 28 12:13:03 hudba volumio[8242]: info: Adding plugin metavolumio to MyMusic Plugins Mar 28 12:13:03 hudba volumio[8242]: info: Adding plugin cd_controller to MyMusic Plugins Mar 28 12:13:03 hudba volumio[8242]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 28 12:13:03 hudba volumio[8242]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 28 12:13:03 hudba volumio[8242]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 28 12:13:03 hudba volumio[8242]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 28 12:13:04 hudba volumio[8242]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 28 12:13:04 hudba volumio[8242]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 28 12:13:04 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 12:13:04 hudba volumio[8242]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 28 12:13:04 hudba volumio[8242]: info: Starting MyVolumio Remote Streaming Endpoints Mar 28 12:13:04 hudba volumio[8242]: info: MyVolumio login type: Token Mar 28 12:13:04 hudba volumio[8242]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 28 12:13:04 hudba volumio[8242]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 28 12:13:05 hudba volumio[8242]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 28 12:13:05 hudba volumio[8242]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 28 12:13:05 hudba volumio[8242]: info: Streaming services startup Mar 28 12:13:05 hudba volumio[8242]: info: Starting Streaming Daemon Mar 28 12:13:05 hudba sudo[8981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 28 12:13:05 hudba sudo[8981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 28 12:13:05 hudba volumio[8242]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 28 12:13:05 hudba sudo[8981]: pam_unix(sudo:session): session closed for user root Mar 28 12:13:05 hudba volumio[8242]: SPOTIFY: SETTING SPOTIFY VOLUME 40 Mar 28 12:13:05 hudba volumio[8242]: info: Sending Spotify command with payload to local API: /player/volume Mar 28 12:13:05 hudba volumio[8242]: error: Cannot start Volumio Streaming Daemon Mar 28 12:13:05 hudba volumio[8242]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 28 12:13:05 hudba volumio[8242]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 28 12:13:05 hudba volumio[8242]: info: Discovery: this is already registered, ae412730-5e6a-429a-9912-105bacee40ef Mar 28 12:13:05 hudba volumio[8242]: info: Discovery: Found device Hudba Mar 28 12:13:05 hudba volumio[8242]: info: CoreCommandRouter::volumioGetState Mar 28 12:13:05 hudba volumio[8242]: info: CorePlayQueue::getTrack 0 Mar 28 12:13:16 hudba go-librespot[8964]: time="2026-03-28T12:13:16+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\": net/http: TLS handshake timeout" Mar 28 12:13:16 hudba systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 28 12:13:16 hudba systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 28 12:13:16 hudba volumio[8242]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Mar 28 12:13:16 hudba volumio[8242]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 12:13:16 hudba volumio[8242]: Error: socket hang up Mar 28 12:13:16 hudba volumio[8242]: at connResetException (node:internal/errors:720:14) Mar 28 12:13:16 hudba volumio[8242]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 28 12:13:16 hudba volumio[8242]: at Socket.emit (node:events:526:35) Mar 28 12:13:16 hudba volumio[8242]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 28 12:13:16 hudba volumio[8242]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 28 12:13:16 hudba volumio[8242]: code: 'ECONNRESET', Mar 28 12:13:16 hudba volumio[8242]: response: undefined Mar 28 12:13:16 hudba volumio[8242]: } Mar 28 12:13:16 hudba volumio[8242]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 12:13:16 hudba sudo[9038]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-28 12:12' Mar 28 12:13:16 hudba sudo[9038]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"