Apr 12 15:17:00 volumio go-librespot[172187]: time="2026-04-12T15:17:00Z" 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 15:17:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:01 volumio volumio[172086]: info: Loading plugin "stylish_player"...
Apr 12 15:17:01 volumio volumio[172086]: info: Loading plugin "outputs"...
Apr 12 15:17:01 volumio volumio[172086]: info: Loading plugin "albumart"...
Apr 12 15:17:01 volumio volumio[172086]: info: Plugin example_plugin is not enabled
Apr 12 15:17:01 volumio volumio[172086]: info: Loading plugin "inputs"...
Apr 12 15:17:01 volumio volumio[172086]: info: Loading plugin "updater_comm"...
Apr 12 15:17:01 volumio volumio5-onboarding[2284]: time=2026-04-12T15:17:01.385Z level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:59304->127.0.0.1:3000: i/o timeout"
Apr 12 15:17:01 volumio volumio[172086]: info: Plugin mpdemulation is not enabled
Apr 12 15:17:01 volumio volumio[172086]: info: Loading plugin "rest_api"...
Apr 12 15:17:01 volumio volumio[172086]: info: Loading plugin "websocket"...
Apr 12 15:17:01 volumio volumio[172086]: info: Starting Socket.io Server version 1.7.4
Apr 12 15:17:01 volumio volumio[172086]: info: Loading plugin "fusiondsp"...
Apr 12 15:17:01 volumio volumio[172198]: Forking 1 albumart workers
Apr 12 15:17:02 volumio volumio[172086]: info: Applying required configuration parameters for plugin fusiondsp
Apr 12 15:17:02 volumio volumio[172086]: info: Loading plugin "display_configuration"...
Apr 12 15:17:03 volumio volumio[172208]: Starting albumart workers
Apr 12 15:17:03 volumio volumio[172086]: info: Loading plugin "peppyspectrum"...
Apr 12 15:17:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 713.
Apr 12 15:17:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:03 volumio go-librespot[172220]: go-librespot daemon starting...
Apr 12 15:17:03 volumio go-librespot[172221]: time="2026-04-12T15:17:03Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:03 volumio go-librespot[172221]: time="2026-04-12T15:17:03Z" level=debug msg="app state loaded"
Apr 12 15:17:03 volumio go-librespot[172221]: time="2026-04-12T15:17:03Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:03 volumio go-librespot[172221]: time="2026-04-12T15:17:03Z" 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 15:17:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:04 volumio volumio[172086]: info: Loading i18n strings for locale en
Apr 12 15:17:04 volumio volumio[172086]: info: Plugin peppyspectrum has duplicated i18n key APPLY. It is ignored.
Apr 12 15:17:04 volumio volumio[172086]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Apr 12 15:17:04 volumio volumio[172086]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored.
Apr 12 15:17:04 volumio volumio[172086]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored.
Apr 12 15:17:04 volumio volumio[172086]: Updating browse sources language
Apr 12 15:17:04 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 12 15:17:04 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 12 15:17:04 volumio volumio[172086]: info: CoreCommandRouter::initPlayerControls
Apr 12 15:17:04 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:04 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:04 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:04 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:04 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:04 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:04 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:04 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:04 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 12 15:17:04 volumio volumio[172086]: Express server listening on port 3000
Apr 12 15:17:04 volumio volumio[172086]: [Metrics] WebUI: 13s 816.27ms
Apr 12 15:17:04 volumio volumio[172086]: info: Setting Device type: x86
Apr 12 15:17:04 volumio volumio[172086]: info: CoreStateMachine::resetVolumioState
Apr 12 15:17:04 volumio volumio[172086]: info: CoreStateMachine::getcurrentVolume
Apr 12 15:17:04 volumio volumio[172086]: info: CoreCommandRouter::volumioRetrievevolume
Apr 12 15:17:04 volumio volumio[172086]: info: CoreStateMachine::pushState
Apr 12 15:17:04 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:17:04 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 12 15:17:04 volumio volumio[172086]: info: CoreCommandRouter::volumioPushState
Apr 12 15:17:04 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 15:17:04 volumio volumio[172086]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt'
Apr 12 15:17:04 volumio volumio[172086]: info: Completed loading Core Plugins
Apr 12 15:17:04 volumio volumio[172086]: info: Preparing to generate the ALSA configuration file
Apr 12 15:17:04 volumio volumio[172086]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf
Apr 12 15:17:04 volumio volumio[172086]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Apr 12 15:17:04 volumio volumio[172086]: info: The plugin stylish_player has an ALSA contribution file sp_in.sp_out.7.conf
Apr 12 15:17:04 volumio volumio[172086]: info: Reading ALSA contributions from plugins.
Apr 12 15:17:04 volumio volumio[172086]: info: Volumio Network Manager: Network status updated: 1
Apr 12 15:17:04 volumio volumio[172086]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision
Apr 12 15:17:05 volumio volumio[172086]: 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 15:17:05 volumio volumio[172086]: info: Cannot read play queue from file
Apr 12 15:17:05 volumio volumio[172086]: info: CoreStateMachine::setRepeat null single undefined
Apr 12 15:17:05 volumio volumio[172086]: info: CoreStateMachine::pushState
Apr 12 15:17:05 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:17:05 volumio volumio[172086]: info: CoreCommandRouter::volumioPushState
Apr 12 15:17:05 volumio volumio[172086]: info: CoreStateMachine::setRandom null
Apr 12 15:17:05 volumio volumio[172086]: info: CoreStateMachine::pushState
Apr 12 15:17:05 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:17:05 volumio volumio[172086]: info: CoreCommandRouter::volumioPushState
Apr 12 15:17:05 volumio volumio[172086]: 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 15:17:05 volumio volumio[172086]: 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 15:17:05 volumio volumio[172086]: 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 15:17:05 volumio volumio[172086]: info: Asound.conf file unchanged, so no further update is needed
Apr 12 15:17:05 volumio volumio[172086]: info: Output device has changed, restarting MPD
Apr 12 15:17:05 volumio volumio[172086]: info: Output device has changed, restarting Shairport Sync
Apr 12 15:17:05 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:05 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 15:17:05 volumio sudo[172258]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 12 15:17:05 volumio sudo[172258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:05 volumio sudo[172258]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:05 volumio volumio[172086]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 12 15:17:05 volumio volumio[172086]: info: ___________ START PLUGINS ___________
Apr 12 15:17:05 volumio sudo[172260]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 12 15:17:05 volumio sudo[172260]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:05 volumio volumio[172086]: info: ControllerMpd::onStart: Initializing MPD
Apr 12 15:17:05 volumio volumio[172086]: info: Creating MPD Configuration file
Apr 12 15:17:05 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 12 15:17:05 volumio sudo[172268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service
Apr 12 15:17:05 volumio sudo[172268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:05 volumio volumio[172086]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 12 15:17:05 volumio volumio[172086]: info: [1776007025519] CoreMusicLibrary::Adding element Media Servers
Apr 12 15:17:05 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 12 15:17:05 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Apr 12 15:17:05 volumio volumio[172086]: info: UPNP Browser: Client initialized successfully
Apr 12 15:17:05 volumio sudo[172270]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 12 15:17:05 volumio sudo[172270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:05 volumio sudo[172273]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 12 15:17:05 volumio sudo[172273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:05 volumio sudo[172270]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:05 volumio sudo[172268]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:05 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:05 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 15:17:05 volumio systemd[1]: mpd.service: Deactivated successfully.
Apr 12 15:17:05 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Apr 12 15:17:05 volumio systemd[1]: mpd.service: Consumed 3.613s CPU time.
Apr 12 15:17:05 volumio systemd[1]: mpd.socket: Deactivated successfully.
Apr 12 15:17:05 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Apr 12 15:17:05 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Apr 12 15:17:05 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Apr 12 15:17:05 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Apr 12 15:17:05 volumio volumio[172086]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 12 15:17:05 volumio volumio5-onboarding[2284]: time=2026-04-12T15:17:05.864Z 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 15:17:05 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:05 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 15:17:05 volumio systemd[1]: mpd.service: Deactivated successfully.
Apr 12 15:17:05 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Apr 12 15:17:05 volumio systemd[1]: mpd.socket: Deactivated successfully.
Apr 12 15:17:05 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Apr 12 15:17:05 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Apr 12 15:17:05 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Apr 12 15:17:05 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Apr 12 15:17:05 volumio volumio[172086]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 12 15:17:05 volumio volumio[172086]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 12 15:17:05 volumio volumio[172086]: info: [1776007025976] CoreMusicLibrary::Adding element Last_100
Apr 12 15:17:05 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 12 15:17:05 volumio volumio[172086]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 12 15:17:05 volumio volumio[172086]: info: [1776007025998] CoreMusicLibrary::Adding element Webradio
Apr 12 15:17:06 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 12 15:17:06 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 12 15:17:06 volumio volumio[172086]: info: Initializing BBC Radios
Apr 12 15:17:06 volumio sudo[172287]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Apr 12 15:17:06 volumio sudo[172287]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 12 15:17:06 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 12 15:17:06 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 15:17:06 volumio sudo[172287]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:06 volumio volumio[172086]: info: Creating Spotify config file
Apr 12 15:17:06 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:06 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Apr 12 15:17:06 volumio volumio[172086]: /usr/bin/mkfifo: cannot create fifo '/tmp/stream.mp3': File exists
Apr 12 15:17:06 volumio volumio[172086]: error: ----failed to create fifo :Error: Command failed: /usr/bin/mkfifo -m 646 /tmp/stream.mp3
Apr 12 15:17:06 volumio volumio[172086]: /usr/bin/mkfifo: cannot create fifo '/tmp/stream.mp3': File exists
Apr 12 15:17:06 volumio volumio[172086]: info: Stylish Player: Found process ID
Apr 12 15:17:06 volumio volumio[172086]: info: Stylish Player: Starting audio server on port 9993
Apr 12 15:17:06 volumio volumio[172086]: info: FusionDsp - CamillaDSP binary found.
Apr 12 15:17:06 volumio volumio[172086]: info: Loading i18n strings for locale en
Apr 12 15:17:06 volumio volumio-remote-updater[723]: [2026-04-12 15:17:06] [connect] Successful connection
Apr 12 15:17:06 volumio volumio[172086]: info: Plugin peppyspectrum has duplicated i18n key APPLY. It is ignored.
Apr 12 15:17:06 volumio volumio[172086]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored.
Apr 12 15:17:06 volumio volumio[172086]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored.
Apr 12 15:17:06 volumio volumio[172086]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored.
Apr 12 15:17:06 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Apr 12 15:17:06 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:06 volumio volumio[172086]: info: FusionDsp - mixtype--------------------- None
Apr 12 15:17:06 volumio volumio[172086]: info: Display-configuration --- loadI18nStrings: loading from /data/plugins/user_interface/display_configuration/i18n/strings_en.json
Apr 12 15:17:06 volumio volumio[172086]: info: Display-configuration --- loadI18nStrings: loaded 52 keys
Apr 12 15:17:07 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Apr 12 15:17:07 volumio volumio[172086]: info: Volumio Calling Home
Apr 12 15:17:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 714.
Apr 12 15:17:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:07 volumio sudo[172314]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/bash -c 'if [ -f /root/.Xauthority ]; then cp /root/.Xauthority /home/volumio/ && chown volumio:volumio /home/volumio/.Xauthority; fi'
Apr 12 15:17:07 volumio sudo[172314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:07 volumio go-librespot[172318]: go-librespot daemon starting...
Apr 12 15:17:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:07 volumio go-librespot[172321]: time="2026-04-12T15:17:07Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:07 volumio sudo[172316]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd-aloop index=7 pcm_substreams=1
Apr 12 15:17:07 volumio sudo[172316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:07 volumio sudo[172314]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:07 volumio sudo[172316]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:07 volumio volumio[172086]: info: Preparing to generate the ALSA configuration file
Apr 12 15:17:07 volumio volumio[172086]: info: Stylish Player: Resilient Audio Streamer on port 9993
Apr 12 15:17:07 volumio volumio[172086]: info: Stylish Player: FIFO sentinel opened
Apr 12 15:17:07 volumio volumio[172086]: info: Stylish Player: No stream clients — draining FIFO to keep ALSA unblocked
Apr 12 15:17:07 volumio volumio[172086]: info: Stylish Player: Server listening on port 3339
Apr 12 15:17:07 volumio go-librespot[172321]: time="2026-04-12T15:17:07Z" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": tls: failed to verify certificate: x509: certificate is not valid for any names, but wanted to match apresolve.spotify.com"
Apr 12 15:17:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:07 volumio sudo[172333]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 12 15:17:07 volumio sudo[172333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:07 volumio sudo[172336]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 12 15:17:07 volumio sudo[172336]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:07 volumio sudo[172333]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:07 volumio sudo[172336]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:08 volumio volumio[172086]: info: Discovery: adding e675fc64-9db0-44b9-b089-c4553e5b48e6
Apr 12 15:17:08 volumio volumio[172086]: info: Discovery: Found device Volumio
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::volumioGetState
Apr 12 15:17:08 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:17:08 volumio volumio[172086]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf
Apr 12 15:17:08 volumio volumio[172086]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Apr 12 15:17:08 volumio volumio[172086]: info: The plugin stylish_player has an ALSA contribution file sp_in.sp_out.7.conf
Apr 12 15:17:08 volumio volumio[172086]: info: Reading ALSA contributions from plugins.
Apr 12 15:17:08 volumio volumio[172086]: info: Discovery: this is already registered, e675fc64-9db0-44b9-b089-c4553e5b48e6
Apr 12 15:17:08 volumio volumio[172086]: info: Discovery: Found device Volumio
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::volumioGetState
Apr 12 15:17:08 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:17:08 volumio volumio[172086]: info: snd_dummy loaded
Apr 12 15:17:08 volumio volumio[172086]: info: Display-configuration --- fixXauthority: /home/volumio/.Xauthority updated
Apr 12 15:17:08 volumio volumio[172086]: info: MPD Permissions set
Apr 12 15:17:08 volumio volumio[172086]: info: MPD Permissions set
Apr 12 15:17:08 volumio volumio-remote-updater[723]: [2026-04-12 15:17:08] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776007026 101
Apr 12 15:17:08 volumio volumio[172086]: 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: 3
Apr 12 15:17:08 volumio volumio[172086]: info: Display-configuration --- X server ready after 1 attempt(s)
Apr 12 15:17:08 volumio volumio[172086]: info: Volumio called home
Apr 12 15:17:08 volumio volumio[172086]: info: Spotify config file written
Apr 12 15:17:08 volumio volumio[172086]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4
Apr 12 15:17:08 volumio sudo[172348]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Apr 12 15:17:08 volumio sudo[172348]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
Apr 12 15:17:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:08 volumio go-librespot[172355]: go-librespot daemon starting...
Apr 12 15:17:08 volumio sudo[172348]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio go-librespot[172358]: time="2026-04-12T15:17:08Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:08 volumio go-librespot[172358]: time="2026-04-12T15:17:08Z" level=debug msg="app state loaded"
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio go-librespot[172358]: time="2026-04-12T15:17:08Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
Apr 12 15:17:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:08 volumio volumio[172086]: info: No need to fix Spotify hosts
Apr 12 15:17:08 volumio volumio[172086]: info: An error occurred while refreshing Spotify Token Error: self-signed certificate
Apr 12 15:17:09 volumio volumio[172086]: 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 15:17:09 volumio volumio[172086]: info: Display-configuration --- Monitoring lid(s): /proc/acpi/button/lid/LID/state
Apr 12 15:17:09 volumio go-librespot[172358]: time="2026-04-12T15:17: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 15:17:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:09 volumio volumio[172086]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists
Apr 12 15:17:09 volumio volumio[172086]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo
Apr 12 15:17:09 volumio volumio[172086]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists
Apr 12 15:17:09 volumio volumio[172086]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Apr 12 15:17:09 volumio volumio[172086]: info: camilladsp service started and running in background, instance 1
Apr 12 15:17:09 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:09 volumio volumio[172086]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 384000 768000 <-AAAAAAAAAAAAA
Apr 12 15:17:09 volumio volumio[172086]: info: FusionDsp loaded
Apr 12 15:17:09 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 12 15:17:09 volumio volumio[172086]: info: FusionDsp - --[object Object]
Apr 12 15:17:09 volumio volumio[172086]: error: FusionDsp - Socket connection not established
Apr 12 15:17:09 volumio volumio[172086]: info: FusionDsp - Reporting Fusion DSP Enabled
Apr 12 15:17:09 volumio volumio[172086]: info: Adding Signal Path Element [object Object]
Apr 12 15:17:09 volumio volumio[172086]: info: Adding fusiondspeq DSP Signal Path Element
Apr 12 15:17:09 volumio volumio[172086]: info: FusionDsp - ---- installed callbackRead (debounced 200ms)
Apr 12 15:17:09 volumio volumio[172086]: info: FusionDsp - PEQ graph server listening on port 10015
Apr 12 15:17:09 volumio sudo[172396]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service
Apr 12 15:17:09 volumio sudo[172396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:10 volumio sudo[172396]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:10 volumio volumio[172086]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6
Apr 12 15:17:10 volumio volumio[172086]: info: Display-configuration --- xscreensaver cleaned up before starting
Apr 12 15:17:10 volumio volumio[172086]: error: FusionDsp - Reload WebSocket error: [object Object]
Apr 12 15:17:10 volumio volumio[172086]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7
Apr 12 15:17:10 volumio volumio[172086]: info: Display-configuration --- DPMS disabled before playback state check
Apr 12 15:17:10 volumio volumio[172086]: info: Starting Shairport Sync
Apr 12 15:17:10 volumio volumio[172086]: info: Starting Shairport Sync
Apr 12 15:17:10 volumio volumio[172086]: info: Starting Shairport Sync
Apr 12 15:17:10 volumio mpd[172302]: 2026-04-12T15:17:10 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Apr 12 15:17:10 volumio sudo[172399]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 12 15:17:10 volumio sudo[172399]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:10 volumio sudo[172401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 12 15:17:10 volumio sudo[172401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:10 volumio sudo[172403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 12 15:17:10 volumio sudo[172403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:10 volumio sudo[172407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Apr 12 15:17:10 volumio sudo[172407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:10 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 12 15:17:10 volumio sudo[172401]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:10 volumio sudo[172399]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:10 volumio volumio[172086]: info: Display-configuration --- Connected screens: LVDS, HDMI-0
Apr 12 15:17:10 volumio volumio[172086]: info: Display-configuration --- Lid closed - turning screen off via DPMS
Apr 12 15:17:10 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Apr 12 15:17:10 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Apr 12 15:17:10 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 12 15:17:10 volumio sudo[172407]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:10 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 12 15:17:10 volumio sudo[172403]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:10 volumio volumio[172086]: info: Upmpdcli Daemon Started
Apr 12 15:17:10 volumio volumio[172086]: info: Shairport-Sync Started
Apr 12 15:17:10 volumio volumio[172086]: Error adding Membership: Error: addMembership EINVAL
Apr 12 15:17:11 volumio volumio[172086]: info: Shairport-Sync Started
Apr 12 15:17:11 volumio volumio[172086]: info: Shairport-Sync Started
Apr 12 15:17:11 volumio volumio[172086]: info: Asound.conf file unchanged, so no further update is needed
Apr 12 15:17:11 volumio volumio[172086]: info: Output device has changed, restarting MPD
Apr 12 15:17:11 volumio volumio[172086]: info: Output device has changed, restarting Shairport Sync
Apr 12 15:17:11 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:11 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 15:17:11 volumio sudo[172433]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 12 15:17:11 volumio sudo[172433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:11 volumio sudo[172435]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 12 15:17:11 volumio sudo[172435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:11 volumio sudo[172433]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:11 volumio volumio[172086]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 12 15:17:11 volumio volumio[172086]: info: Preparing to generate the ALSA configuration file
Apr 12 15:17:11 volumio systemd[1]: mpd.service: Deactivated successfully.
Apr 12 15:17:11 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Apr 12 15:17:11 volumio systemd[1]: mpd.service: Consumed 3.410s CPU time.
Apr 12 15:17:11 volumio systemd[1]: mpd.socket: Deactivated successfully.
Apr 12 15:17:11 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Apr 12 15:17:11 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Apr 12 15:17:11 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Apr 12 15:17:11 volumio volumio[172086]: info: Display-configuration --- No forced DRM orientation detected for LVDS
Apr 12 15:17:11 volumio volumio[172086]: info: Display-configuration --- TTY: display=normal(0) + offset=same(0) = 0 deg (fbconv=0)
Apr 12 15:17:11 volumio volumio[172086]: info: Display-configuration --- Plymouth: display=normal(0) + offset=same(0) = 0 deg
Apr 12 15:17:11 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Apr 12 15:17:11 volumio volumio[172086]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf
Apr 12 15:17:11 volumio volumio[172086]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Apr 12 15:17:11 volumio volumio[172086]: info: The plugin stylish_player has an ALSA contribution file sp_in.sp_out.7.conf
Apr 12 15:17:11 volumio volumio[172086]: info: Reading ALSA contributions from plugins.
Apr 12 15:17:11 volumio volumio[172086]: error: Upnp client error: Error: read ECONNRESET
Apr 12 15:17:11 volumio volumio[172086]: info: MPD Permissions set
Apr 12 15:17:11 volumio sudo[172444]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Apr 12 15:17:11 volumio sudo[172444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 12 15:17:11 volumio sudo[172444]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:11 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:11 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:11 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:11 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:11 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:11 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:11 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:11 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:12 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 15:17:12 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
Apr 12 15:17:12 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:12 volumio volumio[172086]: info: Display-configuration --- Kiosk browser detected after 1s, re-applying input settings in 3s
Apr 12 15:17:12 volumio volumio[172086]: info: Display-configuration --- Connected screens: LVDS, HDMI-0
Apr 12 15:17:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 715.
Apr 12 15:17:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:12 volumio volumio[172086]: info: Starting Shairport Sync
Apr 12 15:17:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:12 volumio go-librespot[172461]: go-librespot daemon starting...
Apr 12 15:17:12 volumio go-librespot[172464]: time="2026-04-12T15:17:12Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:12 volumio go-librespot[172464]: time="2026-04-12T15:17:12Z" level=debug msg="app state loaded"
Apr 12 15:17:12 volumio volumio[172086]: info: Display-configuration --- Rotation config saved for Grub: screen=LVDS, plymouth=0, fbcon=0
Apr 12 15:17:12 volumio go-librespot[172464]: time="2026-04-12T15:17:12Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:12 volumio sudo[172463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 12 15:17:12 volumio volumio[172086]: info: Display-configuration --- Panel Rotation applied via xrandr
Apr 12 15:17:12 volumio sudo[172463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:12 volumio sudo[172476]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/graphics/fbcon/rotate_all
Apr 12 15:17:12 volumio volumio[172086]: info: Display-configuration --- Runtime rotation applied: normal | Boot config (plymouth=0, fbconv=0)
Apr 12 15:17:12 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Apr 12 15:17:12 volumio sudo[172476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:12 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Apr 12 15:17:12 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 12 15:17:12 volumio volumio[172086]: info: Asound.conf file unchanged, so no further update is needed
Apr 12 15:17:12 volumio volumio[172086]: info: Output device has changed, restarting MPD
Apr 12 15:17:12 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 12 15:17:12 volumio sudo[172476]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:12 volumio sudo[172463]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:12 volumio volumio[172086]: info: Output device has changed, restarting Shairport Sync
Apr 12 15:17:12 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:12 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 15:17:13 volumio sudo[172482]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 12 15:17:13 volumio sudo[172482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:13 volumio go-librespot[172464]: time="2026-04-12T15:17:13Z" 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 15:17:13 volumio sudo[172482]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:13 volumio volumio[172086]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 12 15:17:13 volumio sudo[172486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 12 15:17:13 volumio volumio[172086]: info: Preparing to generate the ALSA configuration file
Apr 12 15:17:13 volumio sudo[172486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:13 volumio volumio[172086]: info: CoreCommandRouter::volumioGetState
Apr 12 15:17:13 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:17:13 volumio volumio[172086]: info: go-librespot daemon successfully initialized
Apr 12 15:17:13 volumio systemd[1]: mpd.service: Deactivated successfully.
Apr 12 15:17:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Apr 12 15:17:13 volumio systemd[1]: mpd.socket: Deactivated successfully.
Apr 12 15:17:13 volumio volumio[172086]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf
Apr 12 15:17:13 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Apr 12 15:17:13 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Apr 12 15:17:13 volumio volumio[172086]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf
Apr 12 15:17:13 volumio volumio[172086]: info: The plugin stylish_player has an ALSA contribution file sp_in.sp_out.7.conf
Apr 12 15:17:13 volumio volumio[172086]: info: Reading ALSA contributions from plugins.
Apr 12 15:17:13 volumio volumio[172086]: info: MPD Permissions set
Apr 12 15:17:13 volumio volumio[172086]: info: Display-configuration --- Connected screens: LVDS, HDMI-0
Apr 12 15:17:13 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Apr 12 15:17:13 volumio volumio[172086]: info: Shairport-Sync Started
Apr 12 15:17:13 volumio volumio[172086]: info: Display-configuration --- fbcon console rotation set to 0
Apr 12 15:17:13 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Apr 12 15:17:13 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:13 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:13 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:13 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:13 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:13 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:13 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:13 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:13 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 15:17:13 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
Apr 12 15:17:13 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:13 volumio volumio[172086]: info: Display-configuration --- Touch-related devices detected: [{"id":"11","name":"⎜ ↳ ETPS/2 Elantech Touchpad"}]
Apr 12 15:17:13 volumio volumio[172086]: info: Display-configuration --- Touch matrix: display=normal, offset=0, matrix=1 0 0 0 1 0 0 0 1
Apr 12 15:17:13 volumio volumio[172086]: info: Starting Shairport Sync
Apr 12 15:17:13 volumio sudo[172508]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Apr 12 15:17:13 volumio sudo[172508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 12 15:17:13 volumio sudo[172508]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:13 volumio volumio[172086]: info: Asound.conf file unchanged, so no further update is needed
Apr 12 15:17:13 volumio volumio[172086]: info: Output device has changed, restarting MPD
Apr 12 15:17:14 volumio volumio[172086]: info: Output device has changed, restarting Shairport Sync
Apr 12 15:17:14 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:14 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 15:17:14 volumio sudo[172523]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 12 15:17:14 volumio sudo[172526]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 12 15:17:14 volumio sudo[172523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:14 volumio sudo[172526]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:14 volumio sudo[172526]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:14 volumio volumio[172086]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 12 15:17:14 volumio sudo[172529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 12 15:17:14 volumio sudo[172529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Apr 12 15:17:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Apr 12 15:17:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 12 15:17:14 volumio volumio[172086]: info: MPD Permissions set
Apr 12 15:17:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 12 15:17:14 volumio sudo[172523]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:14 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:14 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:14 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:14 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:14 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:14 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:14 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:14 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:14 volumio systemd[1]: mpd.service: Deactivated successfully.
Apr 12 15:17:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Apr 12 15:17:14 volumio systemd[1]: mpd.socket: Deactivated successfully.
Apr 12 15:17:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Apr 12 15:17:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Apr 12 15:17:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Apr 12 15:17:14 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 15:17:14 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
Apr 12 15:17:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Apr 12 15:17:14 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:14 volumio volumio[172086]: info: Shairport-Sync Started
Apr 12 15:17:14 volumio volumio[172086]: info: Starting Shairport Sync
Apr 12 15:17:15 volumio sudo[172562]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Apr 12 15:17:15 volumio sudo[172562]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 12 15:17:15 volumio sudo[172562]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:15 volumio sudo[172582]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 12 15:17:15 volumio sudo[172582]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:15 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Apr 12 15:17:15 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Apr 12 15:17:15 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 12 15:17:15 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Apr 12 15:17:15 volumio sudo[172582]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:15 volumio volumio[172086]: info: Shairport-Sync Started
Apr 12 15:17:15 volumio volumio[172086]: info: Display-configuration --- Connected screens: LVDS, HDMI-0
Apr 12 15:17:15 volumio volumio[172086]: info: Display-configuration --- Touch correction applied to ⎜ ↳ ETPS/2 Elantech Touchpad (id=11)
Apr 12 15:17:15 volumio volumio[172086]: info: Display-configuration --- applyPointerCorrection: pointer_offset=0
Apr 12 15:17:15 volumio volumio[172086]: info: Display-configuration --- Pointer correction: none (xrandr handles relative devices)
Apr 12 15:17:15 volumio volumio[172086]: info: Display-configuration --- Touch-related devices detected: [{"id":"11","name":"⎜ ↳ ETPS/2 Elantech Touchpad"}]
Apr 12 15:17:15 volumio volumio[172086]: info: Display-configuration --- Touch matrix: display=normal, offset=0, matrix=1 0 0 0 1 0 0 0 1
Apr 12 15:17:16 volumio sudo[172616]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/tee /sys/class/backlight/radeon_bl0/brightness
Apr 12 15:17:16 volumio sudo[172616]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:16 volumio sudo[172616]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 716.
Apr 12 15:17:16 volumio sudo[172611]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/pkill -9 -f unclutter
Apr 12 15:17:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:16 volumio volumio[172086]: info: Display-configuration --- Brightness set to 100% (255/255) on radeon_bl0
Apr 12 15:17:16 volumio sudo[172611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:16 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:17:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:16 volumio go-librespot[172621]: go-librespot daemon starting...
Apr 12 15:17:16 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 12 15:17:16 volumio go-librespot[172624]: time="2026-04-12T15:17:16Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:16 volumio go-librespot[172624]: time="2026-04-12T15:17:16Z" level=debug msg="app state loaded"
Apr 12 15:17:16 volumio go-librespot[172624]: time="2026-04-12T15:17:16Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:16 volumio volumio[172086]: info: Display-configuration --- No unclutter process to stop
Apr 12 15:17:16 volumio volumio[172086]: info: Display-configuration --- unclutter stopped
Apr 12 15:17:17 volumio go-librespot[172624]: time="2026-04-12T15:17: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\": tls: failed to verify certificate: x509: certificate is not valid for any names, but wanted to match apresolve.spotify.com"
Apr 12 15:17:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:17 volumio volumio[172086]: info: Display-configuration --- Touch correction applied to ⎜ ↳ ETPS/2 Elantech Touchpad (id=11)
Apr 12 15:17:17 volumio volumio[172086]: info: Display-configuration --- applyPointerCorrection: pointer_offset=0
Apr 12 15:17:17 volumio volumio[172086]: info: Display-configuration --- Pointer correction: none (xrandr handles relative devices)
Apr 12 15:17:17 volumio volumio[172086]: info: Display-configuration --- Input settings re-applied after kiosk start
Apr 12 15:17:18 volumio mpd[172585]: 2026-04-12T15:17:18 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Apr 12 15:17:19 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Apr 12 15:17:19 volumio sudo[172486]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:19 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:17:19 volumio sudo[172529]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:19 volumio sudo[172435]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:19 volumio sudo[172260]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:19 volumio sudo[172273]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:19 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 12 15:17:19 volumio volumio[172086]: info: Completed starting Core Plugins
Apr 12 15:17:19 volumio volumio[172086]: info: -------------------------------------------
Apr 12 15:17:19 volumio volumio[172086]: info: ----- MyVolumio plugins startup ----
Apr 12 15:17:19 volumio volumio[172086]: info: -------------------------------------------
Apr 12 15:17:19 volumio volumio[172086]: info: [MyVolumio PluginManager] Fetching plans data....
Apr 12 15:17:19 volumio volumio[172086]: error: MPD error: The expression evaluated to a falsy value:
Apr 12 15:17:19 volumio volumio[172086]: assert.ok(self.idling)
Apr 12 15:17:19 volumio volumio[172086]: error: The expression evaluated to a falsy value:
Apr 12 15:17:19 volumio volumio[172086]: assert.ok(self.idling)
Apr 12 15:17:19 volumio volumio[172086]: info: MPD running with PID172585
Apr 12 15:17:19 volumio volumio[172086]: ,establishing connection
Apr 12 15:17:19 volumio volumio[172086]: error: MPD error: The expression evaluated to a falsy value:
Apr 12 15:17:19 volumio volumio[172086]: assert.ok(self.idling)
Apr 12 15:17:19 volumio volumio[172086]: error: The expression evaluated to a falsy value:
Apr 12 15:17:19 volumio volumio[172086]: assert.ok(self.idling)
Apr 12 15:17:19 volumio volumio[172086]: error: MPD error: The expression evaluated to a falsy value:
Apr 12 15:17:19 volumio volumio[172086]: assert.ok(self.idling)
Apr 12 15:17:19 volumio volumio[172086]: error: The expression evaluated to a falsy value:
Apr 12 15:17:19 volumio volumio[172086]: assert.ok(self.idling)
Apr 12 15:17:19 volumio volumio[172086]: error: MPD error: The expression evaluated to a falsy value:
Apr 12 15:17:19 volumio volumio[172086]: assert.ok(self.idling)
Apr 12 15:17:19 volumio volumio[172086]: error: The expression evaluated to a falsy value:
Apr 12 15:17:19 volumio volumio[172086]: assert.ok(self.idling)
Apr 12 15:17:19 volumio volumio[172086]: error: MPD error: The expression evaluated to a falsy value:
Apr 12 15:17:19 volumio volumio[172086]: assert.ok(self.idling)
Apr 12 15:17:19 volumio volumio[172086]: error: The expression evaluated to a falsy value:
Apr 12 15:17:19 volumio volumio[172086]: assert.ok(self.idling)
Apr 12 15:17:19 volumio volumio[172086]: error: updateQueue error: null
Apr 12 15:17:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 717.
Apr 12 15:17:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:20 volumio go-librespot[172642]: go-librespot daemon starting...
Apr 12 15:17:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:20 volumio go-librespot[172643]: time="2026-04-12T15:17:20Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:20 volumio go-librespot[172643]: time="2026-04-12T15:17:20Z" level=debug msg="app state loaded"
Apr 12 15:17:20 volumio go-librespot[172643]: time="2026-04-12T15:17:20Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:20 volumio go-librespot[172643]: time="2026-04-12T15:17: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\": tls: failed to verify certificate: x509: certificate is not valid for any names, but wanted to match apresolve.spotify.com"
Apr 12 15:17:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:22 volumio kernel: r8169 0000:01:00.0 eth0: Link is Down
Apr 12 15:17:22 volumio dhcpcd[842]: eth0: carrier lost
Apr 12 15:17:22 volumio dhcpcd[715]: eth0: carrier lost
Apr 12 15:17:22 volumio avahi-daemon[699]: Withdrawing address record for 192.168.1.3 on eth0.
Apr 12 15:17:22 volumio avahi-daemon[699]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.1.3.
Apr 12 15:17:22 volumio avahi-daemon[699]: Interface eth0.IPv4 no longer relevant for mDNS.
Apr 12 15:17:22 volumio dhcpcd[715]: eth0: deleting route to 192.168.1.0/24
Apr 12 15:17:22 volumio dhcpcd[715]: eth0: deleting default route via 192.168.1.1
Apr 12 15:17:22 volumio volumio[172086]: info: Discovery: A device disappeared from network
Apr 12 15:17:22 volumio dhcpcd[842]: eth0: deleting route to 192.168.1.0/24
Apr 12 15:17:22 volumio dhcpcd[842]: eth0: deleting default route via 192.168.1.1
Apr 12 15:17:22 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Apr 12 15:17:22 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Apr 12 15:17:22 volumio systemd[1]: welcome.service: Deactivated successfully.
Apr 12 15:17:22 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console.
Apr 12 15:17:22 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console...
Apr 12 15:17:22 volumio systemd[1]: Starting welcome.service - Show a welcome message on console...
Apr 12 15:17:22 volumio welcome[172704]: Resolved ip:[0]
Apr 12 15:17:22 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:17:22 volumio systemd[1]: Finished welcome.service - Show a welcome message on console.
Apr 12 15:17:22 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Apr 12 15:17:22 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: AggregateError
Apr 12 15:17:22 volumio ifplugd(eth0)[916]: Link beat lost.
Apr 12 15:17:22 volumio volumio[172086]: info: Received Get System Info
Apr 12 15:17:22 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 12 15:17:22 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 12 15:17:22 volumio volumio[172086]: info: Discovery: Getting this device information
Apr 12 15:17:22 volumio volumio[172086]: info: CoreCommandRouter::volumioGetState
Apr 12 15:17:22 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:17:22 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 12 15:17:22 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 12 15:17:22 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 12 15:17:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 718.
Apr 12 15:17:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:23 volumio go-librespot[172716]: go-librespot daemon starting...
Apr 12 15:17:23 volumio volumio5-onboarding[2284]: time=2026-04-12T15:17:23.904Z level=INFO msg="service successfully established" component=discovery/localnet
Apr 12 15:17:23 volumio go-librespot[172717]: time="2026-04-12T15:17:23Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:23 volumio go-librespot[172717]: time="2026-04-12T15:17:23Z" level=debug msg="app state loaded"
Apr 12 15:17:23 volumio go-librespot[172717]: time="2026-04-12T15:17:23Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:23 volumio go-librespot[172717]: time="2026-04-12T15:17:23Z" 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 15:17:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:24 volumio ntpd[902]: IO: Deleting interface #4 eth0, 192.168.1.3#123, interface stats: received=19, sent=20, dropped=0, active_time=2744 secs
Apr 12 15:17:24 volumio ntpd[902]: PROTO: 140.186.0.227 unlink local addr 192.168.1.3 ->
Apr 12 15:17:24 volumio ntpd[902]: PROTO: 208.113.130.146 unlink local addr 192.168.1.3 ->
Apr 12 15:17:24 volumio ntpd[902]: PROTO: 50.117.3.95 unlink local addr 192.168.1.3 ->
Apr 12 15:17:24 volumio ntpd[902]: PROTO: 155.248.196.28 unlink local addr 192.168.1.3 ->
Apr 12 15:17:24 volumio ntpd[902]: PROTO: 162.159.200.1 unlink local addr 192.168.1.3 ->
Apr 12 15:17:24 volumio ntpd[902]: PROTO: 50.205.57.38 unlink local addr 192.168.1.3 ->
Apr 12 15:17:24 volumio ntpd[902]: PROTO: 192.227.170.78 unlink local addr 192.168.1.3 ->
Apr 12 15:17:25 volumio volumio[172086]: info: Volumio Network Manager: Network status updated: 0
Apr 12 15:17:25 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:17:25 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: AggregateError
Apr 12 15:17:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 719.
Apr 12 15:17:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:27 volumio go-librespot[172741]: go-librespot daemon starting...
Apr 12 15:17:27 volumio go-librespot[172742]: time="2026-04-12T15:17:27Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:27 volumio go-librespot[172742]: time="2026-04-12T15:17:27Z" level=debug msg="app state loaded"
Apr 12 15:17:27 volumio go-librespot[172742]: time="2026-04-12T15:17:27Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:27 volumio go-librespot[172742]: time="2026-04-12T15:17:27Z" 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 15:17:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:29 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:17:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 720.
Apr 12 15:17:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:30 volumio go-librespot[172752]: go-librespot daemon starting...
Apr 12 15:17:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:30 volumio go-librespot[172753]: time="2026-04-12T15:17:30Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:30 volumio go-librespot[172753]: time="2026-04-12T15:17:30Z" level=debug msg="app state loaded"
Apr 12 15:17:30 volumio go-librespot[172753]: time="2026-04-12T15:17:30Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:30 volumio go-librespot[172753]: time="2026-04-12T15:17:30Z" 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 15:17:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:31 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: AggregateError
Apr 12 15:17:33 volumio ifplugd(eth0)[916]: Executing '/etc/ifplugd/ifplugd.action eth0 down'.
Apr 12 15:17:33 volumio kernel: r8169 0000:01:00.0 eth0: Link is Up - 100Mbps/Full - flow control rx/tx
Apr 12 15:17:33 volumio dhcpcd[842]: eth0: carrier acquired
Apr 12 15:17:33 volumio dhcpcd[715]: eth0: carrier acquired
Apr 12 15:17:33 volumio dhcpcd[842]: eth0: IAID 01:a2:8c:17
Apr 12 15:17:33 volumio dhcpcd[715]: eth0: IAID 01:a2:8c:17
Apr 12 15:17:33 volumio ifplugd(eth0)[916]: client: sending signal ALRM to pid 714
Apr 12 15:17:33 volumio dhcpcd[172775]: sending signal ALRM to pid 714
Apr 12 15:17:33 volumio dhcpcd[172775]: waiting for pid 714 to exit
Apr 12 15:17:33 volumio ifplugd(eth0)[916]: client: waiting for pid 714 to exit
Apr 12 15:17:33 volumio dhcpcd[715]: received SIGALRM, releasing
Apr 12 15:17:33 volumio dhcpcd[715]: eth0: removing interface
Apr 12 15:17:33 volumio kernel: r8169 0000:01:00.0 eth0: Link is Down
Apr 12 15:17:33 volumio dhcpcd[842]: eth0: carrier lost
Apr 12 15:17:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 721.
Apr 12 15:17:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:33 volumio go-librespot[172803]: go-librespot daemon starting...
Apr 12 15:17:33 volumio ifplugd(eth0)[916]: Program executed successfully.
Apr 12 15:17:33 volumio kernel: RTL8208 Fast Ethernet r8169-0-100:00: attached PHY driver (mii_bus:phy_addr=r8169-0-100:00, irq=MAC)
Apr 12 15:17:33 volumio go-librespot[172804]: time="2026-04-12T15:17:33Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:33 volumio go-librespot[172804]: time="2026-04-12T15:17:33Z" level=debug msg="app state loaded"
Apr 12 15:17:33 volumio dhcpcd[842]: eth0: carrier acquired
Apr 12 15:17:33 volumio kernel: r8169 0000:01:00.0 eth0: Link is Down
Apr 12 15:17:33 volumio dhcpcd[842]: eth0: IAID 01:a2:8c:17
Apr 12 15:17:34 volumio dhcpcd[842]: eth0: carrier lost
Apr 12 15:17:34 volumio go-librespot[172804]: time="2026-04-12T15:17:34Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:34 volumio go-librespot[172804]: time="2026-04-12T15:17:34Z" 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 15:17:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:34 volumio wireless.js[724]: WIRELESS.JS - INFO: === SNM TRANSITION ===
Apr 12 15:17:34 volumio wireless.js[724]: WIRELESS.JS - INFO: Previous ethernet state: connected
Apr 12 15:17:34 volumio wireless.js[724]: WIRELESS.JS - INFO: New ethernet state: disconnected
Apr 12 15:17:34 volumio wireless.js[724]: WIRELESS.JS - INFO: Single Network Mode: enabled
Apr 12 15:17:34 volumio wireless.js[724]: WIRELESS.JS - INFO: First start: no
Apr 12 15:17:34 volumio wireless.js[724]: WIRELESS.JS - INFO: Action: Reconnect WiFi
Apr 12 15:17:34 volumio wireless.js[724]: WIRELESS.JS - INFO: === END TRANSITION ===
Apr 12 15:17:34 volumio sudo[172824]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
Apr 12 15:17:34 volumio sudo[172824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:34 volumio sudo[172824]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:34 volumio wireless.js[724]: WIRELESS.JS - INFO: SNM: Ethernet disconnected, reconnecting WiFi
Apr 12 15:17:34 volumio wireless.js[724]: WIRELESS.JS - INFO: SNM: Ethernet disconnected, reconnecting WiFi
Apr 12 15:17:34 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:17:35 volumio wireless.js[724]: WIRELESS.JS - INFO: reconnectWiFi: Reconnect command failed: Error: Command failed: /sbin/wpa_cli -i wlan0 reconnect
Apr 12 15:17:35 volumio wireless.js[724]: Failed to connect to non-global ctrl_ifname: wlan0 error: No such file or directory
Apr 12 15:17:35 volumio wireless.js[724]: WIRELESS.JS - INFO: reconnectWiFi: Falling back to full wireless flow restart
Apr 12 15:17:35 volumio wireless.js[724]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow
Apr 12 15:17:35 volumio dhcpcd[842]: eth0: carrier acquired
Apr 12 15:17:35 volumio kernel: r8169 0000:01:00.0 eth0: Link is Up - 100Mbps/Full - flow control rx/tx
Apr 12 15:17:35 volumio dhcpcd[842]: eth0: IAID 01:a2:8c:17
Apr 12 15:17:35 volumio wpa_supplicant[1113]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all
Apr 12 15:17:35 volumio wireless.js[724]: WIRELESS.JS - INFO: === SNM TRANSITION ===
Apr 12 15:17:35 volumio wireless.js[724]: WIRELESS.JS - INFO: Previous ethernet state: disconnected
Apr 12 15:17:35 volumio wireless.js[724]: WIRELESS.JS - INFO: New ethernet state: connected
Apr 12 15:17:35 volumio wireless.js[724]: WIRELESS.JS - INFO: Single Network Mode: enabled
Apr 12 15:17:35 volumio wireless.js[724]: WIRELESS.JS - INFO: First start: no
Apr 12 15:17:35 volumio wireless.js[724]: WIRELESS.JS - INFO: Action: Switch to ethernet (WiFi scan mode)
Apr 12 15:17:35 volumio wireless.js[724]: WIRELESS.JS - INFO: === END TRANSITION ===
Apr 12 15:17:35 volumio wireless.js[724]: WIRELESS.JS - INFO: SNM: Ethernet connected, switching to ethernet (WiFi scan mode)
Apr 12 15:17:35 volumio wpa_supplicant[1113]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all
Apr 12 15:17:35 volumio wpa_supplicant[1113]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0
Apr 12 15:17:35 volumio sudo[172857]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd -k wlan0
Apr 12 15:17:35 volumio sudo[172857]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 12 15:17:35 volumio dhcpcd[172858]: dhcpcd not running
Apr 12 15:17:35 volumio sudo[172857]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:35 volumio wireless.js[724]: dhcpcd not running
Apr 12 15:17:35 volumio wireless.js[724]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow
Apr 12 15:17:35 volumio wpa_supplicant[1113]: wlan0: CTRL-EVENT-TERMINATING
Apr 12 15:17:35 volumio ifplugd(eth0)[916]: Link beat detected.
Apr 12 15:17:36 volumio ifplugd(eth0)[916]: Executing '/etc/ifplugd/ifplugd.action eth0 up'.
Apr 12 15:17:36 volumio sudo[172862]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0
Apr 12 15:17:36 volumio sudo[172862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 12 15:17:36 volumio sudo[172862]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:36 volumio sudo[172872]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down
Apr 12 15:17:36 volumio sudo[172872]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 12 15:17:36 volumio sudo[172872]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:36 volumio wireless.js[724]: WIRELESS.JS - INFO: Cleaning previous...
Apr 12 15:17:36 volumio dhcpcd[842]: eth0: rebinding lease of 192.168.1.3
Apr 12 15:17:36 volumio ifplugd(eth0)[916]: client: sending commands to dhcpcd process
Apr 12 15:17:36 volumio dhcpcd[842]: control command: dhcpcd eth0
Apr 12 15:17:36 volumio dhcpcd[842]: control_free: No such file or directory
Apr 12 15:17:36 volumio sudo[172892]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up
Apr 12 15:17:36 volumio sudo[172892]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 12 15:17:36 volumio dhcpcd[842]: eth0: soliciting an IPv6 router
Apr 12 15:17:36 volumio sudo[172892]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:36 volumio wireless.js[724]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations
Apr 12 15:17:36 volumio wireless.js[724]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 2ms
Apr 12 15:17:36 volumio wireless.js[724]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: 2c:d0:5a:f9:4a:00)
Apr 12 15:17:36 volumio sudo[172924]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get
Apr 12 15:17:36 volumio sudo[172924]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:36 volumio sudo[172924]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:37 volumio sudo[172934]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan
Apr 12 15:17:37 volumio sudo[172934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 722.
Apr 12 15:17:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:37 volumio go-librespot[172941]: go-librespot daemon starting...
Apr 12 15:17:37 volumio ifplugd(eth0)[916]: Program executed successfully.
Apr 12 15:17:37 volumio go-librespot[172942]: time="2026-04-12T15:17:37Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:37 volumio go-librespot[172942]: time="2026-04-12T15:17:37Z" level=debug msg="app state loaded"
Apr 12 15:17:37 volumio go-librespot[172942]: time="2026-04-12T15:17:37Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:37 volumio go-librespot[172942]: time="2026-04-12T15:17:37Z" 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 15:17:37 volumio volumio[172086]: info: Received Get System Info
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 12 15:17:37 volumio volumio[172086]: info: Discovery: Getting this device information
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::volumioGetState
Apr 12 15:17:37 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:17:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 12 15:17:37 volumio volumio[172086]: info: Received Get System Info
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 12 15:17:37 volumio volumio[172086]: info: Discovery: Getting this device information
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::volumioGetState
Apr 12 15:17:37 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 12 15:17:37 volumio volumio[172086]: info: Received Get System Info
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 12 15:17:37 volumio volumio[172086]: info: Discovery: Getting this device information
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::volumioGetState
Apr 12 15:17:37 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 12 15:17:37 volumio volumio[172086]: info: Received Get System Info
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 12 15:17:37 volumio volumio[172086]: info: Discovery: Getting this device information
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::volumioGetState
Apr 12 15:17:37 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 15:17:37 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Apr 12 15:17:37 volumio sudo[172934]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:37 volumio wireless.js[724]: WIRELESS.JS - INFO: netconfigured file not found, starting hotspot
Apr 12 15:17:37 volumio wireless.js[724]: WIRELESS.JS - INFO: Single Network Mode: Ethernet active, maintaining WiFi scan capability
Apr 12 15:17:37 volumio wireless.js[724]: WIRELESS.JS - INFO: SNM: Maintaining wlan0 UP without IP (scan mode)
Apr 12 15:17:37 volumio wireless.js[724]: WIRELESS.JS - INFO: SNM: Users can configure WiFi via WebUI while ethernet is active
Apr 12 15:17:38 volumio sudo[172958]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0
Apr 12 15:17:38 volumio sudo[172958]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 12 15:17:38 volumio sudo[172958]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:38 volumio sudo[172962]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down
Apr 12 15:17:38 volumio sudo[172962]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 12 15:17:38 volumio sudo[172962]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:38 volumio wireless.js[724]: WIRELESS.JS - INFO: Cleaning previous...
Apr 12 15:17:38 volumio sudo[172965]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up
Apr 12 15:17:38 volumio sudo[172965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 12 15:17:38 volumio sudo[172965]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:38 volumio sudo[172968]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up
Apr 12 15:17:38 volumio sudo[172968]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 12 15:17:38 volumio sudo[172968]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:38 volumio wireless.js[724]: WIRELESS.JS - INFO: InterfaceValidator: READY - wlan0 is ready for operations
Apr 12 15:17:38 volumio wireless.js[724]: WIRELESS.JS - INFO: InterfaceValidator: wlan0 became ready after 12ms
Apr 12 15:17:38 volumio wireless.js[724]: WIRELESS.JS - INFO: ensureInterfaceReady: Interface ready (MAC: 2c:d0:5a:f9:4a:00)
Apr 12 15:17:38 volumio sudo[172977]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get
Apr 12 15:17:38 volumio sudo[172977]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:38 volumio sudo[172977]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:38 volumio sudo[172985]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan
Apr 12 15:17:38 volumio sudo[172985]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 12 15:17:39 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 12 15:17:39 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 12 15:17:39 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 12 15:17:39 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 12 15:17:39 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 12 15:17:39 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 12 15:17:39 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 12 15:17:39 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 12 15:17:39 volumio volumio[172086]: info: Received Get System Info
Apr 12 15:17:39 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 12 15:17:39 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 12 15:17:39 volumio volumio[172086]: info: Discovery: Getting this device information
Apr 12 15:17:39 volumio volumio[172086]: info: CoreCommandRouter::volumioGetState
Apr 12 15:17:39 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:17:39 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 12 15:17:39 volumio volumio[172086]: info: Received Get System Info
Apr 12 15:17:39 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 12 15:17:39 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 12 15:17:39 volumio volumio[172086]: info: Discovery: Getting this device information
Apr 12 15:17:39 volumio volumio[172086]: info: CoreCommandRouter::volumioGetState
Apr 12 15:17:39 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:17:39 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 12 15:17:39 volumio sudo[172985]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:39 volumio sudo[172991]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0
Apr 12 15:17:39 volumio sudo[172991]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Apr 12 15:17:39 volumio sudo[172991]: pam_unix(sudo:session): session closed for user root
Apr 12 15:17:39 volumio wpa_supplicant[172994]: Successfully initialized wpa_supplicant
Apr 12 15:17:40 volumio wireless.js[724]: WIRELESS.JS - INFO: SNM: Transition to scan mode completed in 4269ms
Apr 12 15:17:40 volumio wireless.js[724]: WIRELESS.JS - INFO: SNM: wlan0 is UP without IP, scan capable
Apr 12 15:17:40 volumio wireless.js[724]: Failed to connect to non-global ctrl_ifname: wlan0 error: No such file or directory
Apr 12 15:17:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 723.
Apr 12 15:17:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:40 volumio go-librespot[173009]: go-librespot daemon starting...
Apr 12 15:17:40 volumio wireless.js[724]: WIRELESS.JS - INFO: Notified systemd about wireless ready
Apr 12 15:17:40 volumio go-librespot[173010]: time="2026-04-12T15:17:40Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:40 volumio go-librespot[173010]: time="2026-04-12T15:17:40Z" level=debug msg="app state loaded"
Apr 12 15:17:40 volumio go-librespot[173010]: time="2026-04-12T15:17:40Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:40 volumio go-librespot[173010]: time="2026-04-12T15:17:40Z" 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 15:17:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:40 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 12 15:17:40 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 12 15:17:40 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 12 15:17:40 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 12 15:17:40 volumio volumio[172086]: info: Received Get System Info
Apr 12 15:17:40 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 12 15:17:40 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 12 15:17:40 volumio volumio[172086]: info: Discovery: Getting this device information
Apr 12 15:17:40 volumio volumio[172086]: info: CoreCommandRouter::volumioGetState
Apr 12 15:17:40 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:17:40 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 12 15:17:40 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: Error: socket hang up
Apr 12 15:17:40 volumio volumio[172086]: error: MyVolumio Plugin failed to start in a timely fashion
Apr 12 15:17:40 volumio volumio[172086]: [Metrics] CommandRouter: 49s 401.43ms
Apr 12 15:17:40 volumio volumio[172086]: info: CoreCommandRouter::volumiosetStartupVolume
Apr 12 15:17:40 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 15:17:40 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 15:17:41 volumio volumio[172086]: info: CoreCommandRouter::Close All Modals sent
Apr 12 15:17:41 volumio volumio[172086]: info: CoreCommandRouter::Close All Modals sent
Apr 12 15:17:41 volumio dhcpcd[842]: eth0: DHCP lease expired
Apr 12 15:17:41 volumio dhcpcd[842]: eth0: soliciting a DHCP lease
Apr 12 15:17:42 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 12 15:17:42 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 12 15:17:42 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Apr 12 15:17:42 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Apr 12 15:17:42 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Apr 12 15:17:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 724.
Apr 12 15:17:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:43 volumio go-librespot[173041]: go-librespot daemon starting...
Apr 12 15:17:43 volumio go-librespot[173042]: time="2026-04-12T15:17:43Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:43 volumio go-librespot[173042]: time="2026-04-12T15:17:43Z" level=debug msg="app state loaded"
Apr 12 15:17:43 volumio go-librespot[173042]: time="2026-04-12T15:17:43Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:43 volumio go-librespot[173042]: time="2026-04-12T15:17:43Z" 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 15:17:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:44 volumio volumio[172086]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Apr 12 15:17:44 volumio volumio[172086]: info: FusionDsp - ---- read samplerate from file: 44100
Apr 12 15:17:44 volumio volumio[172086]: info: camilladsp stopping service pid 172389...
Apr 12 15:17:45 volumio volumio[172086]: grep: /proc/172389/cmdline: binary file matches
Apr 12 15:17:45 volumio volumio[172086]: grep: /proc/172389/cmdline: binary file matches
Apr 12 15:17:45 volumio volumio[172086]: grep: /proc/172389/cmdline: binary file matches
Apr 12 15:17:45 volumio volumio[172086]: grep: /proc/172389/cmdline: binary file matches
Apr 12 15:17:45 volumio volumio[172086]: grep: /proc/172389/cmdline: binary file matches
Apr 12 15:17:45 volumio volumio[172086]: info: camilladsp service terminated, instance 1
Apr 12 15:17:45 volumio volumio[172086]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Apr 12 15:17:45 volumio volumio[172086]: info: camilladsp service started and running in background, instance 1
Apr 12 15:17:45 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:17:46 volumio volumio5-onboarding[2284]: time=2026-04-12T15:17:46.161Z level=INFO msg="service successfully established" component=discovery/localnet
Apr 12 15:17:46 volumio kernel: r8169 0000:01:00.0 eth0: Link is Down
Apr 12 15:17:46 volumio dhcpcd[842]: eth0: carrier lost
Apr 12 15:17:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 725.
Apr 12 15:17:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:46 volumio go-librespot[173094]: go-librespot daemon starting...
Apr 12 15:17:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:46 volumio go-librespot[173095]: time="2026-04-12T15:17:46Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:46 volumio go-librespot[173095]: time="2026-04-12T15:17:46Z" level=debug msg="app state loaded"
Apr 12 15:17:46 volumio go-librespot[173095]: time="2026-04-12T15:17:46Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:47 volumio go-librespot[173095]: time="2026-04-12T15:17:47Z" 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 15:17:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:47 volumio ifplugd(eth0)[916]: Link beat lost.
Apr 12 15:17:47 volumio volumio[172086]: info: camilladsp respawn in 100 ms (attempt 1/10)
Apr 12 15:17:48 volumio kernel: r8169 0000:01:00.0 eth0: Link is Up - 100Mbps/Full - flow control rx/tx
Apr 12 15:17:48 volumio dhcpcd[842]: eth0: carrier acquired
Apr 12 15:17:48 volumio dhcpcd[842]: eth0: IAID 01:a2:8c:17
Apr 12 15:17:48 volumio dhcpcd[842]: eth0: soliciting a DHCP lease
Apr 12 15:17:48 volumio ifplugd(eth0)[916]: Link beat detected.
Apr 12 15:17:48 volumio dhcpcd[842]: eth0: soliciting an IPv6 router
Apr 12 15:17:49 volumio volumio[172086]: info: Received Get System Info
Apr 12 15:17:49 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 12 15:17:49 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 12 15:17:49 volumio volumio[172086]: info: Discovery: Getting this device information
Apr 12 15:17:49 volumio volumio[172086]: info: CoreCommandRouter::volumioGetState
Apr 12 15:17:49 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:17:49 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 12 15:17:49 volumio volumio[172086]: info: Received Get System Info
Apr 12 15:17:49 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 12 15:17:49 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 12 15:17:49 volumio volumio[172086]: info: Discovery: Getting this device information
Apr 12 15:17:49 volumio volumio[172086]: info: CoreCommandRouter::volumioGetState
Apr 12 15:17:49 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:17:49 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 12 15:17:49 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: AggregateError
Apr 12 15:17:49 volumio volumio[172086]: info: BOOT COMPLETED
Apr 12 15:17:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 726.
Apr 12 15:17:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:50 volumio go-librespot[173116]: go-librespot daemon starting...
Apr 12 15:17:50 volumio go-librespot[173117]: time="2026-04-12T15:17:50Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:50 volumio go-librespot[173117]: time="2026-04-12T15:17:50Z" level=debug msg="app state loaded"
Apr 12 15:17:50 volumio go-librespot[173117]: time="2026-04-12T15:17:50Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:50 volumio go-librespot[173117]: time="2026-04-12T15:17:50Z" 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 15:17:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:51 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 12 15:17:51 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 12 15:17:51 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 12 15:17:51 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 12 15:17:53 volumio volumio5-onboarding[2284]: time=2026-04-12T15:17:53.168Z level=INFO msg="service successfully established" component=discovery/localnet
Apr 12 15:17:53 volumio volumio[172086]: info: camilladsp respawn in 200 ms (attempt 2/10)
Apr 12 15:17:53 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:17:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 727.
Apr 12 15:17:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:53 volumio go-librespot[173127]: go-librespot daemon starting...
Apr 12 15:17:53 volumio go-librespot[173128]: time="2026-04-12T15:17:53Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:53 volumio go-librespot[173128]: time="2026-04-12T15:17:53Z" level=debug msg="app state loaded"
Apr 12 15:17:53 volumio go-librespot[173128]: time="2026-04-12T15:17:53Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:53 volumio go-librespot[173128]: time="2026-04-12T15:17:53Z" 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 15:17:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 728.
Apr 12 15:17:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:56 volumio go-librespot[173156]: go-librespot daemon starting...
Apr 12 15:17:56 volumio go-librespot[173157]: time="2026-04-12T15:17:56Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:56 volumio go-librespot[173157]: time="2026-04-12T15:17:56Z" level=debug msg="app state loaded"
Apr 12 15:17:56 volumio go-librespot[173157]: time="2026-04-12T15:17:56Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:56 volumio go-librespot[173157]: time="2026-04-12T15:17:56Z" 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 15:17:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:17:57 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: AggregateError
Apr 12 15:17:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 729.
Apr 12 15:17:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:17:59 volumio go-librespot[173167]: go-librespot daemon starting...
Apr 12 15:17:59 volumio go-librespot[173168]: time="2026-04-12T15:17:59Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:17:59 volumio go-librespot[173168]: time="2026-04-12T15:17:59Z" level=debug msg="app state loaded"
Apr 12 15:17:59 volumio go-librespot[173168]: time="2026-04-12T15:17:59Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:17:59 volumio go-librespot[173168]: time="2026-04-12T15:17:59Z" 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 15:17:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:17:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:18:01 volumio kernel: r8169 0000:01:00.0 eth0: Link is Down
Apr 12 15:18:01 volumio dhcpcd[842]: eth0: carrier lost
Apr 12 15:18:01 volumio ifplugd(eth0)[916]: Link beat lost.
Apr 12 15:18:02 volumio dhcpcd[842]: eth0: carrier acquired
Apr 12 15:18:02 volumio kernel: r8169 0000:01:00.0 eth0: Link is Up - 100Mbps/Full - flow control rx/tx
Apr 12 15:18:02 volumio dhcpcd[842]: eth0: IAID 01:a2:8c:17
Apr 12 15:18:02 volumio dhcpcd[842]: eth0: soliciting an IPv6 router
Apr 12 15:18:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 730.
Apr 12 15:18:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:03 volumio go-librespot[173194]: go-librespot daemon starting...
Apr 12 15:18:03 volumio go-librespot[173195]: time="2026-04-12T15:18:03Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:18:03 volumio go-librespot[173195]: time="2026-04-12T15:18:03Z" level=debug msg="app state loaded"
Apr 12 15:18:03 volumio go-librespot[173195]: time="2026-04-12T15:18:03Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:18:03 volumio go-librespot[173195]: time="2026-04-12T15:18:03Z" 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 15:18:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:18:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:18:03 volumio ifplugd(eth0)[916]: Link beat detected.
Apr 12 15:18:04 volumio dhcpcd[842]: eth0: soliciting a DHCP lease
Apr 12 15:18:05 volumio nmbd[1035]: [2026/04/12 15:18:05.676233, 0] ../../source3/nmbd/nmbd.c:359(reload_interfaces)
Apr 12 15:18:05 volumio nmbd[1035]: reload_interfaces: No subnets to listen to. Waiting..
Apr 12 15:18:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 731.
Apr 12 15:18:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:06 volumio go-librespot[173220]: go-librespot daemon starting...
Apr 12 15:18:06 volumio go-librespot[173221]: time="2026-04-12T15:18:06Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:18:06 volumio go-librespot[173221]: time="2026-04-12T15:18:06Z" level=debug msg="app state loaded"
Apr 12 15:18:06 volumio go-librespot[173221]: time="2026-04-12T15:18:06Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:18:06 volumio go-librespot[173221]: time="2026-04-12T15:18:06Z" 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 15:18:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:18:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:18:08 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:18:08 volumio volumio[172086]: info: Received Get System Info
Apr 12 15:18:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 12 15:18:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 12 15:18:08 volumio volumio[172086]: info: Discovery: Getting this device information
Apr 12 15:18:08 volumio volumio[172086]: info: CoreCommandRouter::volumioGetState
Apr 12 15:18:08 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:18:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 12 15:18:08 volumio volumio[172086]: info: Received Get System Info
Apr 12 15:18:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 12 15:18:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 12 15:18:08 volumio volumio[172086]: info: Discovery: Getting this device information
Apr 12 15:18:08 volumio volumio[172086]: info: CoreCommandRouter::volumioGetState
Apr 12 15:18:08 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:18:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 12 15:18:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 12 15:18:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 12 15:18:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 12 15:18:08 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 12 15:18:08 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: AggregateError
Apr 12 15:18:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 732.
Apr 12 15:18:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:09 volumio go-librespot[173231]: go-librespot daemon starting...
Apr 12 15:18:09 volumio go-librespot[173232]: time="2026-04-12T15:18:09Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:18:09 volumio go-librespot[173232]: time="2026-04-12T15:18:09Z" level=debug msg="app state loaded"
Apr 12 15:18:09 volumio go-librespot[173232]: time="2026-04-12T15:18:09Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:18:09 volumio go-librespot[173232]: time="2026-04-12T15:18: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\": dial tcp: lookup apresolve.spotify.com: device or resource busy"
Apr 12 15:18:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:18:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:18:10 volumio volumio5-onboarding[2284]: time=2026-04-12T15:18:10.318Z level=INFO msg="service successfully established" component=discovery/localnet
Apr 12 15:18:11 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:18:11 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: AggregateError
Apr 12 15:18:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 733.
Apr 12 15:18:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:12 volumio go-librespot[173242]: go-librespot daemon starting...
Apr 12 15:18:12 volumio go-librespot[173243]: time="2026-04-12T15:18:12Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:18:12 volumio go-librespot[173243]: time="2026-04-12T15:18:12Z" level=debug msg="app state loaded"
Apr 12 15:18:12 volumio go-librespot[173243]: time="2026-04-12T15:18:12Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:18:12 volumio go-librespot[173243]: time="2026-04-12T15:18: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 15:18:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:18:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:18:14 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:18:14 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: AggregateError
Apr 12 15:18:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 734.
Apr 12 15:18:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:16 volumio go-librespot[173268]: go-librespot daemon starting...
Apr 12 15:18:16 volumio go-librespot[173269]: time="2026-04-12T15:18:16Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:18:16 volumio go-librespot[173269]: time="2026-04-12T15:18:16Z" level=debug msg="app state loaded"
Apr 12 15:18:16 volumio go-librespot[173269]: time="2026-04-12T15:18:16Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:18:16 volumio go-librespot[173269]: time="2026-04-12T15:18: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 15:18:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:18:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:18:17 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:18:17 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: AggregateError
Apr 12 15:18:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 735.
Apr 12 15:18:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:19 volumio go-librespot[173279]: go-librespot daemon starting...
Apr 12 15:18:19 volumio go-librespot[173280]: time="2026-04-12T15:18:19Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:18:19 volumio go-librespot[173280]: time="2026-04-12T15:18:19Z" level=debug msg="app state loaded"
Apr 12 15:18:19 volumio go-librespot[173280]: time="2026-04-12T15:18:19Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:18:19 volumio go-librespot[173280]: time="2026-04-12T15:18: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 15:18:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:18:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:18:20 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:18:20 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: AggregateError
Apr 12 15:18:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 736.
Apr 12 15:18:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:22 volumio go-librespot[173290]: go-librespot daemon starting...
Apr 12 15:18:22 volumio go-librespot[173291]: time="2026-04-12T15:18:22Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:18:22 volumio go-librespot[173291]: time="2026-04-12T15:18:22Z" level=debug msg="app state loaded"
Apr 12 15:18:22 volumio go-librespot[173291]: time="2026-04-12T15:18:22Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:18:22 volumio go-librespot[173291]: time="2026-04-12T15:18: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 15:18:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:18:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:18:23 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:18:23 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: AggregateError
Apr 12 15:18:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 737.
Apr 12 15:18:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:25 volumio go-librespot[173301]: go-librespot daemon starting...
Apr 12 15:18:25 volumio go-librespot[173302]: time="2026-04-12T15:18:25Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:18:25 volumio go-librespot[173302]: time="2026-04-12T15:18:25Z" level=debug msg="app state loaded"
Apr 12 15:18:25 volumio go-librespot[173302]: time="2026-04-12T15:18:25Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:18:25 volumio go-librespot[173302]: time="2026-04-12T15:18: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 15:18:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:18:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:18:26 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:18:26 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: AggregateError
Apr 12 15:18:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 738.
Apr 12 15:18:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:29 volumio go-librespot[173326]: go-librespot daemon starting...
Apr 12 15:18:29 volumio go-librespot[173327]: time="2026-04-12T15:18:29Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:18:29 volumio go-librespot[173327]: time="2026-04-12T15:18:29Z" level=debug msg="app state loaded"
Apr 12 15:18:29 volumio go-librespot[173327]: time="2026-04-12T15:18:29Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:18:29 volumio go-librespot[173327]: time="2026-04-12T15:18: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 15:18:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:18:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:18:29 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:18:29 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: AggregateError
Apr 12 15:18:30 volumio dhcpcd[842]: eth0: offered 192.168.1.2 from 192.168.1.1
Apr 12 15:18:30 volumio dhcpcd[842]: eth0: probing address 192.168.1.2/24
Apr 12 15:18:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 739.
Apr 12 15:18:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:32 volumio go-librespot[173339]: go-librespot daemon starting...
Apr 12 15:18:32 volumio go-librespot[173340]: time="2026-04-12T15:18:32Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:18:32 volumio go-librespot[173340]: time="2026-04-12T15:18:32Z" level=debug msg="app state loaded"
Apr 12 15:18:32 volumio go-librespot[173340]: time="2026-04-12T15:18:32Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:18:32 volumio go-librespot[173340]: time="2026-04-12T15:18: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 15:18:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:18:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:18:32 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:18:32 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: AggregateError
Apr 12 15:18:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 740.
Apr 12 15:18:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:35 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:18:35 volumio volumio[172086]: info: Error connecting to go-librespot Websocket: AggregateError
Apr 12 15:18:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:35 volumio go-librespot[173350]: go-librespot daemon starting...
Apr 12 15:18:35 volumio go-librespot[173351]: time="2026-04-12T15:18:35Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:18:35 volumio go-librespot[173351]: time="2026-04-12T15:18:35Z" level=debug msg="app state loaded"
Apr 12 15:18:35 volumio go-librespot[173351]: time="2026-04-12T15:18:35Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:18:35 volumio go-librespot[173351]: time="2026-04-12T15:18: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 15:18:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:18:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:18:36 volumio dhcpcd[842]: eth0: leased 192.168.1.2 for 86400 seconds
Apr 12 15:18:36 volumio avahi-daemon[699]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.2.
Apr 12 15:18:36 volumio avahi-daemon[699]: New relevant interface eth0.IPv4 for mDNS.
Apr 12 15:18:36 volumio avahi-daemon[699]: Registering new address record for 192.168.1.2 on eth0.IPv4.
Apr 12 15:18:36 volumio dhcpcd[842]: eth0: adding route to 192.168.1.0/24
Apr 12 15:18:36 volumio dhcpcd[842]: eth0: adding default route via 192.168.1.1
Apr 12 15:18:36 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0.
Apr 12 15:18:36 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0...
Apr 12 15:18:36 volumio systemd[1]: welcome.service: Deactivated successfully.
Apr 12 15:18:36 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console.
Apr 12 15:18:36 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console...
Apr 12 15:18:36 volumio systemd[1]: Starting welcome.service - Show a welcome message on console...
Apr 12 15:18:36 volumio welcome[173381]: Resolved ip:[1] 192.168.1.2
Apr 12 15:18:36 volumio systemd[1]: Finished welcome.service - Show a welcome message on console.
Apr 12 15:18:36 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0.
Apr 12 15:18:36 volumio volumio[172086]: info: Received Get System Info
Apr 12 15:18:36 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 12 15:18:36 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 12 15:18:36 volumio volumio[172086]: info: Discovery: Getting this device information
Apr 12 15:18:36 volumio volumio[172086]: info: CoreCommandRouter::volumioGetState
Apr 12 15:18:36 volumio volumio[172086]: info: CorePlayQueue::getTrack 0
Apr 12 15:18:36 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 12 15:18:36 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 12 15:18:36 volumio volumio[172086]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 12 15:18:37 volumio ntpd[902]: IO: Listen normally on 5 eth0 192.168.1.2:123
Apr 12 15:18:37 volumio ntpd[902]: IO: new interface(s) found: waking up resolver
Apr 12 15:18:37 volumio volumio5-onboarding[2284]: time=2026-04-12T15:18:37.924Z level=INFO msg="service successfully established" component=discovery/localnet
Apr 12 15:18:38 volumio volumio[172086]: info: Initializing connection to go-librespot Websocket
Apr 12 15:18:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 741.
Apr 12 15:18:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Apr 12 15:18:38 volumio go-librespot[173401]: go-librespot daemon starting...
Apr 12 15:18:38 volumio go-librespot[173402]: time="2026-04-12T15:18:38Z" level=info msg="running go-librespot 0.7.1"
Apr 12 15:18:38 volumio go-librespot[173402]: time="2026-04-12T15:18:38Z" level=debug msg="app state loaded"
Apr 12 15:18:38 volumio go-librespot[173402]: time="2026-04-12T15:18:38Z" level=info msg="api server listening on 127.0.0.1:9879"
Apr 12 15:18:46 volumio volumio[172086]: info: Volumio Network Manager: Network status updated: 1
Apr 12 15:18:55 volumio volumio[172086]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
Apr 12 15:18:55 volumio volumio[172086]: info: Discovery: Restarting Browsing
Apr 12 15:18:55 volumio go-librespot[173402]: time="2026-04-12T15:18:55Z" level=debug msg="new websocket client"
Apr 12 15:18:55 volumio volumio[172086]: info: Connection to go-librespot Websocket established
Apr 12 15:18:56 volumio go-librespot[173402]: time="2026-04-12T15:18:56Z" 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 15:18:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 12 15:18:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 12 15:18:56 volumio volumio[172086]: info: Connection to go-librespot Websocket closed
Apr 12 15:18:58 volumio volumio[172086]: info: Getting Spotify volume
Apr 12 15:18:58 volumio volumio[172086]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 12 15:18:58 volumio volumio[172086]: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 12 15:18:58 volumio volumio[172086]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Apr 12 15:18:58 volumio volumio[172086]: errno: -111,
Apr 12 15:18:58 volumio volumio[172086]: code: 'ECONNREFUSED',
Apr 12 15:18:58 volumio volumio[172086]: syscall: 'connect',
Apr 12 15:18:58 volumio volumio[172086]: address: '127.0.0.1',
Apr 12 15:18:58 volumio volumio[172086]: port: 9879,
Apr 12 15:18:58 volumio volumio[172086]: response: undefined
Apr 12 15:18:58 volumio volumio[172086]: }
Apr 12 15:18:58 volumio volumio[172086]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 12 15:18:59 volumio sudo[173473]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-12 15:17'
Apr 12 15:18:59 volumio sudo[173473]: 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"