Mar 25 01:23:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 25 01:23:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:00 volumio go-librespot[1819]: go-librespot daemon starting... Mar 25 01:23:00 volumio go-librespot[1820]: time="2026-03-25T01:23:00+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:00 volumio go-librespot[1820]: time="2026-03-25T01:23:00+08:00" level=debug msg="app state loaded" Mar 25 01:23:00 volumio go-librespot[1820]: time="2026-03-25T01:23:00+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:00 volumio go-librespot[1820]: time="2026-03-25T01:23:00+08: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 25 01:23:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:02 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:02 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 25 01:23:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:03 volumio go-librespot[1828]: go-librespot daemon starting... Mar 25 01:23:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:04 volumio go-librespot[1829]: time="2026-03-25T01:23:04+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:04 volumio go-librespot[1829]: time="2026-03-25T01:23:04+08:00" level=debug msg="app state loaded" Mar 25 01:23:04 volumio go-librespot[1829]: time="2026-03-25T01:23:04+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:04 volumio go-librespot[1829]: time="2026-03-25T01:23:04+08: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 25 01:23:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:05 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:05 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 25 01:23:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:07 volumio go-librespot[1837]: go-librespot daemon starting... Mar 25 01:23:07 volumio go-librespot[1838]: time="2026-03-25T01:23:07+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:07 volumio go-librespot[1838]: time="2026-03-25T01:23:07+08:00" level=debug msg="app state loaded" Mar 25 01:23:07 volumio go-librespot[1838]: time="2026-03-25T01:23:07+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:07 volumio go-librespot[1838]: time="2026-03-25T01:23:07+08: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 25 01:23:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:08 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:08 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 25 01:23:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:10 volumio go-librespot[1861]: go-librespot daemon starting... Mar 25 01:23:10 volumio go-librespot[1862]: time="2026-03-25T01:23:10+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:10 volumio go-librespot[1862]: time="2026-03-25T01:23:10+08:00" level=debug msg="app state loaded" Mar 25 01:23:10 volumio go-librespot[1862]: time="2026-03-25T01:23:10+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:10 volumio go-librespot[1862]: time="2026-03-25T01:23:10+08: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 25 01:23:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:11 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:11 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Mar 25 01:23:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:13 volumio go-librespot[1870]: go-librespot daemon starting... Mar 25 01:23:14 volumio go-librespot[1871]: time="2026-03-25T01:23:14+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:14 volumio go-librespot[1871]: time="2026-03-25T01:23:14+08:00" level=debug msg="app state loaded" Mar 25 01:23:14 volumio go-librespot[1871]: time="2026-03-25T01:23:14+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:14 volumio go-librespot[1871]: time="2026-03-25T01:23:14+08: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 25 01:23:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:14 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:14 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:16 volumio hostapd[1154]: wlan0: STA ba:29:b8:c6:94:99 IEEE 802.11: disassociated Mar 25 01:23:16 volumio hostapd[1154]: wlan0: STA ba:29:b8:c6:94:99 IEEE 802.11: disassociated Mar 25 01:23:16 volumio hostapd[1154]: wlan0: STA ba:29:b8:c6:94:99 IEEE 802.11: disassociated Mar 25 01:23:16 volumio hostapd[1154]: wlan0: STA ba:29:b8:c6:94:99 IEEE 802.11: associated Mar 25 01:23:16 volumio hostapd[1154]: wlan0: STA ba:29:b8:c6:94:99 RADIUS: starting accounting session 83485CA9ED13704E Mar 25 01:23:17 volumio dnsmasq-dhcp[1161]: DHCPREQUEST(wlan0) 192.168.211.163 ba:29:b8:c6:94:99 Mar 25 01:23:17 volumio dnsmasq-dhcp[1161]: DHCPACK(wlan0) 192.168.211.163 ba:29:b8:c6:94:99 Mar 25 01:23:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Mar 25 01:23:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:17 volumio go-librespot[1879]: go-librespot daemon starting... Mar 25 01:23:17 volumio go-librespot[1880]: time="2026-03-25T01:23:17+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:17 volumio go-librespot[1880]: time="2026-03-25T01:23:17+08:00" level=debug msg="app state loaded" Mar 25 01:23:17 volumio go-librespot[1880]: time="2026-03-25T01:23:17+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:17 volumio go-librespot[1880]: time="2026-03-25T01:23:17+08: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 25 01:23:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:17 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:17 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Mar 25 01:23:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:20 volumio go-librespot[1896]: go-librespot daemon starting... Mar 25 01:23:20 volumio go-librespot[1899]: time="2026-03-25T01:23:20+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:20 volumio go-librespot[1899]: time="2026-03-25T01:23:20+08:00" level=debug msg="app state loaded" Mar 25 01:23:20 volumio go-librespot[1899]: time="2026-03-25T01:23:20+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:20 volumio go-librespot[1899]: time="2026-03-25T01:23:20+08: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 25 01:23:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:20 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:21 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Mar 25 01:23:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:24 volumio go-librespot[1910]: go-librespot daemon starting... Mar 25 01:23:24 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:24 volumio go-librespot[1911]: time="2026-03-25T01:23:24+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:24 volumio go-librespot[1911]: time="2026-03-25T01:23:24+08:00" level=debug msg="app state loaded" Mar 25 01:23:24 volumio go-librespot[1911]: time="2026-03-25T01:23:24+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:24 volumio go-librespot[1911]: time="2026-03-25T01:23:24+08: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 25 01:23:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:24 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: read ECONNRESET Mar 25 01:23:25 volumio sudo[1920]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 01:23:25 volumio sudo[1920]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:25 volumio sudo[1920]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:25 volumio sudo[1925]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:23:25 volumio sudo[1925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:25 volumio sudo[1925]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:25 volumio volumio[1097]: verbose: New Socket.io Connection to 192.168.211.1 from 192.168.211.163 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 4 Mar 25 01:23:26 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 25 01:23:27 volumio sudo[1928]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 01:23:27 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:27 volumio sudo[1928]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:27 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:27 volumio sudo[1930]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:23:27 volumio sudo[1930]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:27 volumio sudo[1928]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:27 volumio sudo[1930]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Mar 25 01:23:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:27 volumio go-librespot[1935]: go-librespot daemon starting... Mar 25 01:23:27 volumio go-librespot[1936]: time="2026-03-25T01:23:27+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:27 volumio go-librespot[1936]: time="2026-03-25T01:23:27+08:00" level=debug msg="app state loaded" Mar 25 01:23:27 volumio go-librespot[1936]: time="2026-03-25T01:23:27+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:27 volumio go-librespot[1936]: time="2026-03-25T01:23:27+08: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 25 01:23:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:27 volumio volumio[1097]: verbose: New Socket.io Connection to 192.168.211.1 from 192.168.211.163 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 4 Mar 25 01:23:28 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 25 01:23:28 volumio volumio[1097]: info: CoreCommandRouter::volumioGetVisibleSources Mar 25 01:23:28 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 01:23:28 volumio volumio[1097]: info: CoreCommandRouter::volumioGetState Mar 25 01:23:28 volumio volumio[1097]: info: CorePlayQueue::getTrack 0 Mar 25 01:23:28 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 25 01:23:28 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 25 01:23:28 volumio volumio[1097]: info: Received Get System Info Mar 25 01:23:28 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 25 01:23:28 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 25 01:23:28 volumio volumio[1097]: info: Discovery: Getting this device information Mar 25 01:23:28 volumio volumio[1097]: info: CoreCommandRouter::volumioGetState Mar 25 01:23:28 volumio volumio[1097]: info: CorePlayQueue::getTrack 0 Mar 25 01:23:28 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 25 01:23:28 volumio volumio[1097]: info: CoreCommandRouter::volumioGetState Mar 25 01:23:28 volumio volumio[1097]: info: CorePlayQueue::getTrack 0 Mar 25 01:23:28 volumio volumio[1097]: info: Listing playlists Mar 25 01:23:28 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 25 01:23:28 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 25 01:23:29 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 25 01:23:29 volumio volumio[1097]: info: Received Get System Info Mar 25 01:23:29 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 25 01:23:29 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 25 01:23:29 volumio volumio[1097]: info: Discovery: Getting this device information Mar 25 01:23:29 volumio volumio[1097]: info: CoreCommandRouter::volumioGetState Mar 25 01:23:29 volumio volumio[1097]: info: CorePlayQueue::getTrack 0 Mar 25 01:23:29 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 25 01:23:30 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:30 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Mar 25 01:23:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:30 volumio go-librespot[1944]: go-librespot daemon starting... Mar 25 01:23:30 volumio go-librespot[1945]: time="2026-03-25T01:23:30+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:30 volumio go-librespot[1945]: time="2026-03-25T01:23:30+08:00" level=debug msg="app state loaded" Mar 25 01:23:30 volumio go-librespot[1945]: time="2026-03-25T01:23:30+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:30 volumio go-librespot[1945]: time="2026-03-25T01:23:30+08: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 25 01:23:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:31 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Mar 25 01:23:33 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:33 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Mar 25 01:23:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:34 volumio go-librespot[1967]: go-librespot daemon starting... Mar 25 01:23:34 volumio go-librespot[1969]: time="2026-03-25T01:23:34+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:34 volumio go-librespot[1969]: time="2026-03-25T01:23:34+08:00" level=debug msg="app state loaded" Mar 25 01:23:34 volumio go-librespot[1969]: time="2026-03-25T01:23:34+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:34 volumio go-librespot[1969]: time="2026-03-25T01:23:34+08: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 25 01:23:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:35 volumio volumio[1097]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 25 01:23:36 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Mar 25 01:23:36 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:36 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:36 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Mar 25 01:23:36 volumio sudo[1986]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Mar 25 01:23:36 volumio sudo[1986]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:36 volumio sudo[1986]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:36 volumio sudo[1982]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Mar 25 01:23:36 volumio sudo[1982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:37 volumio sudo[1998]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Mar 25 01:23:37 volumio sudo[1998]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:37 volumio sudo[2001]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 01:23:37 volumio sudo[2001]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:37 volumio sudo[1982]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:37 volumio sudo[2001]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:37 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Mar 25 01:23:37 volumio sudo[1998]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:37 volumio sudo[2012]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:23:37 volumio sudo[2012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:37 volumio sudo[1993]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Mar 25 01:23:37 volumio sudo[1993]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:37 volumio sudo[2012]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:37 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Mar 25 01:23:37 volumio sudo[1993]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Mar 25 01:23:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:37 volumio sudo[2016]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 01:23:37 volumio sudo[2016]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:37 volumio go-librespot[2017]: go-librespot daemon starting... Mar 25 01:23:37 volumio go-librespot[2019]: time="2026-03-25T01:23:37+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:37 volumio go-librespot[2019]: time="2026-03-25T01:23:37+08:00" level=debug msg="app state loaded" Mar 25 01:23:37 volumio go-librespot[2019]: time="2026-03-25T01:23:37+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:37 volumio go-librespot[2019]: time="2026-03-25T01:23:37+08: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 25 01:23:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:37 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 25 01:23:38 volumio sudo[2016]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:38 volumio volumio5-onboarding[1469]: time=2026-03-25T01:23:38.701+08:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x3420c30" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 25 01:23:38 volumio volumio[1097]: info: Received Get System Info Mar 25 01:23:38 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 25 01:23:38 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 25 01:23:38 volumio volumio[1097]: info: Discovery: Getting this device information Mar 25 01:23:38 volumio volumio[1097]: info: CoreCommandRouter::volumioGetState Mar 25 01:23:38 volumio volumio[1097]: info: CorePlayQueue::getTrack 0 Mar 25 01:23:38 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 25 01:23:38 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 25 01:23:38 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 25 01:23:39 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:39 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:39 volumio volumio5-onboarding[1469]: time=2026-03-25T01:23:39.752+08:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 25 01:23:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Mar 25 01:23:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:40 volumio go-librespot[2027]: go-librespot daemon starting... Mar 25 01:23:40 volumio go-librespot[2028]: time="2026-03-25T01:23:40+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:40 volumio go-librespot[2028]: time="2026-03-25T01:23:40+08:00" level=debug msg="app state loaded" Mar 25 01:23:40 volumio go-librespot[2028]: time="2026-03-25T01:23:40+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:40 volumio go-librespot[2028]: time="2026-03-25T01:23:40+08: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 25 01:23:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:42 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:42 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Mar 25 01:23:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:43 volumio go-librespot[2050]: go-librespot daemon starting... Mar 25 01:23:44 volumio go-librespot[2051]: time="2026-03-25T01:23:44+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:44 volumio go-librespot[2051]: time="2026-03-25T01:23:44+08:00" level=debug msg="app state loaded" Mar 25 01:23:44 volumio go-librespot[2051]: time="2026-03-25T01:23:44+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:44 volumio go-librespot[2051]: time="2026-03-25T01:23:44+08: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 25 01:23:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:45 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:45 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Mar 25 01:23:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:47 volumio go-librespot[2060]: go-librespot daemon starting... Mar 25 01:23:47 volumio go-librespot[2061]: time="2026-03-25T01:23:47+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:47 volumio go-librespot[2061]: time="2026-03-25T01:23:47+08:00" level=debug msg="app state loaded" Mar 25 01:23:47 volumio go-librespot[2061]: time="2026-03-25T01:23:47+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:47 volumio go-librespot[2061]: time="2026-03-25T01:23:47+08: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 25 01:23:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:48 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:48 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:49 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: network , saveWirelessNetworkSettings Mar 25 01:23:49 volumio volumio[1097]: info: Saving new wireless network Mar 25 01:23:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Mar 25 01:23:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:50 volumio go-librespot[2069]: go-librespot daemon starting... Mar 25 01:23:50 volumio go-librespot[2070]: time="2026-03-25T01:23:50+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:50 volumio go-librespot[2070]: time="2026-03-25T01:23:50+08:00" level=debug msg="app state loaded" Mar 25 01:23:50 volumio go-librespot[2070]: time="2026-03-25T01:23:50+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:50 volumio go-librespot[2070]: time="2026-03-25T01:23:50+08: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 25 01:23:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:51 volumio sudo[2080]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/wpa_supplicant/wpa_supplicant.conf Mar 25 01:23:51 volumio sudo[2080]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:51 volumio sudo[2080]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:51 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:51 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:51 volumio sudo[2097]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Mar 25 01:23:51 volumio sudo[2097]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:51 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Mar 25 01:23:52 volumio systemd[1]: Stopping wireless.service - Wireless Services... Mar 25 01:23:52 volumio systemd[1]: wireless.service: Deactivated successfully. Mar 25 01:23:52 volumio systemd[1]: Stopped wireless.service - Wireless Services. Mar 25 01:23:52 volumio systemd[1]: wireless.service: Consumed 4min 24.835s CPU time. Mar 25 01:23:52 volumio systemd[1]: Starting wireless.service - Wireless Services... Mar 25 01:23:53 volumio sudo[2103]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:23:53 volumio sudo[2103]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:53 volumio sudo[2103]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Mar 25 01:23:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:53 volumio go-librespot[2112]: go-librespot daemon starting... Mar 25 01:23:54 volumio go-librespot[2113]: time="2026-03-25T01:23:54+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:54 volumio go-librespot[2113]: time="2026-03-25T01:23:54+08:00" level=debug msg="app state loaded" Mar 25 01:23:54 volumio go-librespot[2113]: time="2026-03-25T01:23:54+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:54 volumio go-librespot[2113]: time="2026-03-25T01:23:54+08: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 25 01:23:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:54 volumio sudo[2123]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:23:54 volumio sudo[2123]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:54 volumio sudo[2123]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:54 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:54 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:55 volumio sudo[2127]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:23:55 volumio sudo[2127]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:55 volumio sudo[2127]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:56 volumio wireless.js[2101]: WIRELESS.JS - INFO: Single Network Mode enabled (default) - only one network device can be active at a time between ethernet and wireless Mar 25 01:23:56 volumio sudo[2130]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:23:56 volumio sudo[2130]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:56 volumio sudo[2130]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:56 volumio wireless.js[2101]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow Mar 25 01:23:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Mar 25 01:23:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:23:57 volumio go-librespot[2146]: go-librespot daemon starting... Mar 25 01:23:57 volumio systemd[1]: Stopping dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server... Mar 25 01:23:57 volumio dnsmasq[1161]: exiting on receipt of SIGTERM Mar 25 01:23:57 volumio go-librespot[2147]: time="2026-03-25T01:23:57+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:23:57 volumio go-librespot[2147]: time="2026-03-25T01:23:57+08:00" level=debug msg="app state loaded" Mar 25 01:23:57 volumio go-librespot[2147]: time="2026-03-25T01:23:57+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:23:57 volumio go-librespot[2147]: time="2026-03-25T01:23:57+08: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 25 01:23:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:23:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:23:57 volumio systemd[1]: dnsmasq.service: Deactivated successfully. Mar 25 01:23:57 volumio systemd[1]: Stopped dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server. Mar 25 01:23:57 volumio systemd[1]: Stopping hostapd.service - Access point and authentication server for Wi-Fi and Ethernet... Mar 25 01:23:57 volumio sudo[2145]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:23:57 volumio sudo[2145]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:57 volumio sudo[2145]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:57 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:23:57 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:23:58 volumio dhcpcd[640]: wlan0: carrier lost Mar 25 01:23:58 volumio systemd[1]: hostapd.service: Deactivated successfully. Mar 25 01:23:58 volumio systemd[1]: Stopped hostapd.service - Access point and authentication server for Wi-Fi and Ethernet. Mar 25 01:23:58 volumio sudo[2174]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Mar 25 01:23:58 volumio sudo[2174]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 01:23:58 volumio sudo[2165]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:23:58 volumio sudo[2165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:58 volumio sudo[2174]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:58 volumio avahi-daemon[565]: Withdrawing address record for 192.168.211.1 on wlan0. Mar 25 01:23:58 volumio avahi-daemon[565]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Mar 25 01:23:58 volumio avahi-daemon[565]: Interface wlan0.IPv4 no longer relevant for mDNS. Mar 25 01:23:58 volumio sudo[2165]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:58 volumio volumio[1097]: info: Discovery: A device disappeared from network Mar 25 01:23:58 volumio sudo[2177]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Mar 25 01:23:58 volumio sudo[2177]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 01:23:59 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Mar 25 01:23:59 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Mar 25 01:23:59 volumio systemd[1]: welcome.service: Deactivated successfully. Mar 25 01:23:59 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Mar 25 01:23:59 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Mar 25 01:23:59 volumio volumio5-onboarding[1469]: time=2026-03-25T01:23:59.221+08:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x3420c30" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 25 01:23:59 volumio volumio[1097]: info: Received Get System Info Mar 25 01:23:59 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 25 01:23:59 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 25 01:23:59 volumio volumio[1097]: info: Discovery: Getting this device information Mar 25 01:23:59 volumio volumio[1097]: info: CoreCommandRouter::volumioGetState Mar 25 01:23:59 volumio volumio[1097]: info: CorePlayQueue::getTrack 0 Mar 25 01:23:59 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 25 01:23:59 volumio sudo[2177]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:59 volumio wireless.js[2101]: WIRELESS.JS - INFO: Cleaning previous... Mar 25 01:23:59 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Mar 25 01:23:59 volumio welcome[2180]: Resolved ip:[0] Mar 25 01:23:59 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 25 01:23:59 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 25 01:23:59 volumio sudo[2184]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Mar 25 01:23:59 volumio sudo[2184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 01:23:59 volumio sudo[2184]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:59 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Mar 25 01:23:59 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Mar 25 01:23:59 volumio sudo[2182]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:23:59 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Mar 25 01:23:59 volumio sudo[2182]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:23:59 volumio sudo[2182]: pam_unix(sudo:session): session closed for user root Mar 25 01:23:59 volumio volumio5-onboarding[1469]: time=2026-03-25T01:23:59.977+08:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x3420c30" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 25 01:23:59 volumio volumio[1097]: info: Received Get System Info Mar 25 01:23:59 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 25 01:23:59 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 25 01:23:59 volumio volumio[1097]: info: Discovery: Getting this device information Mar 25 01:23:59 volumio volumio[1097]: info: CoreCommandRouter::volumioGetState Mar 25 01:23:59 volumio volumio[1097]: info: CorePlayQueue::getTrack 0 Mar 25 01:23:59 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 25 01:23:59 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 25 01:23:59 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 25 01:24:00 volumio wireless.js[2101]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Mar 25 01:24:00 volumio wireless.js[2101]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 17ms Mar 25 01:24:00 volumio wireless.js[2101]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: 88:a2:9e:58:a2:ec) Mar 25 01:24:00 volumio sudo[2196]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Mar 25 01:24:00 volumio sudo[2196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:24:00 volumio sudo[2201]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:24:00 volumio sudo[2201]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:24:00 volumio sudo[2201]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Mar 25 01:24:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:24:00 volumio sudo[2196]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:24:00 volumio go-librespot[2205]: go-librespot daemon starting... Mar 25 01:24:00 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:24:00 volumio sudo[2208]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Mar 25 01:24:00 volumio sudo[2208]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:24:00 volumio go-librespot[2211]: time="2026-03-25T01:24:00+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:24:00 volumio go-librespot[2211]: time="2026-03-25T01:24:00+08:00" level=debug msg="app state loaded" Mar 25 01:24:00 volumio go-librespot[2211]: time="2026-03-25T01:24:00+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:24:00 volumio go-librespot[2211]: time="2026-03-25T01:24:00+08: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 25 01:24:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:24:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:24:00 volumio ntpd[755]: IO: Deleting interface #3 wlan0, 192.168.211.1#123, interface stats: received=0, sent=0, dropped=0, active_time=151 secs Mar 25 01:24:00 volumio volumio[1097]: info: Error connecting to go-librespot Websocket: AggregateError Mar 25 01:24:01 volumio sudo[2208]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:01 volumio wireless.js[2101]: WIRELESS.JS - INFO: Regdomain already correct: US Mar 25 01:24:01 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:01.337+08:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 25 01:24:01 volumio wireless.js[2101]: WIRELESS.JS - INFO: Start wireless flow Mar 25 01:24:01 volumio wireless.js[2101]: WIRELESS.JS - INFO: Stopped hotspot (if there).. Mar 25 01:24:01 volumio sudo[2226]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Mar 25 01:24:01 volumio sudo[2226]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 01:24:01 volumio sudo[2226]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:01 volumio sudo[2221]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:24:01 volumio sudo[2221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:24:01 volumio sudo[2221]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:01 volumio sudo[2228]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Mar 25 01:24:01 volumio sudo[2228]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 01:24:01 volumio volumio[1097]: info: Discovery: Networking Restart detected, restarting advertisement and browsing Mar 25 01:24:02 volumio volumio[1097]: info: Discovery: Restarting Advertising Mar 25 01:24:02 volumio volumio[1097]: info: Discovery: Stopping existing advertisement Mar 25 01:24:02 volumio volumio[1097]: info: Discovery: Restarting Browsing Mar 25 01:24:02 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:02.159+08:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x3420c30" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 25 01:24:02 volumio sudo[2228]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:02 volumio volumio[1097]: info: Received Get System Info Mar 25 01:24:02 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 25 01:24:02 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 25 01:24:02 volumio volumio[1097]: info: Discovery: Getting this device information Mar 25 01:24:02 volumio volumio[1097]: info: CoreCommandRouter::volumioGetState Mar 25 01:24:02 volumio volumio[1097]: info: CorePlayQueue::getTrack 0 Mar 25 01:24:02 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 25 01:24:02 volumio wireless.js[2101]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Mar 25 01:24:02 volumio wireless.js[2101]: WIRELESS.JS - INFO: STAGE 1: wlan0 validated and ready (MAC: 88:a2:9e:58:a2:ec, USB: false) Mar 25 01:24:02 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 25 01:24:02 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 25 01:24:02 volumio wpa_supplicant[2240]: Successfully initialized wpa_supplicant Mar 25 01:24:02 volumio sudo[2245]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:24:02 volumio sudo[2245]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:24:02 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Mar 25 01:24:02 volumio sudo[2245]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:03 volumio wpa_supplicant[2240]: nl80211: kernel reports: Registration to specific type not supported Mar 25 01:24:03 volumio volumio[1097]: info: Discovery: A device disappeared from network Mar 25 01:24:03 volumio sudo[2258]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Mar 25 01:24:03 volumio sudo[2258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 01:24:03 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:03.169+08:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x3420c30" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 25 01:24:03 volumio sudo[2258]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:03 volumio volumio[1097]: info: Received Get System Info Mar 25 01:24:03 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 25 01:24:03 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 25 01:24:03 volumio volumio[1097]: info: Discovery: Getting this device information Mar 25 01:24:03 volumio volumio[1097]: info: CoreCommandRouter::volumioGetState Mar 25 01:24:03 volumio volumio[1097]: info: CorePlayQueue::getTrack 0 Mar 25 01:24:03 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 25 01:24:03 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:03.369+08:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 25 01:24:03 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 25 01:24:03 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 25 01:24:03 volumio sudo[2264]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:24:03 volumio sudo[2264]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:24:03 volumio sudo[2264]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:03 volumio wpa_supplicant[2255]: wlan0: Trying to associate with 0c:80:63:49:04:c6 (SSID='Holland household' freq=2447 MHz) Mar 25 01:24:03 volumio wpa_supplicant[2255]: wlan0: Associated with 0c:80:63:49:04:c6 Mar 25 01:24:03 volumio wpa_supplicant[2255]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Mar 25 01:24:03 volumio wpa_supplicant[2255]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Mar 25 01:24:03 volumio wpa_supplicant[2255]: wlan0: WPA: Key negotiation completed with 0c:80:63:49:04:c6 [PTK=CCMP GTK=TKIP] Mar 25 01:24:03 volumio wpa_supplicant[2255]: wlan0: CTRL-EVENT-CONNECTED - Connection to 0c:80:63:49:04:c6 completed [id=0 id_str=] Mar 25 01:24:03 volumio dhcpcd[640]: wlan0: carrier acquired Mar 25 01:24:03 volumio dhcpcd[640]: wlan0: connected to Access Point: Holland household Mar 25 01:24:03 volumio dhcpcd[640]: wlan0: IAID 9e:58:a2:ec Mar 25 01:24:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Mar 25 01:24:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:24:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:24:03 volumio go-librespot[2268]: go-librespot daemon starting... Mar 25 01:24:04 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:24:04 volumio go-librespot[2269]: time="2026-03-25T01:24:04+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:24:04 volumio go-librespot[2269]: time="2026-03-25T01:24:04+08:00" level=debug msg="app state loaded" Mar 25 01:24:04 volumio go-librespot[2269]: time="2026-03-25T01:24:04+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:24:04 volumio go-librespot[2269]: time="2026-03-25T01:24:04+08:00" level=debug msg="new websocket client" Mar 25 01:24:04 volumio go-librespot[2269]: time="2026-03-25T01:24:04+08: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 25 01:24:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:24:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:24:04 volumio volumio[1097]: info: Connection to go-librespot Websocket established Mar 25 01:24:04 volumio volumio[1097]: info: Connection to go-librespot Websocket closed Mar 25 01:24:04 volumio wpa_supplicant[2255]: wlan0: CTRL-EVENT-DISCONNECTED bssid=0c:80:63:49:04:c6 reason=3 locally_generated=1 Mar 25 01:24:04 volumio dhcpcd[640]: wlan0: carrier lost - roaming Mar 25 01:24:04 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:04.293+08:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x3420c30" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 25 01:24:04 volumio wpa_supplicant[2255]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all Mar 25 01:24:04 volumio wireless.js[2101]: WIRELESS.JS - INFO: DHCP IP fallback Mar 25 01:24:04 volumio wpa_supplicant[2255]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Mar 25 01:24:04 volumio wpa_supplicant[2255]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US Mar 25 01:24:04 volumio wireless.js[2101]: WIRELESS.JS - INFO: STAGE 2: Starting event-driven WPA state monitor Mar 25 01:24:04 volumio wireless.js[2101]: WIRELESS.JS - INFO: WpaStateMachine: Starting state monitor for wlan0 Mar 25 01:24:04 volumio volumio[1097]: info: Received Get System Info Mar 25 01:24:04 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 25 01:24:04 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 25 01:24:04 volumio volumio[1097]: info: Discovery: Getting this device information Mar 25 01:24:04 volumio volumio[1097]: info: CoreCommandRouter::volumioGetState Mar 25 01:24:04 volumio volumio[1097]: info: CorePlayQueue::getTrack 0 Mar 25 01:24:04 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 25 01:24:04 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:04.391+08:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 25 01:24:04 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 25 01:24:04 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 25 01:24:04 volumio sudo[2290]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:24:04 volumio sudo[2290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:24:04 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:04.801+08:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x3420c30" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 25 01:24:04 volumio volumio[1097]: info: Received Get System Info Mar 25 01:24:04 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 25 01:24:04 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 25 01:24:04 volumio volumio[1097]: info: Discovery: Getting this device information Mar 25 01:24:04 volumio volumio[1097]: info: CoreCommandRouter::volumioGetState Mar 25 01:24:04 volumio volumio[1097]: info: CorePlayQueue::getTrack 0 Mar 25 01:24:04 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 25 01:24:04 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 25 01:24:04 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 25 01:24:04 volumio dhcpcd[640]: wlan0: soliciting an IPv6 router Mar 25 01:24:04 volumio wpa_supplicant[2255]: wlan0: Trying to associate with 0c:80:63:49:04:06 (SSID='Holland household' freq=2447 MHz) Mar 25 01:24:04 volumio wireless.js[2101]: WIRELESS.JS - INFO: WpaStateMachine: State transition: NULL -> ASSOCIATING (duration: 0ms) Mar 25 01:24:04 volumio sudo[2290]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:04 volumio wpa_supplicant[2255]: wlan0: Associated with 0c:80:63:49:04:06 Mar 25 01:24:04 volumio wpa_supplicant[2255]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Mar 25 01:24:04 volumio wpa_supplicant[2255]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Mar 25 01:24:05 volumio wpa_supplicant[2255]: wlan0: WPA: Key negotiation completed with 0c:80:63:49:04:06 [PTK=CCMP GTK=TKIP] Mar 25 01:24:05 volumio wpa_supplicant[2255]: wlan0: CTRL-EVENT-CONNECTED - Connection to 0c:80:63:49:04:06 completed [id=0 id_str=] Mar 25 01:24:05 volumio dhcpcd[640]: wlan0: carrier acquired Mar 25 01:24:05 volumio dhcpcd[640]: wlan0: IAID 9e:58:a2:ec Mar 25 01:24:05 volumio wireless.js[2101]: WIRELESS.JS - INFO: WpaStateMachine: State transition: ASSOCIATING -> COMPLETED (duration: 543ms) Mar 25 01:24:05 volumio wireless.js[2101]: WIRELESS.JS - INFO: WpaStateMachine: COMPLETED - connection successful Mar 25 01:24:05 volumio wireless.js[2101]: WIRELESS.JS - INFO: STAGE 2: Connection successful - Connected to 0c:80:63:49:04:06 Mar 25 01:24:05 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:05.537+08:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x3420c30" available=true connected=true macAddress=88:a2:9e:58:a2:ec ip4Address= ip6Address= ssid="Holland household" Mar 25 01:24:05 volumio volumio[1097]: info: Received Get System Info Mar 25 01:24:05 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 25 01:24:05 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 25 01:24:05 volumio volumio[1097]: info: Discovery: Getting this device information Mar 25 01:24:05 volumio volumio[1097]: info: CoreCommandRouter::volumioGetState Mar 25 01:24:05 volumio volumio[1097]: info: CorePlayQueue::getTrack 0 Mar 25 01:24:05 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 25 01:24:05 volumio wireless.js[2101]: WIRELESS.JS - INFO: Onboard WiFi adapter detected, using standard dhcpcd flow Mar 25 01:24:05 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 25 01:24:05 volumio volumio[1097]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 25 01:24:05 volumio sudo[2302]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:24:05 volumio sudo[2302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:24:05 volumio sudo[2302]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:05 volumio dhcpcd[640]: wlan0: soliciting an IPv6 router Mar 25 01:24:06 volumio dhcpcd[640]: wlan0: soliciting a DHCP lease Mar 25 01:24:06 volumio dhcpcd[640]: wlan0: offered 192.168.68.141 from 192.168.68.1 Mar 25 01:24:06 volumio sudo[2308]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd wlan0 Mar 25 01:24:06 volumio sudo[2308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 01:24:06 volumio dhcpcd[640]: wlan0: probing address 192.168.68.141/24 Mar 25 01:24:06 volumio sudo[2307]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:24:06 volumio dhcpcd[640]: control command: /sbin/dhcpcd wlan0 Mar 25 01:24:06 volumio dhcpcd[640]: control_free: No such file or directory Mar 25 01:24:06 volumio sudo[2308]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:06 volumio sudo[2307]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:24:06 volumio sudo[2307]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:07 volumio volumio[1097]: info: Discovery: Started advertising with name: Volumio Mar 25 01:24:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Mar 25 01:24:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:24:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:24:07 volumio go-librespot[2314]: go-librespot daemon starting... Mar 25 01:24:07 volumio go-librespot[2315]: time="2026-03-25T01:24:07+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:24:07 volumio go-librespot[2315]: time="2026-03-25T01:24:07+08:00" level=debug msg="app state loaded" Mar 25 01:24:07 volumio go-librespot[2315]: time="2026-03-25T01:24:07+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:24:07 volumio go-librespot[2315]: time="2026-03-25T01:24:07+08: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 25 01:24:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:24:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:24:07 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:07.552+08:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 25 01:24:07 volumio volumio[1097]: info: Getting Spotify volume Mar 25 01:24:07 volumio volumio[1097]: info: Initializing connection to go-librespot Websocket Mar 25 01:24:07 volumio volumio[1097]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 01:24:07 volumio volumio[1097]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 01:24:07 volumio volumio[1097]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 01:24:07 volumio volumio[1097]: errno: -111, Mar 25 01:24:07 volumio volumio[1097]: code: 'ECONNREFUSED', Mar 25 01:24:07 volumio volumio[1097]: syscall: 'connect', Mar 25 01:24:07 volumio volumio[1097]: address: '127.0.0.1', Mar 25 01:24:07 volumio volumio[1097]: port: 9879, Mar 25 01:24:07 volumio volumio[1097]: response: undefined Mar 25 01:24:07 volumio volumio[1097]: } Mar 25 01:24:07 volumio volumio[1097]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 01:24:08 volumio wireless.js[2101]: WIRELESS.JS - INFO: Start ap Mar 25 01:24:09 volumio wireless.js[2101]: WIRELESS.JS - INFO: Notified systemd about wireless ready Mar 25 01:24:09 volumio systemd[1]: Started wireless.service - Wireless Services. Mar 25 01:24:09 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Mar 25 01:24:09 volumio sudo[2097]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:09 volumio wireless.js[2101]: WIRELESS.JS - INFO: trying... Mar 25 01:24:10 volumio sudo[2351]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Mar 25 01:24:10 volumio sudo[2351]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:24:10 volumio sudo[2351]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Mar 25 01:24:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:24:10 volumio sudo[2354]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:24:10 volumio sudo[2354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 01:24:10 volumio sudo[2354]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:10 volumio wireless.js[2101]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Mar 25 01:24:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:24:10 volumio go-librespot[2355]: go-librespot daemon starting... Mar 25 01:24:10 volumio go-librespot[2357]: time="2026-03-25T01:24:10+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:24:10 volumio go-librespot[2357]: time="2026-03-25T01:24:10+08:00" level=debug msg="app state loaded" Mar 25 01:24:10 volumio go-librespot[2357]: time="2026-03-25T01:24:10+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:24:10 volumio go-librespot[2357]: time="2026-03-25T01:24:10+08: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 25 01:24:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 01:24:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 01:24:10 volumio wireless.js[2101]: WIRELESS.JS - INFO: trying... Mar 25 01:24:11 volumio sudo[2374]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Mar 25 01:24:11 volumio sudo[2374]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:24:11 volumio sudo[2374]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:11 volumio sudo[2377]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:24:11 volumio sudo[2377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 01:24:11 volumio sudo[2377]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:11 volumio wireless.js[2101]: WIRELESS.JS - INFO: ... wlan0 IPv4 is undefined, ipV6 is undefined Mar 25 01:24:11 volumio wireless.js[2101]: WIRELESS.JS - INFO: WARNING: dhcpcd running but no IP assigned yet Mar 25 01:24:11 volumio wireless.js[2101]: WIRELESS.JS - INFO: trying... Mar 25 01:24:12 volumio dhcpcd[640]: wlan0: leased 192.168.68.141 for 7200 seconds Mar 25 01:24:12 volumio avahi-daemon[565]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.68.141. Mar 25 01:24:12 volumio avahi-daemon[565]: New relevant interface wlan0.IPv4 for mDNS. Mar 25 01:24:12 volumio avahi-daemon[565]: Registering new address record for 192.168.68.141 on wlan0.IPv4. Mar 25 01:24:12 volumio dhcpcd[640]: wlan0: adding route to 192.168.68.0/24 Mar 25 01:24:12 volumio dhcpcd[640]: wlan0: adding default route via 192.168.68.1 Mar 25 01:24:12 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Mar 25 01:24:12 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Mar 25 01:24:12 volumio systemd[1]: welcome.service: Deactivated successfully. Mar 25 01:24:12 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Mar 25 01:24:12 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Mar 25 01:24:12 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Mar 25 01:24:12 volumio welcome[2405]: Resolved ip:[1] 192.168.68.141 Mar 25 01:24:12 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Mar 25 01:24:12 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Mar 25 01:24:12 volumio sudo[2417]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Mar 25 01:24:12 volumio sudo[2417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:24:12 volumio sudo[2417]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:12 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:12.567+08:00 level=INFO msg="emitting wifi info changed event" component=server peer="00:00:00:00:00:00%01 @ 0x3420c30" available=true connected=true macAddress=88:a2:9e:58:a2:ec ip4Address=192.168.68.141/24 ip6Address= ssid="Holland household" Mar 25 01:24:12 volumio sudo[2420]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 01:24:12 volumio sudo[2420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 01:24:12 volumio sudo[2420]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:12 volumio wireless.js[2101]: WIRELESS.JS - INFO: ... wlan0 IPv4 is 192.168.68.141, ipV6 is undefined Mar 25 01:24:12 volumio wireless.js[2101]: WIRELESS.JS - INFO: Connected to SSID: Holland household Mar 25 01:24:12 volumio wireless.js[2101]: WIRELESS.JS - INFO: It's done! AP Mar 25 01:24:12 volumio wireless.js[2101]: WIRELESS.JS - INFO: Restarting avahi-daemon... Mar 25 01:24:12 volumio sudo[2429]: root : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart avahi-daemon Mar 25 01:24:12 volumio sudo[2429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 01:24:12 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 01:24:12 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 01:24:12 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 01:24:12 volumio systemd[1]: shairport-sync.service: Consumed 2.354s CPU time. Mar 25 01:24:12 volumio systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Mar 25 01:24:12 volumio avahi-daemon[565]: Got SIGTERM, quitting. Mar 25 01:24:12 volumio avahi-daemon[565]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.68.141. Mar 25 01:24:12 volumio avahi-daemon[565]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Mar 25 01:24:12 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:12.973+08:00 level=WARN msg="disconnected from Avahi daemon, trying to reconnect" component=discovery/localnet error="avahi: Daemon connection failed" Mar 25 01:24:12 volumio avahi-daemon[565]: avahi-daemon 0.8 exiting. Mar 25 01:24:12 volumio dbus-daemon[568]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' requested by ':1.20' (uid=0 pid=1469 comm="/usr/bin/volumio5-onboarding") Mar 25 01:24:13 volumio systemd[1]: avahi-daemon.service: Deactivated successfully. Mar 25 01:24:13 volumio systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Mar 25 01:24:13 volumio systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Mar 25 01:24:13 volumio avahi-daemon[2440]: Process 565 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Mar 25 01:24:13 volumio avahi-daemon[2440]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Mar 25 01:24:13 volumio avahi-daemon[2440]: Successfully dropped root privileges. Mar 25 01:24:13 volumio avahi-daemon[2440]: avahi-daemon 0.8 starting up. Mar 25 01:24:13 volumio dbus-daemon[568]: [system] Successfully activated service 'org.freedesktop.Avahi' Mar 25 01:24:13 volumio systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Mar 25 01:24:13 volumio sudo[2429]: pam_unix(sudo:session): session closed for user root Mar 25 01:24:13 volumio avahi-daemon[2440]: Successfully called chroot(). Mar 25 01:24:13 volumio avahi-daemon[2440]: Successfully dropped remaining capabilities. Mar 25 01:24:13 volumio avahi-daemon[2440]: No service file found in /etc/avahi/services. Mar 25 01:24:13 volumio avahi-daemon[2440]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.68.141. Mar 25 01:24:13 volumio avahi-daemon[2440]: New relevant interface wlan0.IPv4 for mDNS. Mar 25 01:24:13 volumio avahi-daemon[2440]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Mar 25 01:24:13 volumio avahi-daemon[2440]: New relevant interface lo.IPv4 for mDNS. Mar 25 01:24:13 volumio avahi-daemon[2440]: Network interface enumeration completed. Mar 25 01:24:13 volumio avahi-daemon[2440]: Registering new address record for 192.168.68.141 on wlan0.IPv4. Mar 25 01:24:13 volumio avahi-daemon[2440]: Registering new address record for 127.0.0.1 on lo.IPv4. Mar 25 01:24:13 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 01:24:13 volumio wireless.js[2101]: WIRELESS.JS - INFO: Notified systemd about wireless ready Mar 25 01:24:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Mar 25 01:24:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:24:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 01:24:13 volumio go-librespot[2460]: go-librespot daemon starting... Mar 25 01:24:13 volumio go-librespot[2461]: time="2026-03-25T01:24:13+08:00" level=info msg="running go-librespot 0.7.1" Mar 25 01:24:13 volumio go-librespot[2461]: time="2026-03-25T01:24:13+08:00" level=debug msg="app state loaded" Mar 25 01:24:13 volumio ntpd[755]: IO: Listen normally on 4 wlan0 192.168.68.141:123 Mar 25 01:24:13 volumio ntpd[755]: IO: new interface(s) found: waking up resolver Mar 25 01:24:13 volumio ntpd[755]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Mar 25 01:24:13 volumio go-librespot[2461]: time="2026-03-25T01:24:13+08:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 01:24:13 volumio ntpd[755]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Mar 25 01:24:13 volumio ntpd[755]: DNS: Pool taking: 142.91.103.26 Mar 25 01:24:13 volumio ntpd[755]: DNS: Pool taking: 47.241.41.246 Mar 25 01:24:13 volumio ntpd[755]: DNS: Pool taking: 64.235.61.113 Mar 25 01:24:13 volumio ntpd[755]: DNS: Pool taking: 203.123.48.1 Mar 25 01:24:13 volumio ntpd[755]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Mar 25 01:24:14 volumio avahi-daemon[2440]: Server startup complete. Host name is volumio.local. Local service cookie is 576308960. Mar 25 01:24:14 volumio go-librespot[2461]: time="2026-03-25T01:24:14+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Mar 25 01:24:14 volumio go-librespot[2461]: time="2026-03-25T01:24:14+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Mar 25 01:24:14 volumio go-librespot[2461]: time="2026-03-25T01:24:14+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Mar 25 01:24:14 volumio go-librespot[2461]: time="2026-03-25T01:24:14+08:00" level=info msg="zeroconf server listening on port 41651" Mar 25 01:24:14 volumio go-librespot[2461]: time="2026-03-25T01:24:14+08:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Mar 25 01:24:14 volumio ntpd[755]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Mar 25 01:24:14 volumio ntpd[755]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Mar 25 01:24:14 volumio ntpd[755]: DNS: Pool taking: 128.199.223.193 Mar 25 01:24:14 volumio ntpd[755]: DNS: Pool taking: 45.77.249.167 Mar 25 01:24:14 volumio ntpd[755]: DNS: Pool taking: 5.223.50.207 Mar 25 01:24:14 volumio ntpd[755]: DNS: Pool taking: 94.237.79.110 Mar 25 01:24:14 volumio ntpd[755]: DNS: Pool taking: 2406:2000:e4:a1f::1000 Mar 25 01:24:14 volumio ntpd[755]: DNS: Pool taking: 2406:da18:6d1:a600::be00:4 Mar 25 01:24:14 volumio ntpd[755]: DNS: Pool taking: 2a04:3543:1000:2310:444a:58ff:fee4:61b2 Mar 25 01:24:14 volumio ntpd[755]: DNS: Pool taking: 2402:1f00:8001:1a25::123 Mar 25 01:24:14 volumio ntpd[755]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Mar 25 01:24:14 volumio go-librespot[2461]: time="2026-03-25T01:24:14+08:00" level=debug msg="obtained new client token: AACSNFpP5LPVda4WbKTeIT60Lou5NbogA/WqldQcMs+YaD+j4KrJ2DmmZlD3MVxYvx/l08iBjDJaFHW91zPW0rLzrhQEweE36TdH0iBDy+qkuXmCMHcvsuktPBmO4tHrzBwUM1EXL6Wfa7DyR7ZpZmUraEyrMJEO1hYioNg9s2bXyRLSiffV4od5yfWmS9FWbQs4J0sqxSKD26VRnIj6i6IkNuFmkMcUkHLyfGC88Pg9pO6SwJMOfwny" Mar 25 01:24:15 volumio go-librespot[2461]: time="2026-03-25T01:24:15+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Mar 25 01:24:15 volumio go-librespot[2461]: time="2026-03-25T01:24:15+08:00" level=debug msg="completed keyexchange" Mar 25 01:24:15 volumio go-librespot[2461]: time="2026-03-25T01:24:15+08:00" level=debug msg="completed challenge" Mar 25 01:24:15 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:15.161+08:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 25 01:24:15 volumio go-librespot[2461]: time="2026-03-25T01:24:15+08:00" level=info msg="authenticated AP" username="wj*********************g2" Mar 25 01:24:15 volumio dbus-daemon[568]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.15" (uid=0 pid=1469 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=804 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Mar 25 01:24:15 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:15.499+08:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.68.156:55092 Mar 25 01:24:15 volumio go-librespot[2461]: time="2026-03-25T01:24:15+08:00" level=info msg="authenticated Login5" username="wj*********************g2" Mar 25 01:24:15 volumio go-librespot[2461]: time="2026-03-25T01:24:15+08:00" level=debug msg="initializing zeroconf session" username="wj*********************g2" Mar 25 01:24:15 volumio go-librespot[2461]: time="2026-03-25T01:24:15+08:00" level=error msg="failed connecting to dealer" error="failed to WebSocket dial: failed to send handshake request: Get \"https://gae2-dealer.spotify.com:443/?access_token=BQDKBTvQYq3wNLaxXdo5vaGuHnMl0k9lFCWnwL4E4FoVv2SfPcMHhxK4Gb1wBiYw6KZDF3jwFmWkItTQ4uxzsVVm4Gcxui_7f7Ydd6hTC4LeCR1fElLljImJRA0uRhveIU-VRe4hEPyUibGr_TUKKnBOGSQ9RlqD8vCrsreG3SVd8yFae_90KI5C4d7lDi7AM6t0TWXOov-iU3lyuCl2E0lTiC7ggMtlCD5yHE0PM5o9lcXPEUMiX0ZlqiwV3oUeA0lvsgXXrO-BEX60vCY5iD4RvCPZJITns6a7WYUoV0IxHq4i-mzt8NkuyaDB9LxgEzlFklIWKZ8M4U6ckebfTBn03bcTFIHDVlz5zKhe9BBgFS1IBcka0bDTsxdwccE3FlvJH4BInhLD-m-Yej3iDKXUSQj9JPuGZcwRDRmDtVcA99-b_dT_\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2026-03-25T01:24:15+08:00 is before 2026-04-07T00:00:00Z" Mar 25 01:24:15 volumio ntpd[755]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Mar 25 01:24:15 volumio ntpd[755]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Mar 25 01:24:15 volumio ntpd[755]: DNS: Pool taking: 128.199.169.185 Mar 25 01:24:15 volumio ntpd[755]: DNS: Pool skipping: 94.237.79.110 Mar 25 01:24:15 volumio ntpd[755]: DNS: Pool skipping: 45.77.249.167 Mar 25 01:24:15 volumio ntpd[755]: DNS: Pool taking: 51.79.177.199 Mar 25 01:24:15 volumio ntpd[755]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Mar 25 01:24:16 volumio ntpd[755]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Mar 25 01:24:16 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:16.893+08:00 level=INFO msg="new address was allocated" component=ble/conn old=2 new=3 Mar 25 01:24:17 volumio ntpd[755]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Mar 25 01:24:17 volumio ntpd[755]: DNS: Pool taking: 172.104.182.184 Mar 25 01:24:17 volumio ntpd[755]: DNS: Pool taking: 142.91.99.46 Mar 25 01:24:17 volumio ntpd[755]: DNS: Pool taking: 84.33.16.6 Mar 25 01:24:17 volumio ntpd[755]: DNS: Pool taking: 167.71.195.165 Mar 25 01:24:17 volumio ntpd[755]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Mar 25 01:24:17 volumio dbus-daemon[568]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.15" (uid=0 pid=1469 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=804 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Mar 25 01:24:17 volumio dbus-daemon[568]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.15" (uid=0 pid=1469 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.4" (uid=0 pid=804 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Mar 25 01:24:17 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:17.284+08:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.68.156:55092 @ 0x3000ea0" latency=-1645h40m8.964426693s platform=PLATFORM_IOS version=5.260413.0 Mar 25 01:24:17 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:17.289+08:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.68.156:55092 @ 0x3000ea0" latency=-1645h40m8.960627006s timeout=10s Mar 25 01:24:17 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:17.304+08:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.68.156:55092 @ 0x3000ea0" Mar 25 01:24:18 volumio sudo[2481]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 01:23' Mar 25 01:24:18 volumio sudo[2481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 01:24:19 volumio volumio5-onboarding[1469]: time=2026-03-25T01:24:19.833+08:00 level=INFO msg="new address was allocated" component=ble/conn old=3 new=4 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"