Apr 12 16:41:00 volumio volumio[211285]: info: Plugin mpdemulation is not enabled Apr 12 16:41:00 volumio volumio[211285]: info: Loading plugin "rest_api"... Apr 12 16:41:00 volumio volumio[211285]: info: Loading plugin "websocket"... Apr 12 16:41:00 volumio volumio[211285]: info: Starting Socket.io Server version 1.7.4 Apr 12 16:41:00 volumio volumio[211285]: info: Plugin fusiondsp is not enabled Apr 12 16:41:00 volumio volumio[211285]: info: Plugin display_configuration is not enabled Apr 12 16:41:00 volumio volumio[211285]: info: Plugin peppyspectrum is not enabled Apr 12 16:41:00 volumio volumio[211396]: Forking 1 albumart workers Apr 12 16:41:00 volumio volumio[211285]: info: Loading i18n strings for locale en Apr 12 16:41:00 volumio volumio[211285]: Updating browse sources language Apr 12 16:41:00 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 16:41:00 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 16:41:00 volumio volumio[211285]: info: CoreCommandRouter::initPlayerControls Apr 12 16:41:00 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:00 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:00 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:00 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:00 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:00 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:00 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:00 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:00 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 16:41:00 volumio volumio[211285]: Express server listening on port 3000 Apr 12 16:41:00 volumio volumio[211285]: [Metrics] WebUI: 11s 667.74ms Apr 12 16:41:00 volumio volumio[211285]: info: Setting Device type: x86 Apr 12 16:41:00 volumio volumio[211285]: info: CoreStateMachine::resetVolumioState Apr 12 16:41:00 volumio volumio[211285]: info: CoreStateMachine::getcurrentVolume Apr 12 16:41:00 volumio volumio[211285]: info: CoreCommandRouter::volumioRetrievevolume Apr 12 16:41:00 volumio volumio[211285]: info: CoreStateMachine::pushState Apr 12 16:41:00 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:00 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:41:00 volumio volumio[211285]: info: CoreCommandRouter::volumioPushState Apr 12 16:41:00 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 16:41:00 volumio volumio[211285]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Apr 12 16:41:00 volumio volumio[211285]: info: Completed loading Core Plugins Apr 12 16:41:00 volumio volumio[211285]: info: Preparing to generate the ALSA configuration file Apr 12 16:41:01 volumio volumio[211285]: info: Volumio Network Manager: Network status updated: 1 Apr 12 16:41:01 volumio volumio[211285]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Apr 12 16:41:01 volumio volumio[211285]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: websocket Total Clients: 1 Apr 12 16:41:01 volumio volumio[211285]: info: Reloading queue from file Apr 12 16:41:01 volumio volumio[211285]: info: Asound.conf file unchanged, so no further update is needed Apr 12 16:41:01 volumio volumio[211285]: info: Output device has changed, restarting MPD Apr 12 16:41:01 volumio volumio[211285]: info: Output device has changed, restarting Shairport Sync Apr 12 16:41:01 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:01 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 16:41:01 volumio sudo[211423]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 12 16:41:01 volumio sudo[211423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:01 volumio sudo[211423]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:01 volumio sudo[211425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 12 16:41:01 volumio sudo[211425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:01 volumio volumio[211285]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 12 16:41:01 volumio volumio[211285]: info: ___________ START PLUGINS ___________ Apr 12 16:41:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 144. Apr 12 16:41:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:01 volumio go-librespot[211432]: go-librespot daemon starting... Apr 12 16:41:01 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 12 16:41:01 volumio go-librespot[211434]: time="2026-04-12T16:41:01Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:01 volumio go-librespot[211434]: time="2026-04-12T16:41:01Z" level=debug msg="app state loaded" Apr 12 16:41:01 volumio volumio[211285]: info: ControllerMpd::onStart: Initializing MPD Apr 12 16:41:01 volumio volumio[211285]: info: Creating MPD Configuration file Apr 12 16:41:01 volumio go-librespot[211434]: time="2026-04-12T16:41:01Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:01 volumio sudo[211439]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Apr 12 16:41:01 volumio sudo[211439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:01 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 12 16:41:01 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 12 16:41:01 volumio systemd[1]: mpd.service: Consumed 5.161s CPU time. Apr 12 16:41:01 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 12 16:41:01 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 12 16:41:01 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 12 16:41:01 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 12 16:41:01 volumio volumio[211285]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 12 16:41:01 volumio volumio[211285]: info: [1776012061886] CoreMusicLibrary::Adding element Media Servers Apr 12 16:41:01 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 16:41:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 12 16:41:01 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 12 16:41:02 volumio sudo[211439]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:02 volumio volumio[211285]: info: UPNP Browser: Client initialized successfully Apr 12 16:41:02 volumio sudo[211447]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 12 16:41:02 volumio sudo[211444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 12 16:41:02 volumio sudo[211444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:02 volumio sudo[211447]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:02 volumio sudo[211444]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:02 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:02 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 16:41:02 volumio go-librespot[211434]: time="2026-04-12T16:41:02Z" 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\": tls: failed to verify certificate: x509: certificate is not valid for any names, but wanted to match apresolve.spotify.com" Apr 12 16:41:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:02 volumio sudo[211449]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 12 16:41:02 volumio sudo[211449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 12 16:41:02 volumio sudo[211449]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:02 volumio volumio[211285]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 12 16:41:02 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:02 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 16:41:02 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 12 16:41:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 12 16:41:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 12 16:41:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 12 16:41:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 12 16:41:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 12 16:41:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 12 16:41:02 volumio volumio[211285]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 12 16:41:02 volumio volumio[211285]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 12 16:41:02 volumio volumio[211285]: info: [1776012062504] CoreMusicLibrary::Adding element Last_100 Apr 12 16:41:02 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 16:41:02 volumio volumio[211285]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 12 16:41:02 volumio volumio[211285]: info: [1776012062508] CoreMusicLibrary::Adding element Webradio Apr 12 16:41:02 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 12 16:41:02 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 16:41:02 volumio volumio[211285]: info: Initializing BBC Radios Apr 12 16:41:02 volumio volumio[211407]: Starting albumart workers Apr 12 16:41:02 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 16:41:02 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 16:41:02 volumio sudo[211465]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 12 16:41:02 volumio sudo[211465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 12 16:41:02 volumio sudo[211465]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:02 volumio volumio[211285]: info: Creating Spotify config file Apr 12 16:41:02 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:03 volumio volumio[211285]: info: Volumio Calling Home Apr 12 16:41:04 volumio volumio5-onboarding[2284]: time=2026-04-12T16:41:04.211Z level=ERROR msg="failed to update discovery on Wi-Fi info change" error="failed to get system info: could not get system info: context deadline exceeded" Apr 12 16:41:04 volumio volumio[211285]: info: CoreStateMachine::setRepeat null single undefined Apr 12 16:41:04 volumio volumio[211285]: info: CoreStateMachine::pushState Apr 12 16:41:04 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:04 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 12 16:41:04 volumio volumio[211285]: info: CoreCommandRouter::volumioPushState Apr 12 16:41:04 volumio volumio[211285]: info: CoreStateMachine::setRandom null Apr 12 16:41:04 volumio volumio[211285]: info: CoreStateMachine::pushState Apr 12 16:41:04 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:04 volumio volumio[211285]: info: CoreCommandRouter::volumioPushState Apr 12 16:41:04 volumio volumio[211285]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Apr 12 16:41:04 volumio volumio[211285]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Apr 12 16:41:04 volumio volumio[211285]: info: MPD Permissions set Apr 12 16:41:04 volumio volumio[211285]: info: MPD Permissions set Apr 12 16:41:04 volumio volumio[211285]: info: Volumio called home Apr 12 16:41:04 volumio volumio[211285]: info: Spotify config file written Apr 12 16:41:05 volumio volumio-remote-updater[723]: [2026-04-12 16:41:04] [connect] Successful connection Apr 12 16:41:05 volumio sudo[211510]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 12 16:41:05 volumio volumio[211285]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Apr 12 16:41:05 volumio sudo[211510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 145. Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 12 16:41:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:05 volumio go-librespot[211520]: go-librespot daemon starting... Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio sudo[211510]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:05 volumio go-librespot[211522]: time="2026-04-12T16:41:05Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:05 volumio go-librespot[211522]: time="2026-04-12T16:41:05Z" level=debug msg="app state loaded" Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 12 16:41:05 volumio go-librespot[211522]: time="2026-04-12T16:41:05Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:05 volumio volumio[211285]: info: No need to fix Spotify hosts Apr 12 16:41:05 volumio volumio[211285]: info: Discovery: adding e675fc64-9db0-44b9-b089-c4553e5b48e6 Apr 12 16:41:05 volumio volumio[211285]: info: Discovery: Found device Volumio Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::volumioGetState Apr 12 16:41:05 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:05 volumio volumio[211285]: info: Discovery: this is already registered, e675fc64-9db0-44b9-b089-c4553e5b48e6 Apr 12 16:41:05 volumio volumio[211285]: info: Discovery: Found device Volumio Apr 12 16:41:05 volumio volumio[211285]: info: CoreCommandRouter::volumioGetState Apr 12 16:41:05 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:05 volumio volumio[211285]: info: An error occurred while refreshing Spotify Token Error: self-signed certificate Apr 12 16:41:05 volumio sudo[211539]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 12 16:41:05 volumio sudo[211539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:05 volumio sudo[211541]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 12 16:41:05 volumio sudo[211539]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:05 volumio sudo[211541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:05 volumio go-librespot[211522]: time="2026-04-12T16:41:05Z" 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\": tls: failed to verify certificate: x509: certificate is not valid for any names, but wanted to match apresolve.spotify.com" Apr 12 16:41:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:05 volumio sudo[211541]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:05 volumio volumio-remote-updater[723]: [2026-04-12 16:41:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776012064 101 Apr 12 16:41:05 volumio volumio[211285]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 4 Apr 12 16:41:05 volumio volumio[211285]: info: Starting Shairport Sync Apr 12 16:41:05 volumio volumio[211285]: info: Starting Shairport Sync Apr 12 16:41:06 volumio volumio[211285]: info: Starting Shairport Sync Apr 12 16:41:06 volumio sudo[211545]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 12 16:41:06 volumio sudo[211545]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:06 volumio sudo[211547]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 12 16:41:06 volumio sudo[211547]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:06 volumio sudo[211549]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 12 16:41:06 volumio sudo[211549]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:06 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 12 16:41:06 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 12 16:41:06 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 12 16:41:06 volumio systemd[1]: shairport-sync.service: Consumed 2.206s CPU time. Apr 12 16:41:06 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 12 16:41:06 volumio sudo[211545]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:06 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 12 16:41:06 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 12 16:41:06 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 12 16:41:06 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 12 16:41:06 volumio sudo[211547]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:06 volumio sudo[211549]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:06 volumio volumio[211285]: info: Shairport-Sync Started Apr 12 16:41:06 volumio volumio[211285]: Error adding Membership: Error: addMembership EINVAL Apr 12 16:41:06 volumio sudo[211557]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 12 16:41:06 volumio sudo[211557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:06 volumio volumio[211285]: info: CoreCommandRouter::volumioGetState Apr 12 16:41:06 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:06 volumio volumio[211285]: info: Shairport-Sync Started Apr 12 16:41:06 volumio volumio[211285]: info: Shairport-Sync Started Apr 12 16:41:06 volumio sudo[211557]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:06 volumio volumio[211285]: info: Upmpdcli Daemon Started Apr 12 16:41:06 volumio mpd[211480]: 2026-04-12T16:41:06 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 12 16:41:07 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 12 16:41:07 volumio sudo[211425]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:07 volumio sudo[211447]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:07 volumio volumio[211285]: info: Completed starting Core Plugins Apr 12 16:41:07 volumio volumio[211285]: info: ------------------------------------------- Apr 12 16:41:07 volumio volumio[211285]: info: ----- MyVolumio plugins startup ---- Apr 12 16:41:07 volumio volumio[211285]: info: ------------------------------------------- Apr 12 16:41:07 volumio volumio[211285]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 12 16:41:08 volumio volumio[211285]: error: MPD error: The expression evaluated to a falsy value: Apr 12 16:41:08 volumio volumio[211285]: assert.ok(self.idling) Apr 12 16:41:08 volumio volumio[211285]: error: The expression evaluated to a falsy value: Apr 12 16:41:08 volumio volumio[211285]: assert.ok(self.idling) Apr 12 16:41:08 volumio volumio[211285]: info: MPD running with PID211480 Apr 12 16:41:08 volumio volumio[211285]: ,establishing connection Apr 12 16:41:08 volumio volumio[211285]: error: MPD error: The expression evaluated to a falsy value: Apr 12 16:41:08 volumio volumio[211285]: assert.ok(self.idling) Apr 12 16:41:08 volumio volumio[211285]: error: The expression evaluated to a falsy value: Apr 12 16:41:08 volumio volumio[211285]: assert.ok(self.idling) Apr 12 16:41:08 volumio volumio[211285]: error: updateQueue error: null Apr 12 16:41:08 volumio volumio[211285]: info: go-librespot daemon successfully initialized Apr 12 16:41:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 146. Apr 12 16:41:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:09 volumio go-librespot[211581]: go-librespot daemon starting... Apr 12 16:41:09 volumio go-librespot[211582]: time="2026-04-12T16:41:09Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:09 volumio go-librespot[211582]: time="2026-04-12T16:41:09Z" level=debug msg="app state loaded" Apr 12 16:41:09 volumio go-librespot[211582]: time="2026-04-12T16:41:09Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:09 volumio go-librespot[211582]: time="2026-04-12T16:41:09Z" 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\": tls: failed to verify certificate: x509: certificate is not valid for any names, but wanted to match apresolve.spotify.com" Apr 12 16:41:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:11 volumio dhcpcd[842]: eth0: carrier lost Apr 12 16:41:11 volumio kernel: r8169 0000:01:00.0 eth0: Link is Down Apr 12 16:41:11 volumio avahi-daemon[699]: Withdrawing address record for 192.168.1.2 on eth0. Apr 12 16:41:11 volumio avahi-daemon[699]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.1.2. Apr 12 16:41:11 volumio dhcpcd[842]: eth0: deleting route to 192.168.1.0/24 Apr 12 16:41:11 volumio dhcpcd[842]: eth0: deleting default route via 192.168.1.1 Apr 12 16:41:11 volumio avahi-daemon[699]: Interface eth0.IPv4 no longer relevant for mDNS. Apr 12 16:41:11 volumio volumio[211285]: info: Discovery: A device disappeared from network Apr 12 16:41:11 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:41:12 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Apr 12 16:41:12 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Apr 12 16:41:12 volumio systemd[1]: welcome.service: Deactivated successfully. Apr 12 16:41:12 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Apr 12 16:41:12 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Apr 12 16:41:12 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:41:12 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Apr 12 16:41:12 volumio welcome[211616]: Resolved ip:[0] Apr 12 16:41:12 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Apr 12 16:41:12 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Apr 12 16:41:12 volumio volumio[211285]: info: Received Get System Info Apr 12 16:41:12 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 16:41:12 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 16:41:12 volumio volumio[211285]: info: Discovery: Getting this device information Apr 12 16:41:12 volumio volumio[211285]: info: CoreCommandRouter::volumioGetState Apr 12 16:41:12 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:12 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 16:41:12 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 16:41:12 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 16:41:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 147. Apr 12 16:41:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:12 volumio go-librespot[211624]: go-librespot daemon starting... Apr 12 16:41:12 volumio ifplugd(eth0)[916]: Link beat lost. Apr 12 16:41:12 volumio go-librespot[211625]: time="2026-04-12T16:41:12Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:12 volumio go-librespot[211625]: time="2026-04-12T16:41:12Z" level=debug msg="app state loaded" Apr 12 16:41:12 volumio go-librespot[211625]: time="2026-04-12T16:41:12Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:12 volumio go-librespot[211625]: time="2026-04-12T16:41:12Z" 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" Apr 12 16:41:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:13 volumio volumio[211285]: info: Volumio Network Manager: Network status updated: 0 Apr 12 16:41:13 volumio volumio5-onboarding[2284]: time=2026-04-12T16:41:13.413Z level=INFO msg="service successfully established" component=discovery/localnet Apr 12 16:41:13 volumio ntpd[902]: IO: Deleting interface #7 eth0, 192.168.1.2#123, interface stats: received=20, sent=20, dropped=0, active_time=2929 secs Apr 12 16:41:13 volumio ntpd[902]: PROTO: 140.186.0.227 unlink local addr 192.168.1.2 -> Apr 12 16:41:13 volumio ntpd[902]: PROTO: 208.113.130.146 unlink local addr 192.168.1.2 -> Apr 12 16:41:13 volumio ntpd[902]: PROTO: 50.117.3.95 unlink local addr 192.168.1.2 -> Apr 12 16:41:13 volumio ntpd[902]: PROTO: 155.248.196.28 unlink local addr 192.168.1.2 -> Apr 12 16:41:13 volumio ntpd[902]: PROTO: 162.159.200.1 unlink local addr 192.168.1.2 -> Apr 12 16:41:13 volumio ntpd[902]: PROTO: 50.205.57.38 unlink local addr 192.168.1.2 -> Apr 12 16:41:13 volumio ntpd[902]: PROTO: 192.227.170.78 unlink local addr 192.168.1.2 -> Apr 12 16:41:15 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:41:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 148. Apr 12 16:41:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:15 volumio go-librespot[211649]: go-librespot daemon starting... Apr 12 16:41:15 volumio go-librespot[211650]: time="2026-04-12T16:41:15Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:15 volumio go-librespot[211650]: time="2026-04-12T16:41:15Z" level=debug msg="app state loaded" Apr 12 16:41:16 volumio go-librespot[211650]: time="2026-04-12T16:41:16Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:16 volumio go-librespot[211650]: time="2026-04-12T16:41:16Z" 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" Apr 12 16:41:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:16 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:41:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 149. Apr 12 16:41:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:19 volumio go-librespot[211660]: go-librespot daemon starting... Apr 12 16:41:19 volumio go-librespot[211661]: time="2026-04-12T16:41:19Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:19 volumio go-librespot[211661]: time="2026-04-12T16:41:19Z" level=debug msg="app state loaded" Apr 12 16:41:19 volumio go-librespot[211661]: time="2026-04-12T16:41:19Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:19 volumio go-librespot[211661]: time="2026-04-12T16:41:19Z" 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" Apr 12 16:41:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:19 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:41:21 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:41:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 150. Apr 12 16:41:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:22 volumio go-librespot[211672]: go-librespot daemon starting... Apr 12 16:41:22 volumio go-librespot[211673]: time="2026-04-12T16:41:22Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:22 volumio go-librespot[211673]: time="2026-04-12T16:41:22Z" level=debug msg="app state loaded" Apr 12 16:41:22 volumio go-librespot[211673]: time="2026-04-12T16:41:22Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:22 volumio go-librespot[211673]: time="2026-04-12T16:41:22Z" 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" Apr 12 16:41:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:22 volumio ifplugd(eth0)[916]: Executing '/etc/ifplugd/ifplugd.action eth0 down'. Apr 12 16:41:22 volumio kernel: r8169 0000:01:00.0 eth0: Link is Up - 100Mbps/Full - flow control rx/tx Apr 12 16:41:22 volumio dhcpcd[842]: eth0: carrier acquired Apr 12 16:41:22 volumio dhcpcd[842]: eth0: IAID 01:a2:8c:17 Apr 12 16:41:22 volumio dhcpcd[211691]: dhcpcd not running Apr 12 16:41:22 volumio ifplugd(eth0)[916]: client: dhcpcd not running Apr 12 16:41:22 volumio kernel: r8169 0000:01:00.0 eth0: Link is Down Apr 12 16:41:22 volumio dhcpcd[842]: eth0: carrier lost Apr 12 16:41:23 volumio ifplugd(eth0)[916]: Program executed successfully. Apr 12 16:41:23 volumio kernel: RTL8208 Fast Ethernet r8169-0-100:00: attached PHY driver (mii_bus:phy_addr=r8169-0-100:00, irq=MAC) Apr 12 16:41:23 volumio dhcpcd[842]: eth0: carrier acquired Apr 12 16:41:23 volumio kernel: r8169 0000:01:00.0 eth0: Link is Down Apr 12 16:41:23 volumio dhcpcd[842]: eth0: IAID 01:a2:8c:17 Apr 12 16:41:23 volumio dhcpcd[842]: eth0: carrier lost Apr 12 16:41:24 volumio wireless.js[724]: WIRELESS.JS - INFO: === SNM TRANSITION === Apr 12 16:41:24 volumio wireless.js[724]: WIRELESS.JS - INFO: Previous ethernet state: connected Apr 12 16:41:24 volumio wireless.js[724]: WIRELESS.JS - INFO: New ethernet state: disconnected Apr 12 16:41:24 volumio wireless.js[724]: WIRELESS.JS - INFO: Single Network Mode: enabled Apr 12 16:41:24 volumio wireless.js[724]: WIRELESS.JS - INFO: First start: no Apr 12 16:41:24 volumio wireless.js[724]: WIRELESS.JS - INFO: Action: Reconnect WiFi Apr 12 16:41:24 volumio wireless.js[724]: WIRELESS.JS - INFO: === END TRANSITION === Apr 12 16:41:24 volumio sudo[211736]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Apr 12 16:41:24 volumio sudo[211736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:24 volumio sudo[211736]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:24 volumio wireless.js[724]: WIRELESS.JS - INFO: SNM: Ethernet disconnected, reconnecting WiFi Apr 12 16:41:24 volumio wireless.js[724]: WIRELESS.JS - INFO: SNM: Ethernet disconnected, reconnecting WiFi Apr 12 16:41:24 volumio wireless.js[724]: WIRELESS.JS - INFO: reconnectWiFi: Reconnect command failed: Error: Command failed: /sbin/wpa_cli -i wlan0 reconnect Apr 12 16:41:24 volumio wireless.js[724]: Failed to connect to non-global ctrl_ifname: wlan0 error: No such file or directory Apr 12 16:41:24 volumio wireless.js[724]: WIRELESS.JS - INFO: reconnectWiFi: Falling back to full wireless flow restart Apr 12 16:41:24 volumio wireless.js[724]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow Apr 12 16:41:24 volumio dhcpcd[842]: eth0: carrier acquired Apr 12 16:41:24 volumio kernel: r8169 0000:01:00.0 eth0: Link is Up - 100Mbps/Full - flow control rx/tx Apr 12 16:41:24 volumio dhcpcd[842]: eth0: IAID 01:a2:8c:17 Apr 12 16:41:25 volumio sudo[211753]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 12 16:41:25 volumio sudo[211753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 12 16:41:25 volumio sudo[211753]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:25 volumio sudo[211755]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 12 16:41:25 volumio sudo[211755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 12 16:41:25 volumio sudo[211755]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:25 volumio wireless.js[724]: WIRELESS.JS - INFO: Cleaning previous... Apr 12 16:41:25 volumio wireless.js[724]: WIRELESS.JS - INFO: === SNM TRANSITION === Apr 12 16:41:25 volumio wireless.js[724]: WIRELESS.JS - INFO: Previous ethernet state: disconnected Apr 12 16:41:25 volumio wireless.js[724]: WIRELESS.JS - INFO: New ethernet state: connected Apr 12 16:41:25 volumio wireless.js[724]: WIRELESS.JS - INFO: Single Network Mode: enabled Apr 12 16:41:25 volumio wireless.js[724]: WIRELESS.JS - INFO: First start: no Apr 12 16:41:25 volumio wireless.js[724]: WIRELESS.JS - INFO: Action: Switch to ethernet (WiFi scan mode) Apr 12 16:41:25 volumio wireless.js[724]: WIRELESS.JS - INFO: === END TRANSITION === Apr 12 16:41:25 volumio wireless.js[724]: WIRELESS.JS - INFO: SNM: Ethernet connected, switching to ethernet (WiFi scan mode) Apr 12 16:41:25 volumio sudo[211758]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 12 16:41:25 volumio sudo[211758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 12 16:41:25 volumio sudo[211761]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd -k wlan0 Apr 12 16:41:25 volumio sudo[211761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 12 16:41:25 volumio sudo[211758]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:25 volumio dhcpcd[211763]: dhcpcd not running Apr 12 16:41:25 volumio sudo[211761]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:25 volumio wireless.js[724]: dhcpcd not running Apr 12 16:41:25 volumio wireless.js[724]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow Apr 12 16:41:25 volumio ifplugd(eth0)[916]: Link beat detected. Apr 12 16:41:25 volumio ifplugd(eth0)[916]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Apr 12 16:41:25 volumio wireless.js[724]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Apr 12 16:41:25 volumio wireless.js[724]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 19ms Apr 12 16:41:25 volumio wireless.js[724]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: 2c:d0:5a:f9:4a:00) Apr 12 16:41:25 volumio dhcpcd[842]: eth0: soliciting an IPv6 router Apr 12 16:41:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 151. Apr 12 16:41:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:25 volumio go-librespot[211778]: go-librespot daemon starting... Apr 12 16:41:25 volumio go-librespot[211784]: time="2026-04-12T16:41:25Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:25 volumio go-librespot[211784]: time="2026-04-12T16:41:25Z" level=debug msg="app state loaded" Apr 12 16:41:25 volumio sudo[211779]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Apr 12 16:41:25 volumio sudo[211779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:25 volumio go-librespot[211784]: time="2026-04-12T16:41:25Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:25 volumio go-librespot[211784]: time="2026-04-12T16:41:25Z" 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" Apr 12 16:41:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:25 volumio sudo[211779]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:25 volumio dhcpcd[842]: ps_ctl_dispatch: cannot handle another client Apr 12 16:41:25 volumio ifplugd(eth0)[916]: client: sending commands to dhcpcd process Apr 12 16:41:25 volumio dhcpcd[842]: control_free: No such file or directory Apr 12 16:41:25 volumio sudo[211815]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Apr 12 16:41:25 volumio sudo[211815]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:26 volumio ifplugd(eth0)[916]: Program executed successfully. Apr 12 16:41:26 volumio dhcpcd[842]: eth0: rebinding lease of 192.168.1.2 Apr 12 16:41:26 volumio sudo[211815]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:26 volumio wireless.js[724]: WIRELESS.JS - INFO: Regdomain already correct: US Apr 12 16:41:26 volumio wireless.js[724]: WIRELESS.JS - INFO: netconfigured file not found, starting hotspot Apr 12 16:41:26 volumio wireless.js[724]: WIRELESS.JS - INFO: Single Network Mode: Ethernet active, maintaining WiFi scan capability Apr 12 16:41:26 volumio wireless.js[724]: WIRELESS.JS - INFO: SNM: Maintaining wlan0 UP without IP (scan mode) Apr 12 16:41:26 volumio wireless.js[724]: WIRELESS.JS - INFO: SNM: Users can configure WiFi via WebUI while ethernet is active Apr 12 16:41:27 volumio sudo[211853]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 12 16:41:27 volumio sudo[211853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 12 16:41:27 volumio sudo[211853]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:27 volumio sudo[211855]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Apr 12 16:41:27 volumio sudo[211855]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 12 16:41:27 volumio sudo[211855]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:27 volumio wireless.js[724]: WIRELESS.JS - INFO: Cleaning previous... Apr 12 16:41:27 volumio sudo[211859]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 12 16:41:27 volumio sudo[211859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 12 16:41:27 volumio sudo[211859]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:27 volumio sudo[211861]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Apr 12 16:41:27 volumio sudo[211861]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 12 16:41:27 volumio sudo[211861]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:27 volumio sudo[211865]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Apr 12 16:41:27 volumio sudo[211865]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 12 16:41:27 volumio sudo[211865]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:27 volumio wireless.js[724]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations Apr 12 16:41:27 volumio wireless.js[724]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 22ms Apr 12 16:41:27 volumio wireless.js[724]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: 2c:d0:5a:f9:4a:00) Apr 12 16:41:27 volumio volumio[211285]: info: Received Get System Info Apr 12 16:41:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 16:41:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 16:41:27 volumio volumio[211285]: info: Discovery: Getting this device information Apr 12 16:41:27 volumio volumio[211285]: info: CoreCommandRouter::volumioGetState Apr 12 16:41:27 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 16:41:27 volumio volumio[211285]: info: Received Get System Info Apr 12 16:41:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 16:41:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 16:41:27 volumio volumio[211285]: info: Discovery: Getting this device information Apr 12 16:41:27 volumio volumio[211285]: info: CoreCommandRouter::volumioGetState Apr 12 16:41:27 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 16:41:27 volumio volumio[211285]: info: Received Get System Info Apr 12 16:41:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 16:41:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 16:41:27 volumio volumio[211285]: info: Discovery: Getting this device information Apr 12 16:41:27 volumio volumio[211285]: info: CoreCommandRouter::volumioGetState Apr 12 16:41:27 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 16:41:27 volumio volumio[211285]: info: Received Get System Info Apr 12 16:41:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 16:41:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 16:41:27 volumio volumio[211285]: info: Discovery: Getting this device information Apr 12 16:41:27 volumio volumio[211285]: info: CoreCommandRouter::volumioGetState Apr 12 16:41:27 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 16:41:27 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:41:27 volumio sudo[211873]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Apr 12 16:41:27 volumio sudo[211873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:27 volumio sudo[211873]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:28 volumio sudo[211881]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Apr 12 16:41:28 volumio sudo[211881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 12 16:41:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 152. Apr 12 16:41:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:28 volumio go-librespot[211886]: go-librespot daemon starting... Apr 12 16:41:28 volumio sudo[211881]: pam_unix(sudo:session): session closed for user root Apr 12 16:41:28 volumio wireless.js[724]: WIRELESS.JS - INFO: Regdomain already correct: US Apr 12 16:41:29 volumio go-librespot[211887]: time="2026-04-12T16:41:29Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:29 volumio go-librespot[211887]: time="2026-04-12T16:41:29Z" level=debug msg="app state loaded" Apr 12 16:41:29 volumio wpa_supplicant[211893]: Successfully initialized wpa_supplicant Apr 12 16:41:29 volumio go-librespot[211887]: time="2026-04-12T16:41:29Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:29 volumio go-librespot[211887]: time="2026-04-12T16:41:29Z" 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" Apr 12 16:41:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:29 volumio wireless.js[724]: WIRELESS.JS - INFO: SNM: Transition to scan mode completed in 3951ms Apr 12 16:41:29 volumio wireless.js[724]: WIRELESS.JS - INFO: SNM: wlan0 is UP without IP, scan capable Apr 12 16:41:29 volumio wireless.js[724]: Failed to connect to non-global ctrl_ifname: wlan0 error: No such file or directory Apr 12 16:41:29 volumio wireless.js[724]: WIRELESS.JS - INFO: Notified systemd about wireless ready Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 16:41:29 volumio volumio[211285]: info: Received Get System Info Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 16:41:29 volumio volumio[211285]: info: Discovery: Getting this device information Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::volumioGetState Apr 12 16:41:29 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 16:41:29 volumio volumio[211285]: info: Received Get System Info Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 16:41:29 volumio volumio[211285]: info: Discovery: Getting this device information Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::volumioGetState Apr 12 16:41:29 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 16:41:29 volumio volumio[211285]: error: MyVolumio Plugin failed to start in a timely fashion Apr 12 16:41:29 volumio volumio[211285]: [Metrics] CommandRouter: 39s 987.84ms Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::volumiosetStartupVolume Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::Close All Modals sent Apr 12 16:41:29 volumio volumio[211285]: info: CoreCommandRouter::Close All Modals sent Apr 12 16:41:31 volumio dhcpcd[842]: eth0: DHCP lease expired Apr 12 16:41:31 volumio dhcpcd[842]: eth0: soliciting a DHCP lease Apr 12 16:41:31 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 16:41:31 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 16:41:31 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 16:41:31 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 16:41:31 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:41:31 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 12 16:41:31 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 12 16:41:31 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 12 16:41:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 153. Apr 12 16:41:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:32 volumio go-librespot[211926]: go-librespot daemon starting... Apr 12 16:41:32 volumio go-librespot[211927]: time="2026-04-12T16:41:32Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:32 volumio go-librespot[211927]: time="2026-04-12T16:41:32Z" level=debug msg="app state loaded" Apr 12 16:41:32 volumio go-librespot[211927]: time="2026-04-12T16:41:32Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:32 volumio go-librespot[211927]: time="2026-04-12T16:41:32Z" 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" Apr 12 16:41:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:35 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 12 16:41:35 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 12 16:41:35 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 12 16:41:35 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:41:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 154. Apr 12 16:41:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:35 volumio go-librespot[211954]: go-librespot daemon starting... Apr 12 16:41:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:35 volumio go-librespot[211955]: time="2026-04-12T16:41:35Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:35 volumio go-librespot[211955]: time="2026-04-12T16:41:35Z" level=debug msg="app state loaded" Apr 12 16:41:35 volumio go-librespot[211955]: time="2026-04-12T16:41:35Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:35 volumio go-librespot[211955]: time="2026-04-12T16:41:35Z" 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" Apr 12 16:41:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:35 volumio volumio5-onboarding[2284]: time=2026-04-12T16:41:35.566Z level=INFO msg="service successfully established" component=discovery/localnet Apr 12 16:41:36 volumio dhcpcd[842]: eth0: carrier lost Apr 12 16:41:36 volumio kernel: r8169 0000:01:00.0 eth0: Link is Down Apr 12 16:41:36 volumio ifplugd(eth0)[916]: Link beat lost. Apr 12 16:41:36 volumio volumio[211285]: info: BOOT COMPLETED Apr 12 16:41:37 volumio kernel: r8169 0000:01:00.0 eth0: Link is Up - 100Mbps/Full - flow control rx/tx Apr 12 16:41:37 volumio dhcpcd[842]: eth0: carrier acquired Apr 12 16:41:37 volumio dhcpcd[842]: eth0: IAID 01:a2:8c:17 Apr 12 16:41:38 volumio dhcpcd[842]: eth0: soliciting an IPv6 router Apr 12 16:41:38 volumio ifplugd(eth0)[916]: Link beat detected. Apr 12 16:41:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 155. Apr 12 16:41:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:38 volumio go-librespot[211981]: go-librespot daemon starting... Apr 12 16:41:38 volumio go-librespot[211982]: time="2026-04-12T16:41:38Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:38 volumio go-librespot[211982]: time="2026-04-12T16:41:38Z" level=debug msg="app state loaded" Apr 12 16:41:38 volumio go-librespot[211982]: time="2026-04-12T16:41:38Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:38 volumio go-librespot[211982]: time="2026-04-12T16:41:38Z" 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" Apr 12 16:41:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:38 volumio volumio[211285]: info: Received Get System Info Apr 12 16:41:38 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 16:41:38 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 16:41:38 volumio volumio[211285]: info: Discovery: Getting this device information Apr 12 16:41:38 volumio volumio[211285]: info: CoreCommandRouter::volumioGetState Apr 12 16:41:38 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:38 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 16:41:38 volumio volumio[211285]: info: Received Get System Info Apr 12 16:41:38 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 16:41:38 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 16:41:38 volumio volumio[211285]: info: Discovery: Getting this device information Apr 12 16:41:38 volumio volumio[211285]: info: CoreCommandRouter::volumioGetState Apr 12 16:41:38 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:38 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 16:41:38 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:41:39 volumio dhcpcd[842]: eth0: soliciting a DHCP lease Apr 12 16:41:40 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 16:41:40 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 16:41:40 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 16:41:40 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 16:41:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 156. Apr 12 16:41:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:41 volumio go-librespot[211993]: go-librespot daemon starting... Apr 12 16:41:41 volumio go-librespot[211994]: time="2026-04-12T16:41:41Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:41 volumio go-librespot[211994]: time="2026-04-12T16:41:41Z" level=debug msg="app state loaded" Apr 12 16:41:41 volumio go-librespot[211994]: time="2026-04-12T16:41:41Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:41 volumio go-librespot[211994]: time="2026-04-12T16:41:41Z" 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" Apr 12 16:41:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:42 volumio volumio5-onboarding[2284]: time=2026-04-12T16:41:42.917Z level=INFO msg="service successfully established" component=discovery/localnet Apr 12 16:41:44 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:41:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 157. Apr 12 16:41:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:45 volumio go-librespot[212019]: go-librespot daemon starting... Apr 12 16:41:45 volumio go-librespot[212020]: time="2026-04-12T16:41:45Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:45 volumio go-librespot[212020]: time="2026-04-12T16:41:45Z" level=debug msg="app state loaded" Apr 12 16:41:45 volumio go-librespot[212020]: time="2026-04-12T16:41:45Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:45 volumio go-librespot[212020]: time="2026-04-12T16:41:45Z" 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" Apr 12 16:41:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 158. Apr 12 16:41:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:48 volumio go-librespot[212030]: go-librespot daemon starting... Apr 12 16:41:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:48 volumio go-librespot[212031]: time="2026-04-12T16:41:48Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:48 volumio go-librespot[212031]: time="2026-04-12T16:41:48Z" level=debug msg="app state loaded" Apr 12 16:41:48 volumio go-librespot[212031]: time="2026-04-12T16:41:48Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:48 volumio go-librespot[212031]: time="2026-04-12T16:41:48Z" 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" Apr 12 16:41:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:50 volumio kernel: r8169 0000:01:00.0 eth0: Link is Down Apr 12 16:41:50 volumio dhcpcd[842]: eth0: carrier lost Apr 12 16:41:51 volumio ifplugd(eth0)[916]: Link beat lost. Apr 12 16:41:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 159. Apr 12 16:41:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:51 volumio go-librespot[212055]: go-librespot daemon starting... Apr 12 16:41:51 volumio go-librespot[212056]: time="2026-04-12T16:41:51Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:51 volumio go-librespot[212056]: time="2026-04-12T16:41:51Z" level=debug msg="app state loaded" Apr 12 16:41:51 volumio go-librespot[212056]: time="2026-04-12T16:41:51Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:51 volumio go-librespot[212056]: time="2026-04-12T16:41:51Z" 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" Apr 12 16:41:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:52 volumio dhcpcd[842]: eth0: carrier acquired Apr 12 16:41:52 volumio kernel: r8169 0000:01:00.0 eth0: Link is Up - 100Mbps/Full - flow control rx/tx Apr 12 16:41:52 volumio dhcpcd[842]: eth0: IAID 01:a2:8c:17 Apr 12 16:41:52 volumio dhcpcd[842]: eth0: soliciting an IPv6 router Apr 12 16:41:52 volumio ifplugd(eth0)[916]: Link beat detected. Apr 12 16:41:52 volumio dhcpcd[842]: eth0: soliciting a DHCP lease Apr 12 16:41:52 volumio volumio[211285]: info: Received Get System Info Apr 12 16:41:52 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 16:41:52 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 16:41:52 volumio volumio[211285]: info: Discovery: Getting this device information Apr 12 16:41:52 volumio volumio[211285]: info: CoreCommandRouter::volumioGetState Apr 12 16:41:52 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:52 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 16:41:52 volumio volumio[211285]: info: Received Get System Info Apr 12 16:41:52 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 16:41:52 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 16:41:52 volumio volumio[211285]: info: Discovery: Getting this device information Apr 12 16:41:52 volumio volumio[211285]: info: CoreCommandRouter::volumioGetState Apr 12 16:41:52 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:41:52 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 16:41:52 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:41:52 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 16:41:52 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 16:41:52 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 16:41:52 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 16:41:54 volumio volumio5-onboarding[2284]: time=2026-04-12T16:41:54.695Z level=INFO msg="service successfully established" component=discovery/localnet Apr 12 16:41:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 160. Apr 12 16:41:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:54 volumio go-librespot[212083]: go-librespot daemon starting... Apr 12 16:41:54 volumio go-librespot[212084]: time="2026-04-12T16:41:54Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:54 volumio go-librespot[212084]: time="2026-04-12T16:41:54Z" level=debug msg="app state loaded" Apr 12 16:41:54 volumio go-librespot[212084]: time="2026-04-12T16:41:54Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:54 volumio go-librespot[212084]: time="2026-04-12T16:41:54Z" 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" Apr 12 16:41:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:55 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:41:55 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:41:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 161. Apr 12 16:41:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:41:58 volumio go-librespot[212094]: go-librespot daemon starting... Apr 12 16:41:58 volumio go-librespot[212095]: time="2026-04-12T16:41:58Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:41:58 volumio go-librespot[212095]: time="2026-04-12T16:41:58Z" level=debug msg="app state loaded" Apr 12 16:41:58 volumio go-librespot[212095]: time="2026-04-12T16:41:58Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:41:58 volumio go-librespot[212095]: time="2026-04-12T16:41:58Z" 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" Apr 12 16:41:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:41:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:41:58 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:41:58 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:42:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 162. Apr 12 16:42:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:01 volumio go-librespot[212107]: go-librespot daemon starting... Apr 12 16:42:01 volumio go-librespot[212108]: time="2026-04-12T16:42:01Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:42:01 volumio go-librespot[212108]: time="2026-04-12T16:42:01Z" level=debug msg="app state loaded" Apr 12 16:42:01 volumio go-librespot[212108]: time="2026-04-12T16:42:01Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:42:01 volumio go-librespot[212108]: time="2026-04-12T16:42:01Z" 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" Apr 12 16:42:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:42:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:42:01 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:42:01 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:42:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 163. Apr 12 16:42:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:04 volumio go-librespot[212133]: go-librespot daemon starting... Apr 12 16:42:04 volumio go-librespot[212134]: time="2026-04-12T16:42:04Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:42:04 volumio go-librespot[212134]: time="2026-04-12T16:42:04Z" level=debug msg="app state loaded" Apr 12 16:42:04 volumio go-librespot[212134]: time="2026-04-12T16:42:04Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:42:04 volumio go-librespot[212134]: time="2026-04-12T16:42:04Z" 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" Apr 12 16:42:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:42:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:42:04 volumio nmbd[1035]: [2026/04/12 16:42:04.823815, 0] ../../source3/libsmb/nmblib.c:923(send_udp) Apr 12 16:42:04 volumio nmbd[1035]: Packet send failed to 192.168.1.255(137) ERRNO=Network is unreachable Apr 12 16:42:04 volumio nmbd[1035]: [2026/04/12 16:42:04.824078, 0] ../../source3/nmbd/nmbd_packets.c:180(send_netbios_packet) Apr 12 16:42:04 volumio nmbd[1035]: send_netbios_packet: send_packet() to IP 192.168.1.255 port 137 failed Apr 12 16:42:04 volumio nmbd[1035]: [2026/04/12 16:42:04.824166, 0] ../../source3/nmbd/nmbd_namequery.c:245(query_name) Apr 12 16:42:04 volumio nmbd[1035]: query_name: Failed to send packet trying to query name WORKGROUP<1d> Apr 12 16:42:04 volumio nmbd[1035]: [2026/04/12 16:42:04.834506, 0] ../../source3/nmbd/nmbd.c:359(reload_interfaces) Apr 12 16:42:04 volumio nmbd[1035]: reload_interfaces: No subnets to listen to. Waiting.. Apr 12 16:42:04 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:42:04 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:42:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 164. Apr 12 16:42:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:07 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:42:07 volumio go-librespot[212146]: go-librespot daemon starting... Apr 12 16:42:07 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:42:07 volumio go-librespot[212147]: time="2026-04-12T16:42:07Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:42:07 volumio go-librespot[212147]: time="2026-04-12T16:42:07Z" level=debug msg="app state loaded" Apr 12 16:42:07 volumio go-librespot[212147]: time="2026-04-12T16:42:07Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:42:07 volumio go-librespot[212147]: time="2026-04-12T16:42:07Z" 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" Apr 12 16:42:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:42:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:42:10 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:42:10 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:42:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 165. Apr 12 16:42:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:11 volumio go-librespot[212158]: go-librespot daemon starting... Apr 12 16:42:11 volumio go-librespot[212159]: time="2026-04-12T16:42:11Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:42:11 volumio go-librespot[212159]: time="2026-04-12T16:42:11Z" level=debug msg="app state loaded" Apr 12 16:42:11 volumio go-librespot[212159]: time="2026-04-12T16:42:11Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:42:11 volumio go-librespot[212159]: time="2026-04-12T16:42:11Z" 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" Apr 12 16:42:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:42:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:42:13 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:42:13 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:42:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 166. Apr 12 16:42:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:14 volumio go-librespot[212183]: go-librespot daemon starting... Apr 12 16:42:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:14 volumio go-librespot[212184]: time="2026-04-12T16:42:14Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:42:14 volumio go-librespot[212184]: time="2026-04-12T16:42:14Z" level=debug msg="app state loaded" Apr 12 16:42:14 volumio go-librespot[212184]: time="2026-04-12T16:42:14Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:42:14 volumio go-librespot[212184]: time="2026-04-12T16:42:14Z" 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" Apr 12 16:42:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:42:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:42:16 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:42:16 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:42:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 167. Apr 12 16:42:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:17 volumio go-librespot[212194]: go-librespot daemon starting... Apr 12 16:42:17 volumio go-librespot[212195]: time="2026-04-12T16:42:17Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:42:17 volumio go-librespot[212195]: time="2026-04-12T16:42:17Z" level=debug msg="app state loaded" Apr 12 16:42:17 volumio go-librespot[212195]: time="2026-04-12T16:42:17Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:42:17 volumio go-librespot[212195]: time="2026-04-12T16:42:17Z" 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" Apr 12 16:42:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:42:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:42:19 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:42:19 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:42:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 168. Apr 12 16:42:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:20 volumio go-librespot[212205]: go-librespot daemon starting... Apr 12 16:42:20 volumio go-librespot[212207]: time="2026-04-12T16:42:20Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:42:20 volumio go-librespot[212207]: time="2026-04-12T16:42:20Z" level=debug msg="app state loaded" Apr 12 16:42:20 volumio go-librespot[212207]: time="2026-04-12T16:42:20Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:42:20 volumio go-librespot[212207]: time="2026-04-12T16:42:20Z" 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" Apr 12 16:42:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:42:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:42:21 volumio dhcpcd[842]: eth0: offered 192.168.1.2 from 192.168.1.1 Apr 12 16:42:21 volumio dhcpcd[842]: eth0: probing address 192.168.1.2/24 Apr 12 16:42:22 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:42:22 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:42:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 169. Apr 12 16:42:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:24 volumio go-librespot[212218]: go-librespot daemon starting... Apr 12 16:42:24 volumio go-librespot[212219]: time="2026-04-12T16:42:24Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:42:24 volumio go-librespot[212219]: time="2026-04-12T16:42:24Z" level=debug msg="app state loaded" Apr 12 16:42:24 volumio go-librespot[212219]: time="2026-04-12T16:42:24Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:42:24 volumio go-librespot[212219]: time="2026-04-12T16:42:24Z" 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" Apr 12 16:42:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:42:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:42:25 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:42:25 volumio volumio[211285]: info: Error connecting to go-librespot Websocket: AggregateError Apr 12 16:42:26 volumio dhcpcd[842]: eth0: leased 192.168.1.2 for 86400 seconds Apr 12 16:42:26 volumio avahi-daemon[699]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.2. Apr 12 16:42:26 volumio avahi-daemon[699]: New relevant interface eth0.IPv4 for mDNS. Apr 12 16:42:26 volumio avahi-daemon[699]: Registering new address record for 192.168.1.2 on eth0.IPv4. Apr 12 16:42:26 volumio dhcpcd[842]: eth0: adding route to 192.168.1.0/24 Apr 12 16:42:26 volumio dhcpcd[842]: eth0: adding default route via 192.168.1.1 Apr 12 16:42:27 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Apr 12 16:42:27 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Apr 12 16:42:27 volumio systemd[1]: welcome.service: Deactivated successfully. Apr 12 16:42:27 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Apr 12 16:42:27 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Apr 12 16:42:27 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Apr 12 16:42:27 volumio welcome[212253]: Resolved ip:[1] 192.168.1.2 Apr 12 16:42:27 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Apr 12 16:42:27 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Apr 12 16:42:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 170. Apr 12 16:42:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 12 16:42:27 volumio go-librespot[212269]: go-librespot daemon starting... Apr 12 16:42:27 volumio go-librespot[212270]: time="2026-04-12T16:42:27Z" level=info msg="running go-librespot 0.7.1" Apr 12 16:42:27 volumio go-librespot[212270]: time="2026-04-12T16:42:27Z" level=debug msg="app state loaded" Apr 12 16:42:27 volumio go-librespot[212270]: time="2026-04-12T16:42:27Z" level=info msg="api server listening on 127.0.0.1:9879" Apr 12 16:42:27 volumio volumio[211285]: info: Received Get System Info Apr 12 16:42:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 12 16:42:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 12 16:42:27 volumio volumio[211285]: info: Discovery: Getting this device information Apr 12 16:42:27 volumio volumio[211285]: info: CoreCommandRouter::volumioGetState Apr 12 16:42:27 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:42:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 12 16:42:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 12 16:42:27 volumio volumio[211285]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 12 16:42:28 volumio ntpd[902]: IO: Listen normally on 8 eth0 192.168.1.2:123 Apr 12 16:42:28 volumio ntpd[902]: IO: new interface(s) found: waking up resolver Apr 12 16:42:28 volumio volumio5-onboarding[2284]: time=2026-04-12T16:42:28.435Z level=INFO msg="service successfully established" component=discovery/localnet Apr 12 16:42:28 volumio volumio[211285]: info: Initializing connection to go-librespot Websocket Apr 12 16:42:28 volumio go-librespot[212270]: time="2026-04-12T16:42:28Z" level=debug msg="new websocket client" Apr 12 16:42:28 volumio volumio[211285]: info: Connection to go-librespot Websocket established Apr 12 16:42:32 volumio volumio[211285]: info: Getting Spotify volume Apr 12 16:42:34 volumio volumio[211285]: info: Volumio Network Manager: Network status updated: 1 Apr 12 16:42:40 volumio volumio[211285]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Apr 12 16:42:40 volumio volumio[211285]: info: CoreCommandRouter::volumioGetState Apr 12 16:42:40 volumio volumio[211285]: info: CorePlayQueue::getTrack 0 Apr 12 16:42:45 volumio go-librespot[212270]: time="2026-04-12T16:42:45Z" 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" Apr 12 16:42:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 12 16:42:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 12 16:42:45 volumio volumio[211285]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 16:42:45 volumio volumio[211285]: Error: socket hang up Apr 12 16:42:45 volumio volumio[211285]: at connResetException (node:internal/errors:720:14) Apr 12 16:42:45 volumio volumio[211285]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 12 16:42:45 volumio volumio[211285]: at Socket.emit (node:events:526:35) Apr 12 16:42:45 volumio volumio[211285]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 12 16:42:45 volumio volumio[211285]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 12 16:42:45 volumio volumio[211285]: code: 'ECONNRESET', Apr 12 16:42:45 volumio volumio[211285]: response: undefined Apr 12 16:42:45 volumio volumio[211285]: } Apr 12 16:42:45 volumio volumio[211285]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 12 16:42:46 volumio sudo[212338]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-12 16:41' Apr 12 16:42:46 volumio sudo[212338]: 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"