-- Logs begin at Sun 2025-03-16 09:30:26 CET, end at Tue 2025-03-18 04:03:27 CET. -- Mar 18 04:02:01 volumio volumio[18047]: info: Loading plugin "squeezelite_mc"... Mar 18 04:02:01 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 18 04:02:01 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 18 04:02:01 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 18 04:02:01 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 18 04:02:02 volumio volumio[18047]: info: Loading plugin "outputs"... Mar 18 04:02:02 volumio volumio[18047]: info: Loading plugin "albumart"... Mar 18 04:02:02 volumio volumio[18047]: info: Plugin example_plugin is not enabled Mar 18 04:02:02 volumio volumio[18047]: info: Loading plugin "inputs"... Mar 18 04:02:02 volumio volumio[18047]: info: Loading plugin "updater_comm"... Mar 18 04:02:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Mar 18 04:02:02 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:02 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:02 volumio go-librespot[18150]: Librespot-go daemon starting... Mar 18 04:02:02 volumio go-librespot[18150]: time="2025-03-18T04:02:02+01:00" level=info msg="generated new device id: ccb67fed622fdd9e2faa85eca2452e1e1f1bbd92" Mar 18 04:02:02 volumio go-librespot[18150]: time="2025-03-18T04:02:02+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:02 volumio volumio[18047]: info: Plugin mpdemulation is not enabled Mar 18 04:02:02 volumio volumio[18047]: info: Loading plugin "rest_api"... Mar 18 04:02:02 volumio volumio[18047]: info: Loading plugin "websocket"... Mar 18 04:02:02 volumio volumio[18047]: info: Starting Socket.io Server version 2.3.0 Mar 18 04:02:02 volumio volumio[18047]: info: Loading plugin "radio_paradise"... Mar 18 04:02:03 volumio volumio[18047]: Forking 3 albumart workers Mar 18 04:02:03 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 18 04:02:03 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 18 04:02:03 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 18 04:02:03 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 18 04:02:03 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 18 04:02:03 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 18 04:02:03 volumio volumio[18047]: info: Applying required configuration parameters for plugin radio_paradise Mar 18 04:02:03 volumio volumio[18047]: info: [1742266923443] [RadioParadise] API delay: 3 Mar 18 04:02:03 volumio volumio[18047]: info: Loading plugin "backup_restore"... Mar 18 04:02:03 volumio volumio[18047]: info: Applying required configuration parameters for plugin backup_restore Mar 18 04:02:03 volumio volumio[18047]: info: Loading plugin "music_services_shield"... Mar 18 04:02:04 volumio volumio[18047]: info: Applying required configuration parameters for plugin music_services_shield Mar 18 04:02:04 volumio volumio[18047]: info: Loading plugin "Systeminfo"... Mar 18 04:02:05 volumio volumio[18047]: info: Loading i18n strings for locale en Mar 18 04:02:05 volumio volumio[18047]: Updating browse sources language Mar 18 04:02:05 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:02:05 volumio volumio[18047]: Starting albumart workers Mar 18 04:02:05 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 18 04:02:05 volumio volumio[18047]: info: CoreCommandRouter::initPlayerControls Mar 18 04:02:05 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:05 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:05 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 18 04:02:05 volumio volumio[18047]: Express server listening on port 3000 Mar 18 04:02:05 volumio volumio[18047]: [Metrics] WebUI: 12s 298.09ms Mar 18 04:02:05 volumio volumio[18047]: info: CoreStateMachine::resetVolumioState Mar 18 04:02:05 volumio volumio[18047]: info: CoreStateMachine::getcurrentVolume Mar 18 04:02:05 volumio volumio[18047]: info: CoreCommandRouter::volumioRetrievevolume Mar 18 04:02:05 volumio volumio[18047]: Starting albumart workers Mar 18 04:02:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Mar 18 04:02:05 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:05 volumio volumio[18047]: info: Volumio Network Manager: Network status updated: 0 Mar 18 04:02:05 volumio volumio[18047]: info: Cannot mount NAS Music-Dieter at system boot, trial number 1 ,retrying in 5 seconds Mar 18 04:02:05 volumio volumio[18047]: info: Cannot mount NAS NasTas at system boot, trial number 1 ,retrying in 5 seconds Mar 18 04:02:05 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:05 volumio go-librespot[18182]: Librespot-go daemon starting... Mar 18 04:02:05 volumio go-librespot[18182]: time="2025-03-18T04:02:05+01:00" level=info msg="generated new device id: 7ee8ae96ee1f7a57d9bd397efb9214845e954d7c" Mar 18 04:02:05 volumio go-librespot[18182]: time="2025-03-18T04:02:05+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:06 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:02:06 volumio volumio[18047]: info: Reloading queue from file Mar 18 04:02:06 volumio volumio[18047]: Starting albumart workers Mar 18 04:02:06 volumio volumio[18047]: info: CoreStateMachine::setRepeat null single undefined Mar 18 04:02:06 volumio volumio[18047]: info: CoreStateMachine::pushState Mar 18 04:02:06 volumio volumio[18047]: info: CorePlayQueue::getTrack 0 Mar 18 04:02:06 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 18 04:02:06 volumio volumio[18047]: info: CoreCommandRouter::volumioPushState Mar 18 04:02:06 volumio volumio[18047]: info: CoreStateMachine::setRandom false Mar 18 04:02:06 volumio volumio[18047]: info: CoreStateMachine::pushState Mar 18 04:02:06 volumio volumio[18047]: info: CorePlayQueue::getTrack 0 Mar 18 04:02:06 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 18 04:02:06 volumio volumio[18047]: info: CoreCommandRouter::volumioPushState Mar 18 04:02:06 volumio volumio[18047]: info: Setting Device type: Raspberry PI Mar 18 04:02:06 volumio volumio[18047]: info: VolumeController:: Volume=100 Mute =false Mar 18 04:02:06 volumio volumio[18047]: info: CoreStateMachine::pushState Mar 18 04:02:06 volumio volumio[18047]: info: CorePlayQueue::getTrack 0 Mar 18 04:02:06 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 18 04:02:06 volumio volumio[18047]: info: CoreCommandRouter::volumioPushState Mar 18 04:02:06 volumio volumio[18047]: info: CoreStateMachine::updateTrackBlock Mar 18 04:02:06 volumio volumio[18047]: info: CorePlayQueue::getTrackBlock Mar 18 04:02:06 volumio volumio[18047]: info: CoreCommandRouter::volumioRetrievevolume Mar 18 04:02:06 volumio volumio[18047]: info: Completed loading Core Plugins Mar 18 04:02:06 volumio volumio[18047]: info: Preparing to generate the ALSA configuration file Mar 18 04:02:06 volumio volumio[18047]: info: Asound.conf file unchanged, so no further update is needed Mar 18 04:02:06 volumio volumio[18047]: info: Output device has changed, restarting MPD Mar 18 04:02:06 volumio sudo[18197]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 18 04:02:06 volumio sudo[18197]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:06 volumio sudo[18197]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:06 volumio volumio[18047]: info: ___________ START PLUGINS ___________ Mar 18 04:02:06 volumio sudo[18200]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 18 04:02:06 volumio sudo[18200]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:06 volumio volumio[18047]: info: ControllerMpd::onStart: Initializing MPD Mar 18 04:02:06 volumio volumio[18047]: info: Creating MPD Configuration file Mar 18 04:02:06 volumio systemd[1]: musicservicesshield.service: Succeeded. Mar 18 04:02:06 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Mar 18 04:02:06 volumio systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Mar 18 04:02:06 volumio systemd[1]: Stopping Music Player Daemon... Mar 18 04:02:06 volumio systemd[1]: mpd.service: Succeeded. Mar 18 04:02:06 volumio systemd[1]: Stopped Music Player Daemon. Mar 18 04:02:06 volumio volumio[18047]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:02:06 volumio volumio[18047]: info: [1742266926889] CoreMusicLibrary::Adding element Last_100 Mar 18 04:02:06 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:02:06 volumio volumio[18047]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:02:06 volumio volumio[18047]: info: [1742266926945] CoreMusicLibrary::Adding element Webradio Mar 18 04:02:06 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:02:06 volumio systemd[1]: Starting Music Player Daemon... Mar 18 04:02:06 volumio sudo[18203]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 18 04:02:06 volumio sudo[18203]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:06 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 18 04:02:06 volumio volumio[18047]: info: Initializing BBC Radios Mar 18 04:02:07 volumio sudo[18203]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:07 volumio sudo[18205]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 18 04:02:07 volumio sudo[18205]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:07 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Mar 18 04:02:07 volumio systemd[1]: mpd.service: Succeeded. Mar 18 04:02:07 volumio systemd[1]: Stopped Music Player Daemon. Mar 18 04:02:07 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 18 04:02:07 volumio systemd[1]: Starting Music Player Daemon... Mar 18 04:02:07 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 18 04:02:07 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 18 04:02:07 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:02:07 volumio volumio[18047]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:02:07 volumio volumio[18047]: info: [1742266927426] CoreMusicLibrary::Adding element SoundCloud Mar 18 04:02:07 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:02:07 volumio volumio[18047]: Cannot find translation for source SoundCloud Mar 18 04:02:07 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 18 04:02:07 volumio volumio[18047]: info: Creating Spotify config file Mar 18 04:02:07 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:07 volumio sudo[18211]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 18 04:02:07 volumio sudo[18211]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:07 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 18 04:02:07 volumio sudo[18211]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:07 volumio volumio[18047]: info: [squeezelite_mc] Starting proxy server... Mar 18 04:02:07 volumio volumio[18047]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:02:07 volumio volumio[18047]: info: [1742266927724] CoreMusicLibrary::Adding element Radio Paradise Mar 18 04:02:07 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:02:07 volumio volumio[18047]: Cannot find translation for source SoundCloud Mar 18 04:02:07 volumio volumio[18047]: Cannot find translation for source Radio Paradise Mar 18 04:02:08 volumio volumio[18047]: info: Volumio Calling Home Mar 18 04:02:08 volumio sudo[18286]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Mar 18 04:02:08 volumio sudo[18286]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:08 volumio volumio[18047]: info: [squeezelite_mc] Proxy server started on port 36211 Mar 18 04:02:08 volumio volumio[18047]: info: CoreCommandRouter::volumioRetrievevolume Mar 18 04:02:08 volumio volumio[18047]: info: MPD Permissions set Mar 18 04:02:08 volumio volumio[18047]: info: MPD Permissions set Mar 18 04:02:08 volumio volumio[18047]: info: VolumeController:: Volume=100 Mute =false Mar 18 04:02:08 volumio volumio[18047]: info: CoreStateMachine::pushState Mar 18 04:02:08 volumio volumio[18047]: info: CorePlayQueue::getTrack 0 Mar 18 04:02:08 volumio volumio[18047]: info: CoreCommandRouter::volumioPushState Mar 18 04:02:08 volumio volumio[18047]: info: Spotify config file written Mar 18 04:02:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Mar 18 04:02:09 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:09 volumio sudo[18305]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 18 04:02:09 volumio sudo[18305]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:09 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:09 volumio go-librespot[18306]: Librespot-go daemon starting... Mar 18 04:02:09 volumio volumio[18047]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 18 04:02:09 volumio systemd[1]: Stopping go-librespot Daemon... Mar 18 04:02:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Mar 18 04:02:09 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Mar 18 04:02:09 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:09 volumio sudo[18305]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio-remote-updater[567]: [2025-03-18 04:02:09] [connect] Successful connection Mar 18 04:02:09 volumio go-librespot[18313]: Librespot-go daemon starting... Mar 18 04:02:09 volumio go-librespot[18313]: time="2025-03-18T04:02:09+01:00" level=info msg="generated new device id: ea61e8a1b1b72c41f6ccc33946e73a3996f8844d" Mar 18 04:02:09 volumio go-librespot[18313]: time="2025-03-18T04:02:09+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 18 04:02:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 18 04:02:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 18 04:02:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 18 04:02:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 18 04:02:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 18 04:02:09 volumio wpa_supplicant[872]: wlan0: Failed to initiate sched scan Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: No need to fix Spotify hosts Mar 18 04:02:09 volumio volumio[18047]: info: VolumeController:: Volume=100 Mute =false Mar 18 04:02:09 volumio volumio[18047]: info: CoreStateMachine::pushState Mar 18 04:02:09 volumio volumio[18047]: info: CorePlayQueue::getTrack 0 Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::volumioPushState Mar 18 04:02:09 volumio volumio[18047]: info: [squeezelite_mc] Server discovery started Mar 18 04:02:09 volumio volumio[18047]: info: [squeezelite_mc] Player finder started Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 18 04:02:09 volumio volumio[18047]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Mar 18 04:02:09 volumio volumio[18047]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 18 04:02:09 volumio volumio[18047]: Error: send ENETUNREACH 255.255.255.255:3483 Mar 18 04:02:09 volumio volumio[18047]: at doSend (dgram.js:692:16) Mar 18 04:02:09 volumio volumio[18047]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Mar 18 04:02:09 volumio volumio[18047]: at afterDns (dgram.js:638:5) Mar 18 04:02:09 volumio volumio[18047]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Mar 18 04:02:09 volumio volumio[18047]: errno: -101, Mar 18 04:02:09 volumio volumio[18047]: code: 'ENETUNREACH', Mar 18 04:02:09 volumio volumio[18047]: syscall: 'send', Mar 18 04:02:09 volumio volumio[18047]: address: '255.255.255.255', Mar 18 04:02:09 volumio volumio[18047]: port: 3483 Mar 18 04:02:09 volumio volumio[18047]: } Mar 18 04:02:09 volumio volumio[18047]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 18 04:02:09 volumio sudo[18286]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:10 volumio mpd[18250]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 18 04:02:10 volumio mpd[18250]: output: No 'audio_output' defined in config file Mar 18 04:02:10 volumio mpd[18250]: output: Successfully detected a sndio audio device Mar 18 04:02:10 volumio mpd[18250]: zeroconf: No global port, disabling zeroconf Mar 18 04:02:10 volumio systemd[1]: Started Music Player Daemon. Mar 18 04:02:10 volumio sudo[18205]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:10 volumio sudo[18200]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:10 volumio sudo[18344]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-18 04:01 Mar 18 04:02:10 volumio sudo[18344]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:10 volumio systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Mar 18 04:02:11 volumio sudo[18344]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:11 volumio autossh[9021]: starting ssh (count 17) Mar 18 04:02:11 volumio autossh[9021]: ssh child pid is 18355 Mar 18 04:02:11 volumio volumiossh-tunnel[9020]: ssh: Could not resolve hostname eu7.myvolumio.org: Device or resource busy Mar 18 04:02:11 volumio autossh[9021]: ssh exited with error status 255; restarting ssh Mar 18 04:02:11 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:11 volumio volumio-remote-updater[567]: [2025-03-18 04:02:11] [info] asio async_read_at_least error: system:104 (Connection reset by peer) Mar 18 04:02:11 volumio volumio-remote-updater[567]: [2025-03-18 04:02:11] [error] handle_read_http_response error: websocketpp.transport:2 (Underlying Transport Error) Mar 18 04:02:11 volumio volumio-remote-updater[567]: [2025-03-18 04:02:11] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Mar 18 04:02:11 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 18 04:02:11 volumio systemd[1]: Started dynamicswap service. Mar 18 04:02:11 volumio systemd[1]: dynamicswap.service: Succeeded. Mar 18 04:02:11 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Mar 18 04:02:11 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 67. Mar 18 04:02:11 volumio systemd[1]: Stopped Volumio Backend Module. Mar 18 04:02:11 volumio systemd[1]: Started Volumio Backend Module. Mar 18 04:02:11 volumio systemd[1]: Started dynamicswap service. Mar 18 04:02:11 volumio systemd[1]: dynamicswap.service: Succeeded. Mar 18 04:02:11 volumio volumio[18345]: cset: --> shielding system active with Mar 18 04:02:11 volumio volumio[18345]: cset: "system" cpuset of CPUSPEC(1-3) with 55 tasks running Mar 18 04:02:11 volumio volumio[18345]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Mar 18 04:02:11 volumio systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Mar 18 04:02:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 18 04:02:12 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:12 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:12 volumio go-librespot[18386]: Librespot-go daemon starting... Mar 18 04:02:12 volumio go-librespot[18386]: time="2025-03-18T04:02:12+01:00" level=info msg="generated new device id: 9cf47c3816c8ac9a8595631d660ccc8c50a706a6" Mar 18 04:02:12 volumio go-librespot[18386]: time="2025-03-18T04:02:12+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:13 volumio volumio[18373]: info: ------------------------------------------- Mar 18 04:02:13 volumio volumio[18373]: info: ----- Volumio3 ---- Mar 18 04:02:13 volumio volumio[18373]: info: ------------------------------------------- Mar 18 04:02:13 volumio volumio[18373]: info: ----- System startup ---- Mar 18 04:02:13 volumio volumio[18373]: info: ------------------------------------------- Mar 18 04:02:13 volumio kernel: hwmon hwmon1: Voltage normalised Mar 18 04:02:13 volumio volumio[18373]: info: MYVOLUMIO Environment detected Mar 18 04:02:13 volumio volumio[18373]: info: Plugin folders cleanup Mar 18 04:02:13 volumio volumio[18373]: info: Scanning into folder /volumio/app/plugins/ Mar 18 04:02:13 volumio volumio[18373]: info: Scanning category audio_interface Mar 18 04:02:13 volumio volumio[18373]: info: Scanning category miscellanea Mar 18 04:02:13 volumio volumio[18373]: info: Scanning category music_service Mar 18 04:02:13 volumio volumio[18373]: info: Scanning category plugins.json Mar 18 04:02:13 volumio volumio[18373]: info: Scanning category system_controller Mar 18 04:02:13 volumio volumio[18373]: info: Scanning category user_interface Mar 18 04:02:13 volumio volumio[18373]: info: Scanning into folder /data/plugins/ Mar 18 04:02:13 volumio volumio[18373]: info: Scanning category music_service Mar 18 04:02:13 volumio volumio[18373]: info: Scanning category system_controller Mar 18 04:02:13 volumio volumio[18373]: info: Scanning category system_hardware Mar 18 04:02:13 volumio volumio[18373]: info: Scanning category user_interface Mar 18 04:02:13 volumio volumio[18373]: info: Plugin folders cleanup completed Mar 18 04:02:13 volumio volumio[18373]: info: ------------------------------------------- Mar 18 04:02:13 volumio volumio[18373]: info: ----- Core plugins startup ---- Mar 18 04:02:13 volumio volumio[18373]: info: ------------------------------------------- Mar 18 04:02:13 volumio volumio[18373]: info: Loading plugins from folder /volumio/app/plugins/ Mar 18 04:02:13 volumio volumio[18373]: info: Adding plugin upnp to MyMusic Plugins Mar 18 04:02:13 volumio volumio[18373]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 18 04:02:13 volumio volumio[18373]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 18 04:02:13 volumio volumio[18373]: info: Loading plugins from folder /data/plugins/ Mar 18 04:02:13 volumio volumio[18373]: info: Loading plugin "system"... Mar 18 04:02:13 volumio volumio[18373]: info: Loading plugin "appearance"... Mar 18 04:02:15 volumio volumio[18373]: info: Loading plugin "network"... Mar 18 04:02:15 volumio volumio[18373]: info: Refreshing Cached IP Addresses Mar 18 04:02:15 volumio sudo[18408]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 18 04:02:15 volumio sudo[18408]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:15 volumio sudo[18408]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:15 volumio sudo[18410]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 18 04:02:15 volumio sudo[18410]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:15 volumio sudo[18410]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:15 volumio volumio[18373]: info: Loading plugin "services"... Mar 18 04:02:15 volumio volumio[18373]: info: Loading plugin "alsa_controller"... Mar 18 04:02:15 volumio sudo[18419]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 18 04:02:15 volumio sudo[18419]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:15 volumio sudo[18419]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:15 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 18 04:02:15 volumio volumio[18373]: info: Loading plugin "wizard"... Mar 18 04:02:15 volumio volumio[18373]: info: Loading plugin "networkfs"... Mar 18 04:02:15 volumio volumio[18373]: info: Starting Udev Watcher for removable devices Mar 18 04:02:15 volumio sudo[18436]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto,vers=3 192.168.0.101:/volume1/Public/Music /mnt/NAS/NasTas Mar 18 04:02:15 volumio sudo[18436]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:15 volumio sudo[18438]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto,vers=3 192.168.0.101:/volume1/Public/Musik-Dieter /mnt/NAS/Music-Dieter Mar 18 04:02:15 volumio kernel: hwmon hwmon1: Undervoltage detected! Mar 18 04:02:15 volumio sudo[18438]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:15 volumio volumio[18373]: info: Ignoring mount for partition: boot Mar 18 04:02:15 volumio volumio[18373]: info: Ignoring mount for partition: volumio Mar 18 04:02:15 volumio volumio[18373]: info: Ignoring mount for partition: volumio_data Mar 18 04:02:15 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 18 04:02:15 volumio volumio[18373]: info: Loading plugin "volumio_command_line_client"... Mar 18 04:02:15 volumio volumio[18373]: info: Plugin upnp is not enabled Mar 18 04:02:15 volumio volumio[18373]: info: Loading plugin "my_music"... Mar 18 04:02:15 volumio volumio[18373]: info: Loading plugin "mpd"... Mar 18 04:02:15 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 18 04:02:15 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:15 volumio sudo[18436]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:15 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:15 volumio go-librespot[18443]: Librespot-go daemon starting... Mar 18 04:02:15 volumio sudo[18438]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:15 volumio go-librespot[18443]: time="2025-03-18T04:02:15+01:00" level=info msg="generated new device id: df6e5e775c611e475deb765e97a0c1f9d6c2881c" Mar 18 04:02:15 volumio go-librespot[18443]: time="2025-03-18T04:02:15+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:16 volumio volumio[18373]: info: Plugin upnp_browser is not enabled Mar 18 04:02:16 volumio volumio[18373]: info: Loading plugin "alarm-clock"... Mar 18 04:02:16 volumio volumio[18373]: info: Plugin airplay_emulation is not enabled Mar 18 04:02:16 volumio volumio[18373]: info: Loading plugin "last_100"... Mar 18 04:02:16 volumio volumio[18373]: info: Loading plugin "webradio"... Mar 18 04:02:16 volumio volumio[18373]: info: Loading plugin "i2s_dacs"... Mar 18 04:02:16 volumio volumio[18373]: info: Loading plugin "volumiodiscovery"... Mar 18 04:02:17 volumio volumio[18373]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 18 04:02:17 volumio volumio[18373]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 18 04:02:17 volumio volumio[18373]: *** WARNING *** For more information see Mar 18 04:02:17 volumio volumio[18373]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 18 04:02:17 volumio node[18373]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 18 04:02:17 volumio volumio[18373]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 18 04:02:17 volumio volumio[18373]: *** WARNING *** For more information see Mar 18 04:02:17 volumio node[18373]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 18 04:02:17 volumio node[18373]: *** WARNING *** For more information see Mar 18 04:02:17 volumio node[18373]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 18 04:02:17 volumio node[18373]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 18 04:02:17 volumio node[18373]: *** WARNING *** For more information see Mar 18 04:02:17 volumio volumio[18373]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 18 04:02:17 volumio volumio[18373]: info: Discovery: Started advertising with name: Volumio Mar 18 04:02:17 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 18 04:02:17 volumio volumio[18373]: info: Loading plugin "soundcloud"... Mar 18 04:02:17 volumio volumio[18373]: info: Loading plugin "spop"... Mar 18 04:02:18 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 18 04:02:18 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 18 04:02:18 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 18 04:02:18 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 18 04:02:19 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 18 04:02:19 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:19 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:19 volumio go-librespot[18455]: Librespot-go daemon starting... Mar 18 04:02:19 volumio go-librespot[18455]: time="2025-03-18T04:02:19+01:00" level=info msg="generated new device id: a5ddf9d1952ef34eeac32d2903c9feacd3da66f7" Mar 18 04:02:19 volumio go-librespot[18455]: time="2025-03-18T04:02:19+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:19 volumio volumio[18373]: info: Loading plugin "squeezelite_mc"... Mar 18 04:02:20 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 18 04:02:20 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 18 04:02:20 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 18 04:02:20 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 18 04:02:20 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 18 04:02:20 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 18 04:02:20 volumio wpa_supplicant[872]: wlan0: Failed to initiate sched scan Mar 18 04:02:21 volumio volumio[18373]: info: Loading plugin "outputs"... Mar 18 04:02:21 volumio volumio[18373]: info: Loading plugin "albumart"... Mar 18 04:02:21 volumio volumio[18373]: info: Plugin example_plugin is not enabled Mar 18 04:02:21 volumio volumio[18373]: info: Loading plugin "inputs"... Mar 18 04:02:21 volumio volumio[18373]: info: Loading plugin "updater_comm"... Mar 18 04:02:21 volumio volumio-remote-updater[567]: [2025-03-18 04:02:21] [connect] Successful connection Mar 18 04:02:21 volumio volumio[18373]: info: Plugin mpdemulation is not enabled Mar 18 04:02:21 volumio volumio[18373]: info: Loading plugin "rest_api"... Mar 18 04:02:21 volumio volumio[18373]: info: Loading plugin "websocket"... Mar 18 04:02:21 volumio volumio[18373]: info: Starting Socket.io Server version 2.3.0 Mar 18 04:02:21 volumio volumio[18373]: info: Loading plugin "radio_paradise"... Mar 18 04:02:21 volumio volumio[18373]: Forking 3 albumart workers Mar 18 04:02:21 volumio volumio[18373]: info: Applying required configuration parameters for plugin radio_paradise Mar 18 04:02:21 volumio volumio[18373]: info: [1742266941714] [RadioParadise] API delay: 3 Mar 18 04:02:21 volumio volumio[18373]: info: Loading plugin "backup_restore"... Mar 18 04:02:21 volumio volumio[18373]: info: Applying required configuration parameters for plugin backup_restore Mar 18 04:02:21 volumio volumio[18373]: info: Loading plugin "music_services_shield"... Mar 18 04:02:22 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 18 04:02:22 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:22 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:22 volumio go-librespot[18490]: Librespot-go daemon starting... Mar 18 04:02:22 volumio go-librespot[18490]: time="2025-03-18T04:02:22+01:00" level=info msg="generated new device id: 499a2a4b20e22992637152cac48cdb60459ab680" Mar 18 04:02:22 volumio volumio[18373]: info: Applying required configuration parameters for plugin music_services_shield Mar 18 04:02:22 volumio go-librespot[18490]: time="2025-03-18T04:02:22+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:22 volumio volumio[18373]: info: Loading plugin "Systeminfo"... Mar 18 04:02:22 volumio volumio[18373]: info: Loading i18n strings for locale en Mar 18 04:02:22 volumio volumio[18373]: Updating browse sources language Mar 18 04:02:22 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:02:22 volumio volumio[18373]: Starting albumart workers Mar 18 04:02:22 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 18 04:02:22 volumio volumio[18373]: info: CoreCommandRouter::initPlayerControls Mar 18 04:02:22 volumio volumio[18373]: Starting albumart workers Mar 18 04:02:22 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:22 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:22 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:22 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:22 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:22 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:22 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:22 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:22 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 18 04:02:22 volumio volumio[18373]: Express server listening on port 3000 Mar 18 04:02:22 volumio volumio[18373]: [Metrics] WebUI: 10s 336.33ms Mar 18 04:02:22 volumio volumio[18373]: info: CoreStateMachine::resetVolumioState Mar 18 04:02:22 volumio volumio[18373]: info: CoreStateMachine::getcurrentVolume Mar 18 04:02:22 volumio volumio[18373]: info: CoreCommandRouter::volumioRetrievevolume Mar 18 04:02:23 volumio volumio[18373]: info: Volumio Network Manager: Network status updated: 0 Mar 18 04:02:23 volumio volumio[18373]: info: Cannot mount NAS Music-Dieter at system boot, trial number 1 ,retrying in 5 seconds Mar 18 04:02:23 volumio volumio[18373]: info: Cannot mount NAS NasTas at system boot, trial number 1 ,retrying in 5 seconds Mar 18 04:02:23 volumio volumio[18373]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Mar 18 04:02:23 volumio volumio[18373]: wlan0 Interface doesn't support scanning : Device or resource busy Mar 18 04:02:23 volumio volumio[18373]: info: Cannot use regular scanning, forcing with ap-force Mar 18 04:02:23 volumio sudo[18502]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Mar 18 04:02:23 volumio sudo[18502]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:23 volumio volumio[18373]: Starting albumart workers Mar 18 04:02:25 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 18 04:02:25 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:25 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:25 volumio go-librespot[18543]: Librespot-go daemon starting... Mar 18 04:02:25 volumio go-librespot[18543]: time="2025-03-18T04:02:25+01:00" level=info msg="generated new device id: 74d846bdf766acf37cabf296d2b40bd237422063" Mar 18 04:02:25 volumio go-librespot[18543]: time="2025-03-18T04:02:25+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:25 volumio sudo[18502]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:25 volumio volumio-remote-updater[567]: [2025-03-18 04:02:25] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1742266941 101 Mar 18 04:02:25 volumio volumio[18373]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:02:26 volumio volumio[18373]: info: Reloading queue from file Mar 18 04:02:26 volumio volumio[18373]: info: CoreStateMachine::setRepeat null single undefined Mar 18 04:02:26 volumio volumio[18373]: info: CoreStateMachine::pushState Mar 18 04:02:26 volumio volumio[18373]: info: CorePlayQueue::getTrack 0 Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::volumioPushState Mar 18 04:02:26 volumio volumio[18373]: info: CoreStateMachine::setRandom false Mar 18 04:02:26 volumio volumio[18373]: info: CoreStateMachine::pushState Mar 18 04:02:26 volumio volumio[18373]: info: CorePlayQueue::getTrack 0 Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::volumioPushState Mar 18 04:02:26 volumio volumio[18373]: info: Setting Device type: Raspberry PI Mar 18 04:02:26 volumio volumio[18373]: info: VolumeController:: Volume=100 Mute =false Mar 18 04:02:26 volumio volumio[18373]: info: CoreStateMachine::pushState Mar 18 04:02:26 volumio volumio[18373]: info: CorePlayQueue::getTrack 0 Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::volumioPushState Mar 18 04:02:26 volumio volumio[18373]: info: CoreStateMachine::updateTrackBlock Mar 18 04:02:26 volumio volumio[18373]: info: CorePlayQueue::getTrackBlock Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::volumioRetrievevolume Mar 18 04:02:26 volumio volumio[18373]: info: Completed loading Core Plugins Mar 18 04:02:26 volumio volumio[18373]: info: Preparing to generate the ALSA configuration file Mar 18 04:02:26 volumio volumio[18373]: info: Asound.conf file unchanged, so no further update is needed Mar 18 04:02:26 volumio volumio[18373]: info: Output device has changed, restarting MPD Mar 18 04:02:26 volumio sudo[18596]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 18 04:02:26 volumio sudo[18596]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:26 volumio volumio[18373]: info: ___________ START PLUGINS ___________ Mar 18 04:02:26 volumio volumio[18373]: info: ControllerMpd::onStart: Initializing MPD Mar 18 04:02:26 volumio volumio[18373]: info: Creating MPD Configuration file Mar 18 04:02:26 volumio sudo[18596]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:26 volumio sudo[18598]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 18 04:02:26 volumio sudo[18598]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:26 volumio systemd[1]: musicservicesshield.service: Succeeded. Mar 18 04:02:26 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Mar 18 04:02:26 volumio systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Mar 18 04:02:26 volumio systemd[1]: Stopping Music Player Daemon... Mar 18 04:02:26 volumio sudo[18602]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:02:26 volumio volumio[18373]: info: [1742266946378] CoreMusicLibrary::Adding element Last_100 Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:02:26 volumio sudo[18602]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:02:26 volumio volumio[18373]: info: [1742266946391] CoreMusicLibrary::Adding element Webradio Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:02:26 volumio systemd[1]: mpd.service: Succeeded. Mar 18 04:02:26 volumio sudo[18602]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:26 volumio systemd[1]: Stopped Music Player Daemon. Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 18 04:02:26 volumio volumio[18373]: info: Initializing BBC Radios Mar 18 04:02:26 volumio sudo[18604]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 18 04:02:26 volumio sudo[18604]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:26 volumio systemd[1]: Starting Music Player Daemon... Mar 18 04:02:26 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Mar 18 04:02:26 volumio systemd[1]: mpd.service: Succeeded. Mar 18 04:02:26 volumio systemd[1]: Stopped Music Player Daemon. Mar 18 04:02:26 volumio systemd[1]: Starting Music Player Daemon... Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:02:26 volumio volumio[18373]: info: [1742266946613] CoreMusicLibrary::Adding element SoundCloud Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:02:26 volumio volumio[18373]: Cannot find translation for source SoundCloud Mar 18 04:02:26 volumio volumio[18373]: info: Creating Spotify config file Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:26 volumio volumio[18373]: info: [squeezelite_mc] Starting proxy server... Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:02:26 volumio volumio[18373]: info: [1742266946713] CoreMusicLibrary::Adding element Radio Paradise Mar 18 04:02:26 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:02:26 volumio volumio[18373]: Cannot find translation for source SoundCloud Mar 18 04:02:26 volumio volumio[18373]: Cannot find translation for source Radio Paradise Mar 18 04:02:26 volumio sudo[18615]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 18 04:02:26 volumio sudo[18615]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:26 volumio sudo[18615]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:27 volumio volumio[18373]: info: Volumio Calling Home Mar 18 04:02:27 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 18 04:02:27 volumio volumio[18373]: info: [squeezelite_mc] Proxy server started on port 35519 Mar 18 04:02:27 volumio sudo[18647]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Mar 18 04:02:27 volumio sudo[18647]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:27 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 18 04:02:27 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 18 04:02:27 volumio volumio[18373]: info: CoreCommandRouter::volumioRetrievevolume Mar 18 04:02:27 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 18 04:02:27 volumio volumio[18373]: info: MPD Permissions set Mar 18 04:02:27 volumio volumio[18373]: info: VolumeController:: Volume=100 Mute =false Mar 18 04:02:27 volumio volumio[18373]: info: CoreStateMachine::pushState Mar 18 04:02:27 volumio volumio[18373]: info: CorePlayQueue::getTrack 0 Mar 18 04:02:27 volumio volumio[18373]: info: CoreCommandRouter::volumioPushState Mar 18 04:02:27 volumio volumio[18373]: info: Spotify config file written Mar 18 04:02:27 volumio volumio[18373]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 18 04:02:27 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:27 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:27 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:27 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:27 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:27 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:27 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:27 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:27 volumio sudo[18666]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 18 04:02:27 volumio sudo[18666]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:27 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:02:27 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:27 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:28 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:28 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:28 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:02:28 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:28 volumio volumio[18373]: info: No need to fix Spotify hosts Mar 18 04:02:28 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:28 volumio go-librespot[18676]: Librespot-go daemon starting... Mar 18 04:02:28 volumio sudo[18666]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:28 volumio go-librespot[18676]: time="2025-03-18T04:02:28+01:00" level=info msg="generated new device id: 138c7bf04c08469cd0b5290ec09e92ff99c90414" Mar 18 04:02:28 volumio volumio[18373]: info: VolumeController:: Volume=100 Mute =false Mar 18 04:02:28 volumio volumio[18373]: info: CoreStateMachine::pushState Mar 18 04:02:28 volumio volumio[18373]: info: CorePlayQueue::getTrack 0 Mar 18 04:02:28 volumio volumio[18373]: info: CoreCommandRouter::volumioPushState Mar 18 04:02:28 volumio go-librespot[18676]: time="2025-03-18T04:02:28+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:28 volumio volumio[18373]: info: [squeezelite_mc] Server discovery started Mar 18 04:02:28 volumio volumio[18373]: info: [squeezelite_mc] Player finder started Mar 18 04:02:28 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:28 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:28 volumio volumio[18373]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 18 04:02:28 volumio volumio[18373]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Mar 18 04:02:28 volumio volumio[18373]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 18 04:02:28 volumio volumio[18373]: Error: send ENETUNREACH 255.255.255.255:3483 Mar 18 04:02:28 volumio volumio[18373]: at doSend (dgram.js:692:16) Mar 18 04:02:28 volumio volumio[18373]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Mar 18 04:02:28 volumio volumio[18373]: at afterDns (dgram.js:638:5) Mar 18 04:02:28 volumio volumio[18373]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Mar 18 04:02:28 volumio volumio[18373]: errno: -101, Mar 18 04:02:28 volumio volumio[18373]: code: 'ENETUNREACH', Mar 18 04:02:28 volumio volumio[18373]: syscall: 'send', Mar 18 04:02:28 volumio volumio[18373]: address: '255.255.255.255', Mar 18 04:02:28 volumio volumio[18373]: port: 3483 Mar 18 04:02:28 volumio volumio[18373]: } Mar 18 04:02:28 volumio volumio[18373]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 18 04:02:28 volumio sudo[18647]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:29 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 18 04:02:29 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 18 04:02:29 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 18 04:02:29 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 18 04:02:29 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 18 04:02:29 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 18 04:02:29 volumio sudo[18697]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-18 04:01 Mar 18 04:02:29 volumio sudo[18697]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:29 volumio sudo[18697]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:29 volumio mpd[18628]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 18 04:02:29 volumio mpd[18628]: output: No 'audio_output' defined in config file Mar 18 04:02:29 volumio mpd[18628]: output: Successfully detected a sndio audio device Mar 18 04:02:29 volumio mpd[18628]: zeroconf: No global port, disabling zeroconf Mar 18 04:02:29 volumio systemd[1]: Started Music Player Daemon. Mar 18 04:02:29 volumio sudo[18598]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:29 volumio sudo[18604]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:29 volumio systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Mar 18 04:02:30 volumio volumio-remote-updater[567]: [2025-03-18 04:02:30] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 18 04:02:30 volumio volumio-remote-updater[567]: [2025-03-18 04:02:30] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 18 04:02:30 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:30 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 18 04:02:30 volumio systemd[1]: Started dynamicswap service. Mar 18 04:02:30 volumio systemd[1]: dynamicswap.service: Succeeded. Mar 18 04:02:30 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Mar 18 04:02:30 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 68. Mar 18 04:02:30 volumio systemd[1]: Started dynamicswap service. Mar 18 04:02:30 volumio systemd[1]: Stopped Volumio Backend Module. Mar 18 04:02:30 volumio systemd[1]: Started Volumio Backend Module. Mar 18 04:02:30 volumio systemd[1]: dynamicswap.service: Succeeded. Mar 18 04:02:30 volumio volumio[18705]: cset: --> shielding system active with Mar 18 04:02:30 volumio volumio[18705]: cset: "system" cpuset of CPUSPEC(1-3) with 55 tasks running Mar 18 04:02:30 volumio volumio[18705]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Mar 18 04:02:31 volumio systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Mar 18 04:02:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 18 04:02:31 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:31 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:31 volumio go-librespot[18740]: Librespot-go daemon starting... Mar 18 04:02:31 volumio go-librespot[18740]: time="2025-03-18T04:02:31+01:00" level=info msg="generated new device id: 87eb255e8dc2a4a1200e68cb7ea980ef5e69208c" Mar 18 04:02:31 volumio go-librespot[18740]: time="2025-03-18T04:02:31+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:33 volumio volumio[18724]: info: ------------------------------------------- Mar 18 04:02:33 volumio volumio[18724]: info: ----- Volumio3 ---- Mar 18 04:02:33 volumio volumio[18724]: info: ------------------------------------------- Mar 18 04:02:33 volumio volumio[18724]: info: ----- System startup ---- Mar 18 04:02:33 volumio volumio[18724]: info: ------------------------------------------- Mar 18 04:02:33 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 18 04:02:33 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 18 04:02:33 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 18 04:02:33 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 18 04:02:34 volumio volumio[18724]: info: MYVOLUMIO Environment detected Mar 18 04:02:34 volumio volumio[18724]: info: Plugin folders cleanup Mar 18 04:02:34 volumio volumio[18724]: info: Scanning into folder /volumio/app/plugins/ Mar 18 04:02:34 volumio volumio[18724]: info: Scanning category audio_interface Mar 18 04:02:34 volumio volumio[18724]: info: Scanning category miscellanea Mar 18 04:02:34 volumio volumio[18724]: info: Scanning category music_service Mar 18 04:02:34 volumio volumio[18724]: info: Scanning category plugins.json Mar 18 04:02:34 volumio volumio[18724]: info: Scanning category system_controller Mar 18 04:02:34 volumio volumio[18724]: info: Scanning category user_interface Mar 18 04:02:34 volumio volumio[18724]: info: Scanning into folder /data/plugins/ Mar 18 04:02:34 volumio volumio[18724]: info: Scanning category music_service Mar 18 04:02:34 volumio volumio[18724]: info: Scanning category system_controller Mar 18 04:02:34 volumio volumio[18724]: info: Scanning category system_hardware Mar 18 04:02:34 volumio volumio[18724]: info: Scanning category user_interface Mar 18 04:02:34 volumio volumio[18724]: info: Plugin folders cleanup completed Mar 18 04:02:34 volumio volumio[18724]: info: ------------------------------------------- Mar 18 04:02:34 volumio volumio[18724]: info: ----- Core plugins startup ---- Mar 18 04:02:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:34 volumio volumio[18724]: info: ------------------------------------------- Mar 18 04:02:34 volumio volumio[18724]: info: Loading plugins from folder /volumio/app/plugins/ Mar 18 04:02:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 18 04:02:34 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:34 volumio volumio[18724]: info: Adding plugin upnp to MyMusic Plugins Mar 18 04:02:34 volumio volumio[18724]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 18 04:02:34 volumio volumio[18724]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 18 04:02:34 volumio volumio[18724]: info: Loading plugins from folder /data/plugins/ Mar 18 04:02:34 volumio volumio[18724]: info: Loading plugin "system"... Mar 18 04:02:34 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:34 volumio go-librespot[18757]: Librespot-go daemon starting... Mar 18 04:02:34 volumio go-librespot[18757]: time="2025-03-18T04:02:34+01:00" level=info msg="generated new device id: fdd31eedb8625725db1d63604ed85e8ed2a2c1a7" Mar 18 04:02:34 volumio volumio[18724]: info: Loading plugin "appearance"... Mar 18 04:02:34 volumio go-librespot[18757]: time="2025-03-18T04:02:34+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:35 volumio volumio-remote-updater[567]: [2025-03-18 04:02:35] [connect] Successful connection Mar 18 04:02:35 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 18 04:02:35 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 18 04:02:35 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 18 04:02:35 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 18 04:02:35 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 18 04:02:35 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 18 04:02:35 volumio wpa_supplicant[872]: wlan0: Failed to initiate sched scan Mar 18 04:02:36 volumio volumio[18724]: info: Loading plugin "network"... Mar 18 04:02:36 volumio volumio[18724]: info: Refreshing Cached IP Addresses Mar 18 04:02:36 volumio sudo[18768]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 18 04:02:36 volumio sudo[18768]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:36 volumio sudo[18768]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:36 volumio sudo[18770]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 18 04:02:36 volumio sudo[18770]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:36 volumio sudo[18770]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:36 volumio volumio[18724]: info: Loading plugin "services"... Mar 18 04:02:36 volumio volumio[18724]: info: Loading plugin "alsa_controller"... Mar 18 04:02:36 volumio sudo[18779]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 18 04:02:36 volumio sudo[18779]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:36 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 18 04:02:36 volumio volumio[18724]: info: Loading plugin "wizard"... Mar 18 04:02:36 volumio volumio[18724]: info: Loading plugin "networkfs"... Mar 18 04:02:36 volumio volumio[18724]: info: Starting Udev Watcher for removable devices Mar 18 04:02:36 volumio sudo[18797]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto,vers=3 192.168.0.101:/volume1/Public/Music /mnt/NAS/NasTas Mar 18 04:02:36 volumio sudo[18797]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:36 volumio sudo[18801]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto,vers=3 192.168.0.101:/volume1/Public/Musik-Dieter /mnt/NAS/Music-Dieter Mar 18 04:02:36 volumio sudo[18801]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:36 volumio volumio[18724]: info: Ignoring mount for partition: boot Mar 18 04:02:36 volumio volumio[18724]: info: Ignoring mount for partition: volumio Mar 18 04:02:36 volumio volumio[18724]: info: Ignoring mount for partition: volumio_data Mar 18 04:02:36 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 18 04:02:36 volumio volumio[18724]: info: Loading plugin "volumio_command_line_client"... Mar 18 04:02:36 volumio volumio[18724]: info: Plugin upnp is not enabled Mar 18 04:02:36 volumio volumio[18724]: info: Loading plugin "my_music"... Mar 18 04:02:36 volumio volumio[18724]: info: Loading plugin "mpd"... Mar 18 04:02:37 volumio sudo[18797]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:37 volumio sudo[18801]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:37 volumio volumio[18724]: info: Plugin upnp_browser is not enabled Mar 18 04:02:37 volumio volumio[18724]: info: Loading plugin "alarm-clock"... Mar 18 04:02:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 18 04:02:37 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:37 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:37 volumio go-librespot[18806]: Librespot-go daemon starting... Mar 18 04:02:37 volumio go-librespot[18806]: time="2025-03-18T04:02:37+01:00" level=info msg="generated new device id: 2a0b11bdbc3832e5d7602d6f31dc899e1de4b62b" Mar 18 04:02:37 volumio go-librespot[18806]: time="2025-03-18T04:02:37+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:37 volumio volumio[18724]: info: Plugin airplay_emulation is not enabled Mar 18 04:02:37 volumio volumio[18724]: info: Loading plugin "last_100"... Mar 18 04:02:37 volumio volumio[18724]: info: Loading plugin "webradio"... Mar 18 04:02:38 volumio volumio[18724]: info: Loading plugin "i2s_dacs"... Mar 18 04:02:38 volumio volumio[18724]: info: Loading plugin "volumiodiscovery"... Mar 18 04:02:38 volumio volumio[18724]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 18 04:02:38 volumio volumio[18724]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 18 04:02:38 volumio volumio[18724]: *** WARNING *** For more information see Mar 18 04:02:38 volumio node[18724]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 18 04:02:38 volumio volumio[18724]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 18 04:02:38 volumio volumio[18724]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 18 04:02:38 volumio volumio[18724]: *** WARNING *** For more information see Mar 18 04:02:38 volumio node[18724]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 18 04:02:38 volumio node[18724]: *** WARNING *** For more information see Mar 18 04:02:38 volumio node[18724]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 18 04:02:38 volumio node[18724]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 18 04:02:38 volumio node[18724]: *** WARNING *** For more information see Mar 18 04:02:38 volumio volumio[18724]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 18 04:02:38 volumio volumio[18724]: info: Discovery: Started advertising with name: Volumio Mar 18 04:02:38 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 18 04:02:38 volumio volumio[18724]: info: Loading plugin "soundcloud"... Mar 18 04:02:39 volumio volumio[18724]: info: Loading plugin "spop"... Mar 18 04:02:39 volumio sudo[18779]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:40 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 18 04:02:40 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 18 04:02:40 volumio volumio[18724]: info: Loading plugin "squeezelite_mc"... Mar 18 04:02:40 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 18 04:02:40 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 18 04:02:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 18 04:02:41 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:41 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:41 volumio go-librespot[18815]: Librespot-go daemon starting... Mar 18 04:02:41 volumio go-librespot[18815]: time="2025-03-18T04:02:41+01:00" level=info msg="generated new device id: 856db9502423c790df5724d5bf1d9eff9e93723a" Mar 18 04:02:41 volumio go-librespot[18815]: time="2025-03-18T04:02:41+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:41 volumio volumio[18724]: info: Loading plugin "outputs"... Mar 18 04:02:41 volumio volumio[18724]: info: Loading plugin "albumart"... Mar 18 04:02:41 volumio volumio[18724]: info: Plugin example_plugin is not enabled Mar 18 04:02:41 volumio volumio[18724]: info: Loading plugin "inputs"... Mar 18 04:02:41 volumio volumio[18724]: info: Loading plugin "updater_comm"... Mar 18 04:02:42 volumio volumio[18724]: info: Plugin mpdemulation is not enabled Mar 18 04:02:42 volumio volumio[18724]: info: Loading plugin "rest_api"... Mar 18 04:02:42 volumio volumio[18724]: info: Loading plugin "websocket"... Mar 18 04:02:42 volumio volumio[18724]: info: Starting Socket.io Server version 2.3.0 Mar 18 04:02:42 volumio volumio[18724]: info: Loading plugin "radio_paradise"... Mar 18 04:02:42 volumio volumio[18724]: Forking 3 albumart workers Mar 18 04:02:42 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 18 04:02:42 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 18 04:02:42 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 18 04:02:42 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 18 04:02:42 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 18 04:02:42 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 18 04:02:42 volumio volumio[18724]: info: Applying required configuration parameters for plugin radio_paradise Mar 18 04:02:42 volumio volumio[18724]: info: [1742266962905] [RadioParadise] API delay: 3 Mar 18 04:02:42 volumio volumio[18724]: info: Loading plugin "backup_restore"... Mar 18 04:02:43 volumio autossh[9021]: starting ssh (count 18) Mar 18 04:02:43 volumio autossh[9021]: ssh child pid is 18850 Mar 18 04:02:43 volumio volumiossh-tunnel[9020]: ssh: Could not resolve hostname eu7.myvolumio.org: Device or resource busy Mar 18 04:02:43 volumio autossh[9021]: ssh exited with error status 255; restarting ssh Mar 18 04:02:43 volumio volumio[18724]: info: Applying required configuration parameters for plugin backup_restore Mar 18 04:02:43 volumio volumio[18724]: info: Loading plugin "music_services_shield"... Mar 18 04:02:44 volumio volumio[18724]: info: Applying required configuration parameters for plugin music_services_shield Mar 18 04:02:44 volumio volumio[18724]: info: Loading plugin "Systeminfo"... Mar 18 04:02:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 18 04:02:44 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:44 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:44 volumio go-librespot[18851]: Librespot-go daemon starting... Mar 18 04:02:44 volumio go-librespot[18851]: time="2025-03-18T04:02:44+01:00" level=info msg="generated new device id: f10a9307e2b9b92b6554782687ade02640530d2a" Mar 18 04:02:44 volumio go-librespot[18851]: time="2025-03-18T04:02:44+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:44 volumio volumio[18724]: info: Loading i18n strings for locale en Mar 18 04:02:44 volumio volumio[18724]: Starting albumart workers Mar 18 04:02:44 volumio volumio[18724]: Updating browse sources language Mar 18 04:02:44 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:02:44 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 18 04:02:44 volumio volumio[18724]: info: CoreCommandRouter::initPlayerControls Mar 18 04:02:44 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:44 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:44 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:44 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:44 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:44 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:44 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:44 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:44 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 18 04:02:44 volumio volumio[18724]: Express server listening on port 3000 Mar 18 04:02:44 volumio volumio[18724]: [Metrics] WebUI: 12s 204.14ms Mar 18 04:02:44 volumio volumio[18724]: info: CoreStateMachine::resetVolumioState Mar 18 04:02:44 volumio volumio[18724]: info: CoreStateMachine::getcurrentVolume Mar 18 04:02:44 volumio volumio[18724]: info: CoreCommandRouter::volumioRetrievevolume Mar 18 04:02:45 volumio volumio[18724]: info: Volumio Network Manager: Network status updated: 0 Mar 18 04:02:45 volumio volumio[18724]: info: Cannot mount NAS Music-Dieter at system boot, trial number 1 ,retrying in 5 seconds Mar 18 04:02:45 volumio volumio[18724]: info: Cannot mount NAS NasTas at system boot, trial number 1 ,retrying in 5 seconds Mar 18 04:02:45 volumio volumio[18724]: Starting albumart workers Mar 18 04:02:45 volumio volumio[18724]: Starting albumart workers Mar 18 04:02:45 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:02:45 volumio volumio[18724]: info: Reloading queue from file Mar 18 04:02:45 volumio volumio[18724]: info: CoreStateMachine::setRepeat null single undefined Mar 18 04:02:45 volumio volumio[18724]: info: CoreStateMachine::pushState Mar 18 04:02:45 volumio volumio[18724]: info: CorePlayQueue::getTrack 0 Mar 18 04:02:45 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 18 04:02:45 volumio volumio[18724]: info: CoreCommandRouter::volumioPushState Mar 18 04:02:45 volumio volumio[18724]: info: CoreStateMachine::setRandom false Mar 18 04:02:45 volumio volumio[18724]: info: CoreStateMachine::pushState Mar 18 04:02:45 volumio volumio[18724]: info: CorePlayQueue::getTrack 0 Mar 18 04:02:45 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 18 04:02:45 volumio volumio[18724]: info: CoreCommandRouter::volumioPushState Mar 18 04:02:45 volumio volumio[18724]: info: Setting Device type: Raspberry PI Mar 18 04:02:45 volumio volumio[18724]: info: VolumeController:: Volume=100 Mute =false Mar 18 04:02:45 volumio volumio[18724]: info: CoreStateMachine::pushState Mar 18 04:02:45 volumio volumio[18724]: info: CorePlayQueue::getTrack 0 Mar 18 04:02:45 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 18 04:02:45 volumio volumio[18724]: info: CoreCommandRouter::volumioPushState Mar 18 04:02:45 volumio volumio[18724]: info: CoreStateMachine::updateTrackBlock Mar 18 04:02:45 volumio volumio[18724]: info: CorePlayQueue::getTrackBlock Mar 18 04:02:45 volumio volumio[18724]: info: CoreCommandRouter::volumioRetrievevolume Mar 18 04:02:45 volumio volumio[18724]: info: Completed loading Core Plugins Mar 18 04:02:45 volumio volumio[18724]: info: Preparing to generate the ALSA configuration file Mar 18 04:02:45 volumio volumio[18724]: info: Asound.conf file unchanged, so no further update is needed Mar 18 04:02:45 volumio volumio[18724]: info: Output device has changed, restarting MPD Mar 18 04:02:46 volumio volumio[18724]: info: ___________ START PLUGINS ___________ Mar 18 04:02:46 volumio volumio[18724]: info: ControllerMpd::onStart: Initializing MPD Mar 18 04:02:46 volumio volumio[18724]: info: Creating MPD Configuration file Mar 18 04:02:46 volumio sudo[18878]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 18 04:02:46 volumio sudo[18878]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:46 volumio sudo[18880]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 18 04:02:46 volumio sudo[18880]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:46 volumio sudo[18878]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:46 volumio volumio[18724]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:02:46 volumio volumio[18724]: info: [1742266966179] CoreMusicLibrary::Adding element Last_100 Mar 18 04:02:46 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:02:46 volumio sudo[18882]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 18 04:02:46 volumio volumio[18724]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:02:46 volumio volumio[18724]: info: [1742266966192] CoreMusicLibrary::Adding element Webradio Mar 18 04:02:46 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:02:46 volumio sudo[18882]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:46 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 18 04:02:46 volumio volumio[18724]: info: Initializing BBC Radios Mar 18 04:02:46 volumio systemd[1]: musicservicesshield.service: Succeeded. Mar 18 04:02:46 volumio sudo[18882]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:46 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Mar 18 04:02:46 volumio systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Mar 18 04:02:46 volumio systemd[1]: Stopping Music Player Daemon... Mar 18 04:02:46 volumio systemd[1]: mpd.service: Succeeded. Mar 18 04:02:46 volumio systemd[1]: Stopped Music Player Daemon. Mar 18 04:02:46 volumio sudo[18886]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 18 04:02:46 volumio sudo[18886]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:46 volumio systemd[1]: Starting Music Player Daemon... Mar 18 04:02:46 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Mar 18 04:02:46 volumio systemd[1]: mpd.service: Succeeded. Mar 18 04:02:46 volumio systemd[1]: Stopped Music Player Daemon. Mar 18 04:02:46 volumio systemd[1]: Starting Music Player Daemon... Mar 18 04:02:46 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 18 04:02:46 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:02:46 volumio volumio[18724]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:02:46 volumio volumio[18724]: info: [1742266966594] CoreMusicLibrary::Adding element SoundCloud Mar 18 04:02:46 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:02:46 volumio volumio[18724]: Cannot find translation for source SoundCloud Mar 18 04:02:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 18 04:02:46 volumio volumio[18724]: info: Creating Spotify config file Mar 18 04:02:46 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:46 volumio sudo[18896]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 18 04:02:46 volumio sudo[18896]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:46 volumio sudo[18896]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 18 04:02:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 18 04:02:46 volumio volumio[18724]: info: [squeezelite_mc] Starting proxy server... Mar 18 04:02:46 volumio volumio[18724]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:02:46 volumio volumio[18724]: info: [1742266966902] CoreMusicLibrary::Adding element Radio Paradise Mar 18 04:02:46 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:02:46 volumio volumio[18724]: Cannot find translation for source SoundCloud Mar 18 04:02:46 volumio volumio[18724]: Cannot find translation for source Radio Paradise Mar 18 04:02:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 18 04:02:47 volumio volumio[18724]: info: Volumio Calling Home Mar 18 04:02:47 volumio volumio-remote-updater[567]: [2025-03-18 04:02:47] [connect] Successful connection Mar 18 04:02:47 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 18 04:02:47 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:47 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:47 volumio go-librespot[18962]: Librespot-go daemon starting... Mar 18 04:02:47 volumio go-librespot[18962]: time="2025-03-18T04:02:47+01:00" level=info msg="generated new device id: c619fe2a934aeda86cb40dadced36bbfd21eb90c" Mar 18 04:02:47 volumio go-librespot[18962]: time="2025-03-18T04:02:47+01:00" level=fatal msg="unknown credentials: " Mar 18 04:02:47 volumio volumio[18724]: info: [squeezelite_mc] Proxy server started on port 33307 Mar 18 04:02:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:47 volumio sudo[18959]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Mar 18 04:02:47 volumio sudo[18959]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:47 volumio volumio[18724]: info: CoreCommandRouter::volumioRetrievevolume Mar 18 04:02:48 volumio volumio[18724]: info: MPD Permissions set Mar 18 04:02:48 volumio volumio[18724]: info: MPD Permissions set Mar 18 04:02:48 volumio volumio[18724]: info: VolumeController:: Volume=100 Mute =false Mar 18 04:02:48 volumio volumio[18724]: info: CoreStateMachine::pushState Mar 18 04:02:48 volumio volumio[18724]: info: CorePlayQueue::getTrack 0 Mar 18 04:02:48 volumio volumio[18724]: info: CoreCommandRouter::volumioPushState Mar 18 04:02:48 volumio volumio-remote-updater[567]: [2025-03-18 04:02:48] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1742266967 101 Mar 18 04:02:48 volumio volumio[18724]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Mar 18 04:02:48 volumio volumio[18724]: info: Spotify config file written Mar 18 04:02:48 volumio volumio[18724]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 18 04:02:48 volumio sudo[18985]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 18 04:02:48 volumio sudo[18985]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:48 volumio volumio[18724]: info: VolumeController:: Volume=100 Mute =false Mar 18 04:02:48 volumio volumio[18724]: info: CoreStateMachine::pushState Mar 18 04:02:48 volumio volumio[18724]: info: CorePlayQueue::getTrack 0 Mar 18 04:02:48 volumio volumio[18724]: info: CoreCommandRouter::volumioPushState Mar 18 04:02:48 volumio volumio[18724]: info: [squeezelite_mc] Server discovery started Mar 18 04:02:48 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:48 volumio volumio[18724]: info: [squeezelite_mc] Player finder started Mar 18 04:02:48 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:48 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:48 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:02:48 volumio volumio[18724]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 18 04:02:48 volumio volumio[18724]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Mar 18 04:02:48 volumio volumio[18724]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 18 04:02:48 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:48 volumio go-librespot[18988]: Librespot-go daemon starting... Mar 18 04:02:48 volumio volumio[18724]: Error: send ENETUNREACH 255.255.255.255:3483 Mar 18 04:02:48 volumio volumio[18724]: at doSend (dgram.js:692:16) Mar 18 04:02:48 volumio volumio[18724]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Mar 18 04:02:48 volumio volumio[18724]: at afterDns (dgram.js:638:5) Mar 18 04:02:48 volumio volumio[18724]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Mar 18 04:02:48 volumio volumio[18724]: errno: -101, Mar 18 04:02:48 volumio volumio[18724]: code: 'ENETUNREACH', Mar 18 04:02:48 volumio volumio[18724]: syscall: 'send', Mar 18 04:02:48 volumio volumio[18724]: address: '255.255.255.255', Mar 18 04:02:48 volumio volumio[18724]: port: 3483 Mar 18 04:02:48 volumio volumio[18724]: } Mar 18 04:02:48 volumio volumio[18724]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 18 04:02:48 volumio sudo[18985]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:48 volumio go-librespot[18988]: time="2025-03-18T04:02:48+01:00" level=info msg="generated new device id: ee79829d840ea265e975d491eb864ffa92e19013" Mar 18 04:02:48 volumio go-librespot[18988]: time="2025-03-18T04:02:48+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:48 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 18 04:02:48 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 18 04:02:48 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 18 04:02:48 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 18 04:02:48 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 18 04:02:48 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 18 04:02:48 volumio wpa_supplicant[872]: wlan0: Failed to initiate sched scan Mar 18 04:02:48 volumio sudo[18959]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:49 volumio sudo[19008]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-18 04:01 Mar 18 04:02:49 volumio sudo[19008]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:49 volumio mpd[18912]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 18 04:02:49 volumio mpd[18912]: output: No 'audio_output' defined in config file Mar 18 04:02:49 volumio mpd[18912]: output: Successfully detected a sndio audio device Mar 18 04:02:49 volumio mpd[18912]: zeroconf: No global port, disabling zeroconf Mar 18 04:02:49 volumio systemd[1]: Started Music Player Daemon. Mar 18 04:02:49 volumio sudo[18886]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:49 volumio sudo[18880]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:49 volumio systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Mar 18 04:02:50 volumio sudo[19008]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:50 volumio volumio-remote-updater[567]: [2025-03-18 04:02:50] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 18 04:02:50 volumio volumio-remote-updater[567]: [2025-03-18 04:02:50] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 18 04:02:50 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:50 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 18 04:02:50 volumio systemd[1]: Started dynamicswap service. Mar 18 04:02:50 volumio systemd[1]: dynamicswap.service: Succeeded. Mar 18 04:02:50 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Mar 18 04:02:50 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 69. Mar 18 04:02:50 volumio systemd[1]: Started dynamicswap service. Mar 18 04:02:50 volumio systemd[1]: Stopped Volumio Backend Module. Mar 18 04:02:50 volumio systemd[1]: Started Volumio Backend Module. Mar 18 04:02:50 volumio systemd[1]: dynamicswap.service: Succeeded. Mar 18 04:02:51 volumio volumio[19012]: cset: --> shielding system active with Mar 18 04:02:51 volumio volumio[19012]: cset: "system" cpuset of CPUSPEC(1-3) with 55 tasks running Mar 18 04:02:51 volumio volumio[19012]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Mar 18 04:02:51 volumio systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Mar 18 04:02:51 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 18 04:02:51 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:51 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:51 volumio go-librespot[19051]: Librespot-go daemon starting... Mar 18 04:02:51 volumio go-librespot[19051]: time="2025-03-18T04:02:51+01:00" level=info msg="generated new device id: f351dffac422fbff731925d1f28af7624bfc32e4" Mar 18 04:02:51 volumio go-librespot[19051]: time="2025-03-18T04:02:51+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:52 volumio volumio[19036]: info: ------------------------------------------- Mar 18 04:02:52 volumio volumio[19036]: info: ----- Volumio3 ---- Mar 18 04:02:52 volumio volumio[19036]: info: ------------------------------------------- Mar 18 04:02:52 volumio volumio[19036]: info: ----- System startup ---- Mar 18 04:02:52 volumio volumio[19036]: info: ------------------------------------------- Mar 18 04:02:53 volumio volumio[19036]: info: MYVOLUMIO Environment detected Mar 18 04:02:53 volumio volumio[19036]: info: Plugin folders cleanup Mar 18 04:02:53 volumio volumio[19036]: info: Scanning into folder /volumio/app/plugins/ Mar 18 04:02:53 volumio volumio[19036]: info: Scanning category audio_interface Mar 18 04:02:53 volumio volumio[19036]: info: Scanning category miscellanea Mar 18 04:02:53 volumio volumio[19036]: info: Scanning category music_service Mar 18 04:02:53 volumio volumio[19036]: info: Scanning category plugins.json Mar 18 04:02:53 volumio volumio[19036]: info: Scanning category system_controller Mar 18 04:02:53 volumio volumio[19036]: info: Scanning category user_interface Mar 18 04:02:53 volumio volumio[19036]: info: Scanning into folder /data/plugins/ Mar 18 04:02:53 volumio volumio[19036]: info: Scanning category music_service Mar 18 04:02:53 volumio volumio[19036]: info: Scanning category system_controller Mar 18 04:02:53 volumio volumio[19036]: info: Scanning category system_hardware Mar 18 04:02:53 volumio volumio[19036]: info: Scanning category user_interface Mar 18 04:02:53 volumio volumio[19036]: info: Plugin folders cleanup completed Mar 18 04:02:53 volumio volumio[19036]: info: ------------------------------------------- Mar 18 04:02:53 volumio volumio[19036]: info: ----- Core plugins startup ---- Mar 18 04:02:53 volumio volumio[19036]: info: ------------------------------------------- Mar 18 04:02:53 volumio volumio[19036]: info: Loading plugins from folder /volumio/app/plugins/ Mar 18 04:02:53 volumio volumio[19036]: info: Adding plugin upnp to MyMusic Plugins Mar 18 04:02:53 volumio volumio[19036]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 18 04:02:53 volumio volumio[19036]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 18 04:02:53 volumio volumio[19036]: info: Loading plugins from folder /data/plugins/ Mar 18 04:02:53 volumio volumio[19036]: info: Loading plugin "system"... Mar 18 04:02:53 volumio volumio[19036]: info: Loading plugin "appearance"... Mar 18 04:02:54 volumio volumio[19036]: info: Loading plugin "network"... Mar 18 04:02:54 volumio volumio[19036]: info: Refreshing Cached IP Addresses Mar 18 04:02:54 volumio sudo[19072]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 18 04:02:54 volumio sudo[19072]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:54 volumio sudo[19072]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:54 volumio sudo[19074]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 18 04:02:54 volumio sudo[19074]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:54 volumio sudo[19074]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:54 volumio volumio[19036]: info: Loading plugin "services"... Mar 18 04:02:54 volumio volumio[19036]: info: Loading plugin "alsa_controller"... Mar 18 04:02:54 volumio sudo[19083]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 18 04:02:54 volumio sudo[19083]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:54 volumio sudo[19083]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:54 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 18 04:02:54 volumio volumio[19036]: info: Loading plugin "wizard"... Mar 18 04:02:54 volumio volumio[19036]: info: Loading plugin "networkfs"... Mar 18 04:02:54 volumio volumio[19036]: info: Starting Udev Watcher for removable devices Mar 18 04:02:54 volumio sudo[19100]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto,vers=3 192.168.0.101:/volume1/Public/Music /mnt/NAS/NasTas Mar 18 04:02:54 volumio sudo[19100]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:54 volumio sudo[19102]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto,vers=3 192.168.0.101:/volume1/Public/Musik-Dieter /mnt/NAS/Music-Dieter Mar 18 04:02:54 volumio sudo[19102]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:02:54 volumio volumio[19036]: info: Ignoring mount for partition: boot Mar 18 04:02:54 volumio volumio[19036]: info: Ignoring mount for partition: volumio Mar 18 04:02:54 volumio volumio[19036]: info: Ignoring mount for partition: volumio_data Mar 18 04:02:54 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 18 04:02:54 volumio volumio[19036]: info: Loading plugin "volumio_command_line_client"... Mar 18 04:02:54 volumio volumio[19036]: info: Plugin upnp is not enabled Mar 18 04:02:54 volumio volumio[19036]: info: Loading plugin "my_music"... Mar 18 04:02:54 volumio volumio[19036]: info: Loading plugin "mpd"... Mar 18 04:02:55 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 18 04:02:55 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:55 volumio sudo[19100]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:55 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:55 volumio go-librespot[19107]: Librespot-go daemon starting... Mar 18 04:02:55 volumio sudo[19102]: pam_unix(sudo:session): session closed for user root Mar 18 04:02:55 volumio go-librespot[19107]: time="2025-03-18T04:02:55+01:00" level=info msg="generated new device id: 6a2260dd0fe6cad00c65bea9e93081e27eef7037" Mar 18 04:02:55 volumio go-librespot[19107]: time="2025-03-18T04:02:55+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:55 volumio volumio-remote-updater[567]: [2025-03-18 04:02:55] [connect] Successful connection Mar 18 04:02:55 volumio volumio[19036]: info: Plugin upnp_browser is not enabled Mar 18 04:02:55 volumio volumio[19036]: info: Loading plugin "alarm-clock"... Mar 18 04:02:55 volumio volumio[19036]: info: Plugin airplay_emulation is not enabled Mar 18 04:02:55 volumio volumio[19036]: info: Loading plugin "last_100"... Mar 18 04:02:55 volumio volumio[19036]: info: Loading plugin "webradio"... Mar 18 04:02:56 volumio volumio[19036]: info: Loading plugin "i2s_dacs"... Mar 18 04:02:56 volumio volumio[19036]: info: Loading plugin "volumiodiscovery"... Mar 18 04:02:56 volumio volumio[19036]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 18 04:02:56 volumio volumio[19036]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 18 04:02:56 volumio volumio[19036]: *** WARNING *** For more information see Mar 18 04:02:56 volumio node[19036]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 18 04:02:56 volumio volumio[19036]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 18 04:02:56 volumio volumio[19036]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 18 04:02:56 volumio volumio[19036]: *** WARNING *** For more information see Mar 18 04:02:56 volumio node[19036]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 18 04:02:56 volumio node[19036]: *** WARNING *** For more information see Mar 18 04:02:56 volumio node[19036]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 18 04:02:56 volumio node[19036]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 18 04:02:56 volumio node[19036]: *** WARNING *** For more information see Mar 18 04:02:56 volumio volumio[19036]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 18 04:02:56 volumio volumio[19036]: info: Discovery: Started advertising with name: Volumio Mar 18 04:02:56 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 18 04:02:56 volumio volumio[19036]: info: Loading plugin "soundcloud"... Mar 18 04:02:57 volumio volumio[19036]: info: Loading plugin "spop"... Mar 18 04:02:57 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 18 04:02:57 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 18 04:02:58 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 18 04:02:58 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 18 04:02:58 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:02:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 18 04:02:58 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:02:58 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:02:58 volumio go-librespot[19119]: Librespot-go daemon starting... Mar 18 04:02:58 volumio go-librespot[19119]: time="2025-03-18T04:02:58+01:00" level=info msg="generated new device id: 24af9b3daae7e4be110088f9604290ad97b001a5" Mar 18 04:02:58 volumio go-librespot[19119]: time="2025-03-18T04:02:58+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:02:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:02:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:02:58 volumio volumio[19036]: info: Loading plugin "squeezelite_mc"... Mar 18 04:02:59 volumio volumio[19036]: info: Loading plugin "outputs"... Mar 18 04:02:59 volumio volumio[19036]: info: Loading plugin "albumart"... Mar 18 04:02:59 volumio volumio[19036]: info: Plugin example_plugin is not enabled Mar 18 04:02:59 volumio volumio[19036]: info: Loading plugin "inputs"... Mar 18 04:02:59 volumio volumio[19036]: info: Loading plugin "updater_comm"... Mar 18 04:02:59 volumio volumio[19036]: info: Plugin mpdemulation is not enabled Mar 18 04:02:59 volumio volumio[19036]: info: Loading plugin "rest_api"... Mar 18 04:02:59 volumio volumio[19036]: info: Loading plugin "websocket"... Mar 18 04:02:59 volumio volumio[19036]: info: Starting Socket.io Server version 2.3.0 Mar 18 04:02:59 volumio volumio[19036]: info: Loading plugin "radio_paradise"... Mar 18 04:02:59 volumio volumio[19036]: Forking 3 albumart workers Mar 18 04:02:59 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 18 04:02:59 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 18 04:02:59 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 18 04:02:59 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 18 04:02:59 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 18 04:02:59 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 18 04:02:59 volumio wpa_supplicant[872]: wlan0: Failed to initiate sched scan Mar 18 04:03:00 volumio volumio[19036]: info: Applying required configuration parameters for plugin radio_paradise Mar 18 04:03:00 volumio volumio[19036]: info: [1742266980013] [RadioParadise] API delay: 3 Mar 18 04:03:00 volumio volumio[19036]: info: Loading plugin "backup_restore"... Mar 18 04:03:00 volumio volumio[19036]: info: Applying required configuration parameters for plugin backup_restore Mar 18 04:03:00 volumio volumio[19036]: info: Loading plugin "music_services_shield"... Mar 18 04:03:01 volumio volumio[19036]: info: Applying required configuration parameters for plugin music_services_shield Mar 18 04:03:01 volumio volumio[19036]: info: Loading plugin "Systeminfo"... Mar 18 04:03:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:03:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 18 04:03:01 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:03:01 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:03:01 volumio go-librespot[19154]: Librespot-go daemon starting... Mar 18 04:03:01 volumio go-librespot[19154]: time="2025-03-18T04:03:01+01:00" level=info msg="generated new device id: 79b4c3dda41ecf36e2caaa259ee78a44e6f67724" Mar 18 04:03:01 volumio go-librespot[19154]: time="2025-03-18T04:03:01+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:03:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:03:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:03:01 volumio volumio[19036]: Starting albumart workers Mar 18 04:03:01 volumio volumio[19036]: Starting albumart workers Mar 18 04:03:02 volumio volumio[19036]: Starting albumart workers Mar 18 04:03:02 volumio volumio[19036]: info: Loading i18n strings for locale en Mar 18 04:03:02 volumio volumio[19036]: Updating browse sources language Mar 18 04:03:02 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:03:02 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 18 04:03:02 volumio volumio[19036]: info: CoreCommandRouter::initPlayerControls Mar 18 04:03:02 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:02 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:02 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:02 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:02 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:02 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:02 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:02 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:02 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 18 04:03:02 volumio volumio[19036]: Express server listening on port 3000 Mar 18 04:03:02 volumio volumio[19036]: [Metrics] WebUI: 10s 690.24ms Mar 18 04:03:02 volumio volumio[19036]: info: CoreStateMachine::resetVolumioState Mar 18 04:03:02 volumio volumio[19036]: info: CoreStateMachine::getcurrentVolume Mar 18 04:03:02 volumio volumio[19036]: info: CoreCommandRouter::volumioRetrievevolume Mar 18 04:03:02 volumio volumio[19036]: info: Volumio Network Manager: Network status updated: 0 Mar 18 04:03:02 volumio volumio[19036]: info: Cannot mount NAS Music-Dieter at system boot, trial number 1 ,retrying in 5 seconds Mar 18 04:03:02 volumio volumio[19036]: info: Cannot mount NAS NasTas at system boot, trial number 1 ,retrying in 5 seconds Mar 18 04:03:02 volumio volumio[19036]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Mar 18 04:03:02 volumio volumio[19036]: wlan0 Interface doesn't support scanning : Device or resource busy Mar 18 04:03:02 volumio volumio[19036]: info: Cannot use regular scanning, forcing with ap-force Mar 18 04:03:03 volumio sudo[19174]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Mar 18 04:03:03 volumio sudo[19174]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:04 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:03:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 18 04:03:04 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:03:04 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:03:04 volumio go-librespot[19206]: Librespot-go daemon starting... Mar 18 04:03:04 volumio go-librespot[19206]: time="2025-03-18T04:03:04+01:00" level=info msg="generated new device id: a7a9e01e356673659b48621d0074852c86d02687" Mar 18 04:03:04 volumio go-librespot[19206]: time="2025-03-18T04:03:04+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:03:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:03:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:03:05 volumio kernel: hwmon hwmon1: Voltage normalised Mar 18 04:03:05 volumio sudo[19174]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:05 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:03:05 volumio volumio[19036]: info: Reloading queue from file Mar 18 04:03:05 volumio volumio[19036]: info: CoreStateMachine::setRepeat null single undefined Mar 18 04:03:05 volumio volumio[19036]: info: CoreStateMachine::pushState Mar 18 04:03:05 volumio volumio[19036]: info: CorePlayQueue::getTrack 0 Mar 18 04:03:05 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 18 04:03:05 volumio volumio[19036]: info: CoreCommandRouter::volumioPushState Mar 18 04:03:05 volumio volumio[19036]: info: CoreStateMachine::setRandom false Mar 18 04:03:05 volumio volumio[19036]: info: CoreStateMachine::pushState Mar 18 04:03:05 volumio volumio[19036]: info: CorePlayQueue::getTrack 0 Mar 18 04:03:05 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 18 04:03:05 volumio volumio[19036]: info: CoreCommandRouter::volumioPushState Mar 18 04:03:05 volumio volumio[19036]: info: Setting Device type: Raspberry PI Mar 18 04:03:05 volumio volumio[19036]: info: VolumeController:: Volume=100 Mute =false Mar 18 04:03:05 volumio volumio[19036]: info: CoreStateMachine::pushState Mar 18 04:03:05 volumio volumio[19036]: info: CorePlayQueue::getTrack 0 Mar 18 04:03:05 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 18 04:03:05 volumio volumio[19036]: info: CoreCommandRouter::volumioPushState Mar 18 04:03:05 volumio volumio[19036]: info: CoreStateMachine::updateTrackBlock Mar 18 04:03:05 volumio volumio[19036]: info: CorePlayQueue::getTrackBlock Mar 18 04:03:05 volumio volumio[19036]: info: CoreCommandRouter::volumioRetrievevolume Mar 18 04:03:05 volumio volumio[19036]: info: Completed loading Core Plugins Mar 18 04:03:05 volumio volumio[19036]: info: Preparing to generate the ALSA configuration file Mar 18 04:03:05 volumio volumio[19036]: info: Asound.conf file unchanged, so no further update is needed Mar 18 04:03:05 volumio volumio[19036]: info: Output device has changed, restarting MPD Mar 18 04:03:05 volumio sudo[19222]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 18 04:03:05 volumio sudo[19222]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:05 volumio volumio[19036]: info: ___________ START PLUGINS ___________ Mar 18 04:03:05 volumio sudo[19222]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:05 volumio volumio[19036]: info: ControllerMpd::onStart: Initializing MPD Mar 18 04:03:05 volumio volumio[19036]: info: Creating MPD Configuration file Mar 18 04:03:05 volumio sudo[19224]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 18 04:03:05 volumio sudo[19224]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:05 volumio systemd[1]: musicservicesshield.service: Succeeded. Mar 18 04:03:05 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Mar 18 04:03:05 volumio systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Mar 18 04:03:05 volumio systemd[1]: Stopping Music Player Daemon... Mar 18 04:03:05 volumio sudo[19228]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 18 04:03:05 volumio sudo[19228]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:05 volumio volumio[19036]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:03:05 volumio volumio[19036]: info: [1742266985949] CoreMusicLibrary::Adding element Last_100 Mar 18 04:03:05 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:03:05 volumio sudo[19228]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:05 volumio volumio[19036]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:03:05 volumio volumio[19036]: info: [1742266985955] CoreMusicLibrary::Adding element Webradio Mar 18 04:03:05 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:03:05 volumio systemd[1]: mpd.service: Succeeded. Mar 18 04:03:05 volumio systemd[1]: Stopped Music Player Daemon. Mar 18 04:03:05 volumio sudo[19230]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 18 04:03:05 volumio sudo[19230]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:05 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 18 04:03:05 volumio volumio[19036]: info: Initializing BBC Radios Mar 18 04:03:06 volumio systemd[1]: Starting Music Player Daemon... Mar 18 04:03:06 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Mar 18 04:03:06 volumio systemd[1]: mpd.service: Succeeded. Mar 18 04:03:06 volumio systemd[1]: Stopped Music Player Daemon. Mar 18 04:03:06 volumio systemd[1]: Starting Music Player Daemon... Mar 18 04:03:06 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 18 04:03:06 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:03:06 volumio volumio[19036]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:03:06 volumio volumio[19036]: info: [1742266986133] CoreMusicLibrary::Adding element SoundCloud Mar 18 04:03:06 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:03:06 volumio volumio[19036]: Cannot find translation for source SoundCloud Mar 18 04:03:06 volumio volumio[19036]: info: Creating Spotify config file Mar 18 04:03:06 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:06 volumio volumio[19036]: info: [squeezelite_mc] Starting proxy server... Mar 18 04:03:06 volumio volumio[19036]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:03:06 volumio volumio[19036]: info: [1742266986218] CoreMusicLibrary::Adding element Radio Paradise Mar 18 04:03:06 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:03:06 volumio volumio[19036]: Cannot find translation for source SoundCloud Mar 18 04:03:06 volumio volumio[19036]: Cannot find translation for source Radio Paradise Mar 18 04:03:06 volumio sudo[19240]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 18 04:03:06 volumio sudo[19240]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:06 volumio sudo[19240]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:06 volumio volumio[19036]: info: Volumio Calling Home Mar 18 04:03:06 volumio sudo[19273]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Mar 18 04:03:06 volumio sudo[19273]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:06 volumio volumio[19036]: info: [squeezelite_mc] Proxy server started on port 39001 Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::volumioRetrievevolume Mar 18 04:03:07 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 18 04:03:07 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 18 04:03:07 volumio volumio[19036]: info: MPD Permissions set Mar 18 04:03:07 volumio volumio[19036]: info: MPD Permissions set Mar 18 04:03:07 volumio volumio[19036]: info: VolumeController:: Volume=100 Mute =false Mar 18 04:03:07 volumio volumio[19036]: info: CoreStateMachine::pushState Mar 18 04:03:07 volumio volumio[19036]: info: CorePlayQueue::getTrack 0 Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::volumioPushState Mar 18 04:03:07 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 18 04:03:07 volumio volumio[19036]: info: Spotify config file written Mar 18 04:03:07 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 18 04:03:07 volumio volumio[19036]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio sudo[19292]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio sudo[19292]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:03:07 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:03:07 volumio kernel: hwmon hwmon1: Undervoltage detected! Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio go-librespot[19298]: Librespot-go daemon starting... Mar 18 04:03:07 volumio sudo[19292]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio go-librespot[19298]: time="2025-03-18T04:03:07+01:00" level=info msg="generated new device id: 665e14d817276d6e6c062a2be872a7fd5236c864" Mar 18 04:03:07 volumio go-librespot[19298]: time="2025-03-18T04:03:07+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:03:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:03:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio volumio[19036]: info: No need to fix Spotify hosts Mar 18 04:03:07 volumio volumio-remote-updater[567]: [2025-03-18 04:03:07] [connect] Successful connection Mar 18 04:03:07 volumio volumio[19036]: info: VolumeController:: Volume=100 Mute =false Mar 18 04:03:07 volumio volumio[19036]: info: CoreStateMachine::pushState Mar 18 04:03:07 volumio volumio[19036]: info: CorePlayQueue::getTrack 0 Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::volumioPushState Mar 18 04:03:07 volumio volumio[19036]: info: [squeezelite_mc] Server discovery started Mar 18 04:03:07 volumio volumio[19036]: info: [squeezelite_mc] Player finder started Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:07 volumio volumio[19036]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 18 04:03:07 volumio volumio[19036]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Mar 18 04:03:07 volumio volumio[19036]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 18 04:03:07 volumio volumio[19036]: Error: send ENETUNREACH 255.255.255.255:3483 Mar 18 04:03:07 volumio volumio[19036]: at doSend (dgram.js:692:16) Mar 18 04:03:07 volumio volumio[19036]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Mar 18 04:03:07 volumio volumio[19036]: at afterDns (dgram.js:638:5) Mar 18 04:03:07 volumio volumio[19036]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Mar 18 04:03:07 volumio volumio[19036]: errno: -101, Mar 18 04:03:07 volumio volumio[19036]: code: 'ENETUNREACH', Mar 18 04:03:07 volumio volumio[19036]: syscall: 'send', Mar 18 04:03:07 volumio volumio[19036]: address: '255.255.255.255', Mar 18 04:03:07 volumio volumio[19036]: port: 3483 Mar 18 04:03:07 volumio volumio[19036]: } Mar 18 04:03:07 volumio volumio[19036]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 18 04:03:08 volumio sudo[19273]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:09 volumio sudo[19323]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-18 04:02 Mar 18 04:03:09 volumio sudo[19323]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 18 04:03:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 18 04:03:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 18 04:03:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 18 04:03:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 18 04:03:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 18 04:03:09 volumio sudo[19323]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:09 volumio mpd[19254]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 18 04:03:09 volumio mpd[19254]: output: No 'audio_output' defined in config file Mar 18 04:03:09 volumio mpd[19254]: output: Successfully detected a sndio audio device Mar 18 04:03:09 volumio mpd[19254]: zeroconf: No global port, disabling zeroconf Mar 18 04:03:09 volumio systemd[1]: Started Music Player Daemon. Mar 18 04:03:09 volumio sudo[19230]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:09 volumio sudo[19224]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:09 volumio volumio-remote-updater[567]: [2025-03-18 04:03:09] [info] asio async_read_at_least error: system:104 (Connection reset by peer) Mar 18 04:03:09 volumio volumio-remote-updater[567]: [2025-03-18 04:03:09] [error] handle_read_http_response error: websocketpp.transport:2 (Underlying Transport Error) Mar 18 04:03:09 volumio volumio-remote-updater[567]: [2025-03-18 04:03:09] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Mar 18 04:03:09 volumio systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Mar 18 04:03:09 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:03:09 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 18 04:03:09 volumio systemd[1]: Started dynamicswap service. Mar 18 04:03:09 volumio systemd[1]: dynamicswap.service: Succeeded. Mar 18 04:03:09 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Mar 18 04:03:09 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 70. Mar 18 04:03:09 volumio systemd[1]: Stopped Volumio Backend Module. Mar 18 04:03:09 volumio systemd[1]: Started Volumio Backend Module. Mar 18 04:03:09 volumio systemd[1]: Started dynamicswap service. Mar 18 04:03:09 volumio systemd[1]: dynamicswap.service: Succeeded. Mar 18 04:03:10 volumio volumio[19331]: cset: --> shielding system active with Mar 18 04:03:10 volumio volumio[19331]: cset: "system" cpuset of CPUSPEC(1-3) with 56 tasks running Mar 18 04:03:10 volumio volumio[19331]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Mar 18 04:03:10 volumio systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Mar 18 04:03:10 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:03:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 18 04:03:10 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:03:10 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:03:10 volumio go-librespot[19366]: Librespot-go daemon starting... Mar 18 04:03:10 volumio go-librespot[19366]: time="2025-03-18T04:03:10+01:00" level=info msg="generated new device id: 65b6fbcdf589b78e2debe0f35eab9d448f4f99b1" Mar 18 04:03:10 volumio go-librespot[19366]: time="2025-03-18T04:03:10+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:03:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:03:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:03:12 volumio volumio[19350]: info: ------------------------------------------- Mar 18 04:03:12 volumio volumio[19350]: info: ----- Volumio3 ---- Mar 18 04:03:12 volumio volumio[19350]: info: ------------------------------------------- Mar 18 04:03:12 volumio volumio[19350]: info: ----- System startup ---- Mar 18 04:03:12 volumio volumio[19350]: info: ------------------------------------------- Mar 18 04:03:13 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 18 04:03:13 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 18 04:03:13 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 18 04:03:13 volumio volumio[19350]: info: MYVOLUMIO Environment detected Mar 18 04:03:13 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 18 04:03:13 volumio volumio[19350]: info: Plugin folders cleanup Mar 18 04:03:13 volumio volumio[19350]: info: Scanning into folder /volumio/app/plugins/ Mar 18 04:03:13 volumio volumio[19350]: info: Scanning category audio_interface Mar 18 04:03:13 volumio volumio[19350]: info: Scanning category miscellanea Mar 18 04:03:13 volumio volumio[19350]: info: Scanning category music_service Mar 18 04:03:13 volumio volumio[19350]: info: Scanning category plugins.json Mar 18 04:03:13 volumio volumio[19350]: info: Scanning category system_controller Mar 18 04:03:13 volumio volumio[19350]: info: Scanning category user_interface Mar 18 04:03:13 volumio volumio[19350]: info: Scanning into folder /data/plugins/ Mar 18 04:03:13 volumio volumio[19350]: info: Scanning category music_service Mar 18 04:03:13 volumio volumio[19350]: info: Scanning category system_controller Mar 18 04:03:13 volumio volumio[19350]: info: Scanning category system_hardware Mar 18 04:03:13 volumio volumio[19350]: info: Scanning category user_interface Mar 18 04:03:13 volumio volumio[19350]: info: Plugin folders cleanup completed Mar 18 04:03:13 volumio volumio[19350]: info: ------------------------------------------- Mar 18 04:03:13 volumio volumio[19350]: info: ----- Core plugins startup ---- Mar 18 04:03:13 volumio volumio[19350]: info: ------------------------------------------- Mar 18 04:03:13 volumio volumio[19350]: info: Loading plugins from folder /volumio/app/plugins/ Mar 18 04:03:13 volumio volumio[19350]: info: Adding plugin upnp to MyMusic Plugins Mar 18 04:03:13 volumio volumio[19350]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 18 04:03:13 volumio volumio[19350]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 18 04:03:13 volumio volumio[19350]: info: Loading plugins from folder /data/plugins/ Mar 18 04:03:13 volumio volumio[19350]: info: Loading plugin "system"... Mar 18 04:03:13 volumio volumio[19350]: info: Loading plugin "appearance"... Mar 18 04:03:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:03:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 18 04:03:14 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:03:14 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:03:14 volumio go-librespot[19386]: Librespot-go daemon starting... Mar 18 04:03:14 volumio go-librespot[19386]: time="2025-03-18T04:03:14+01:00" level=info msg="generated new device id: cf8974b89e628ffb3608fbdf367f05cb8734917c" Mar 18 04:03:14 volumio go-librespot[19386]: time="2025-03-18T04:03:14+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:03:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:03:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:03:14 volumio volumio[19350]: info: Loading plugin "network"... Mar 18 04:03:14 volumio volumio[19350]: info: Refreshing Cached IP Addresses Mar 18 04:03:14 volumio sudo[19394]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 18 04:03:14 volumio sudo[19394]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:14 volumio sudo[19394]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:14 volumio sudo[19396]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 18 04:03:14 volumio sudo[19396]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:14 volumio sudo[19396]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:14 volumio volumio[19350]: info: Loading plugin "services"... Mar 18 04:03:14 volumio volumio[19350]: info: Loading plugin "alsa_controller"... Mar 18 04:03:14 volumio sudo[19405]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 18 04:03:14 volumio sudo[19405]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:14 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 18 04:03:14 volumio volumio[19350]: info: Loading plugin "wizard"... Mar 18 04:03:14 volumio volumio[19350]: info: Loading plugin "networkfs"... Mar 18 04:03:14 volumio volumio[19350]: info: Starting Udev Watcher for removable devices Mar 18 04:03:14 volumio volumio[19350]: info: Ignoring mount for partition: boot Mar 18 04:03:14 volumio volumio[19350]: info: Ignoring mount for partition: volumio Mar 18 04:03:14 volumio volumio[19350]: info: Ignoring mount for partition: volumio_data Mar 18 04:03:14 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 18 04:03:14 volumio volumio[19350]: info: Loading plugin "volumio_command_line_client"... Mar 18 04:03:14 volumio volumio[19350]: info: Plugin upnp is not enabled Mar 18 04:03:14 volumio volumio[19350]: info: Loading plugin "my_music"... Mar 18 04:03:14 volumio volumio[19350]: info: Loading plugin "mpd"... Mar 18 04:03:15 volumio volumio[19350]: info: Plugin upnp_browser is not enabled Mar 18 04:03:15 volumio volumio[19350]: info: Loading plugin "alarm-clock"... Mar 18 04:03:15 volumio volumio[19350]: info: Plugin airplay_emulation is not enabled Mar 18 04:03:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 18 04:03:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 18 04:03:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 18 04:03:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 18 04:03:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 18 04:03:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 18 04:03:15 volumio volumio[19350]: info: Loading plugin "last_100"... Mar 18 04:03:15 volumio volumio[19350]: info: Loading plugin "webradio"... Mar 18 04:03:15 volumio sudo[19422]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto,vers=3 192.168.0.101:/volume1/Public/Music /mnt/NAS/NasTas Mar 18 04:03:15 volumio sudo[19424]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto,vers=3 192.168.0.101:/volume1/Public/Musik-Dieter /mnt/NAS/Music-Dieter Mar 18 04:03:15 volumio sudo[19422]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:15 volumio sudo[19424]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:15 volumio sudo[19424]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:15 volumio sudo[19422]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:15 volumio volumio[19350]: info: Loading plugin "i2s_dacs"... Mar 18 04:03:15 volumio volumio[19350]: info: Loading plugin "volumiodiscovery"... Mar 18 04:03:15 volumio volumio[19350]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 18 04:03:15 volumio volumio[19350]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 18 04:03:15 volumio volumio[19350]: *** WARNING *** For more information see Mar 18 04:03:15 volumio volumio[19350]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 18 04:03:15 volumio volumio[19350]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 18 04:03:15 volumio volumio[19350]: *** WARNING *** For more information see Mar 18 04:03:15 volumio node[19350]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 18 04:03:15 volumio node[19350]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 18 04:03:15 volumio node[19350]: *** WARNING *** For more information see Mar 18 04:03:15 volumio node[19350]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 18 04:03:15 volumio node[19350]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 18 04:03:15 volumio node[19350]: *** WARNING *** For more information see Mar 18 04:03:15 volumio volumio[19350]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 18 04:03:15 volumio volumio[19350]: info: Discovery: Started advertising with name: Volumio Mar 18 04:03:15 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 18 04:03:15 volumio volumio[19350]: info: Loading plugin "soundcloud"... Mar 18 04:03:16 volumio volumio[19350]: info: Loading plugin "spop"... Mar 18 04:03:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:03:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Mar 18 04:03:17 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:03:17 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:03:17 volumio go-librespot[19434]: Librespot-go daemon starting... Mar 18 04:03:17 volumio go-librespot[19434]: time="2025-03-18T04:03:17+01:00" level=info msg="generated new device id: 696eb875d8e76e01b4328a5b467da528f6483232" Mar 18 04:03:17 volumio go-librespot[19434]: time="2025-03-18T04:03:17+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:03:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:03:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:03:17 volumio sudo[19405]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:18 volumio volumio[19350]: info: Loading plugin "squeezelite_mc"... Mar 18 04:03:19 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 18 04:03:19 volumio volumio[19350]: info: Loading plugin "outputs"... Mar 18 04:03:19 volumio volumio[19350]: info: Loading plugin "albumart"... Mar 18 04:03:19 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 18 04:03:19 volumio volumio[19350]: info: Plugin example_plugin is not enabled Mar 18 04:03:19 volumio volumio[19350]: info: Loading plugin "inputs"... Mar 18 04:03:19 volumio volumio-remote-updater[567]: [2025-03-18 04:03:19] [connect] Successful connection Mar 18 04:03:19 volumio volumio[19350]: info: Loading plugin "updater_comm"... Mar 18 04:03:19 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 18 04:03:19 volumio volumio[19350]: info: Plugin mpdemulation is not enabled Mar 18 04:03:19 volumio volumio[19350]: info: Loading plugin "rest_api"... Mar 18 04:03:19 volumio volumio[19350]: info: Loading plugin "websocket"... Mar 18 04:03:19 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 18 04:03:19 volumio volumio[19350]: info: Starting Socket.io Server version 2.3.0 Mar 18 04:03:19 volumio volumio[19350]: info: Loading plugin "radio_paradise"... Mar 18 04:03:20 volumio volumio[19350]: Forking 3 albumart workers Mar 18 04:03:20 volumio volumio[19350]: info: Applying required configuration parameters for plugin radio_paradise Mar 18 04:03:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:03:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Mar 18 04:03:20 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:03:20 volumio volumio[19350]: info: [1742267000544] [RadioParadise] API delay: 3 Mar 18 04:03:20 volumio volumio[19350]: info: Loading plugin "backup_restore"... Mar 18 04:03:20 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:03:20 volumio go-librespot[19470]: Librespot-go daemon starting... Mar 18 04:03:20 volumio go-librespot[19470]: time="2025-03-18T04:03:20+01:00" level=info msg="generated new device id: 3b7d5bbfe402ce34fd4476c4fe71f630b864d255" Mar 18 04:03:20 volumio go-librespot[19470]: time="2025-03-18T04:03:20+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:03:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:03:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:03:21 volumio volumio[19350]: info: Applying required configuration parameters for plugin backup_restore Mar 18 04:03:21 volumio volumio[19350]: info: Loading plugin "music_services_shield"... Mar 18 04:03:21 volumio wpa_supplicant[872]: wlan0: Trying to associate with SSID 'DAVINCHI-5G' Mar 18 04:03:21 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 18 04:03:21 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 18 04:03:21 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 18 04:03:21 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 18 04:03:21 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 18 04:03:21 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 18 04:03:21 volumio dhcpcd[884]: wlan0: carrier acquired Mar 18 04:03:21 volumio wpa_supplicant[872]: wlan0: Associated with f0:b4:d2:6b:1f:7b Mar 18 04:03:21 volumio wpa_supplicant[872]: wlan0: CTRL-EVENT-CONNECTED - Connection to f0:b4:d2:6b:1f:7b completed [id=0 id_str=] Mar 18 04:03:21 volumio wpa_supplicant[872]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Mar 18 04:03:21 volumio dhcpcd[884]: wlan0: IAID eb:2a:05:b2 Mar 18 04:03:21 volumio dhcpcd[884]: wlan0: carrier lost Mar 18 04:03:21 volumio dhcpcd[884]: wlan0: carrier acquired Mar 18 04:03:21 volumio dhcpcd[884]: wlan0: IAID eb:2a:05:b2 Mar 18 04:03:21 volumio dhcpcd[884]: wlan0: soliciting an IPv6 router Mar 18 04:03:21 volumio volumio[19350]: info: Applying required configuration parameters for plugin music_services_shield Mar 18 04:03:21 volumio volumio[19350]: info: Loading plugin "Systeminfo"... Mar 18 04:03:21 volumio dhcpcd[884]: wlan0: rebinding lease of 192.168.0.120 Mar 18 04:03:21 volumio dhcpcd[884]: wlan0: probing address 192.168.0.120/24 Mar 18 04:03:22 volumio volumio[19350]: Starting albumart workers Mar 18 04:03:22 volumio volumio[19350]: info: Loading i18n strings for locale en Mar 18 04:03:22 volumio volumio[19350]: Updating browse sources language Mar 18 04:03:22 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:03:22 volumio volumio[19350]: Starting albumart workers Mar 18 04:03:22 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 18 04:03:22 volumio volumio[19350]: info: CoreCommandRouter::initPlayerControls Mar 18 04:03:22 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:22 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:22 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:22 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:22 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:22 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:22 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:22 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:22 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 18 04:03:22 volumio volumio[19350]: Express server listening on port 3000 Mar 18 04:03:22 volumio volumio[19350]: [Metrics] WebUI: 10s 902.33ms Mar 18 04:03:23 volumio volumio[19350]: info: CoreStateMachine::resetVolumioState Mar 18 04:03:23 volumio volumio[19350]: info: CoreStateMachine::getcurrentVolume Mar 18 04:03:23 volumio volumio[19350]: info: CoreCommandRouter::volumioRetrievevolume Mar 18 04:03:23 volumio volumio[19350]: Starting albumart workers Mar 18 04:03:23 volumio volumio[19350]: info: Volumio Network Manager: Network status updated: 0 Mar 18 04:03:23 volumio volumio[19350]: info: Cannot mount NAS Music-Dieter at system boot, trial number 1 ,retrying in 5 seconds Mar 18 04:03:23 volumio volumio[19350]: info: Cannot mount NAS NasTas at system boot, trial number 1 ,retrying in 5 seconds Mar 18 04:03:23 volumio volumio-remote-updater[567]: [2025-03-18 04:03:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1742266999 101 Mar 18 04:03:23 volumio volumio[19350]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Mar 18 04:03:23 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:03:23 volumio volumio[19350]: info: Reloading queue from file Mar 18 04:03:23 volumio volumio[19350]: info: CoreStateMachine::setRepeat null single undefined Mar 18 04:03:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 18 04:03:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Mar 18 04:03:23 volumio volumio[19350]: info: CoreStateMachine::pushState Mar 18 04:03:23 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:03:23 volumio volumio[19350]: info: CorePlayQueue::getTrack 0 Mar 18 04:03:23 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 18 04:03:23 volumio volumio[19350]: info: CoreCommandRouter::volumioPushState Mar 18 04:03:23 volumio volumio[19350]: info: CoreStateMachine::setRandom false Mar 18 04:03:23 volumio volumio[19350]: info: CoreStateMachine::pushState Mar 18 04:03:23 volumio volumio[19350]: info: CorePlayQueue::getTrack 0 Mar 18 04:03:23 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 18 04:03:23 volumio volumio[19350]: info: CoreCommandRouter::volumioPushState Mar 18 04:03:23 volumio volumio[19350]: info: Setting Device type: Raspberry PI Mar 18 04:03:23 volumio volumio[19350]: info: VolumeController:: Volume=100 Mute =false Mar 18 04:03:23 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:03:23 volumio go-librespot[19506]: Librespot-go daemon starting... Mar 18 04:03:23 volumio volumio[19350]: info: CoreStateMachine::pushState Mar 18 04:03:23 volumio volumio[19350]: info: CorePlayQueue::getTrack 0 Mar 18 04:03:23 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 18 04:03:23 volumio volumio[19350]: info: CoreCommandRouter::volumioPushState Mar 18 04:03:23 volumio volumio[19350]: info: CoreStateMachine::updateTrackBlock Mar 18 04:03:23 volumio volumio[19350]: info: CorePlayQueue::getTrackBlock Mar 18 04:03:23 volumio volumio[19350]: info: CoreCommandRouter::volumioRetrievevolume Mar 18 04:03:23 volumio go-librespot[19506]: time="2025-03-18T04:03:23+01:00" level=info msg="generated new device id: 4624f2c0af68fef99b804fb0a0cf17d9f1b24e33" Mar 18 04:03:23 volumio go-librespot[19506]: time="2025-03-18T04:03:23+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:03:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:03:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:03:23 volumio volumio[19350]: info: Completed loading Core Plugins Mar 18 04:03:24 volumio volumio[19350]: info: Preparing to generate the ALSA configuration file Mar 18 04:03:24 volumio volumio[19350]: info: Asound.conf file unchanged, so no further update is needed Mar 18 04:03:24 volumio volumio[19350]: info: Output device has changed, restarting MPD Mar 18 04:03:24 volumio volumio[19350]: info: ___________ START PLUGINS ___________ Mar 18 04:03:24 volumio volumio[19350]: info: ControllerMpd::onStart: Initializing MPD Mar 18 04:03:24 volumio volumio[19350]: info: Creating MPD Configuration file Mar 18 04:03:24 volumio sudo[19526]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 18 04:03:24 volumio sudo[19526]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:24 volumio sudo[19524]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 18 04:03:24 volumio sudo[19524]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:24 volumio sudo[19524]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:24 volumio systemd[1]: musicservicesshield.service: Succeeded. Mar 18 04:03:24 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Mar 18 04:03:24 volumio systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Mar 18 04:03:24 volumio systemd[1]: Stopping Music Player Daemon... Mar 18 04:03:24 volumio volumio[19350]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:03:24 volumio volumio[19350]: info: [1742267004336] CoreMusicLibrary::Adding element Last_100 Mar 18 04:03:24 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:03:24 volumio volumio[19350]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:03:24 volumio systemd[1]: mpd.service: Succeeded. Mar 18 04:03:24 volumio volumio[19350]: info: [1742267004350] CoreMusicLibrary::Adding element Webradio Mar 18 04:03:24 volumio systemd[1]: Stopped Music Player Daemon. Mar 18 04:03:24 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:03:24 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 18 04:03:24 volumio sudo[19530]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 18 04:03:24 volumio sudo[19530]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:24 volumio volumio[19350]: info: Initializing BBC Radios Mar 18 04:03:24 volumio sudo[19530]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:24 volumio sudo[19532]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 18 04:03:24 volumio sudo[19532]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:24 volumio systemd[1]: Starting Music Player Daemon... Mar 18 04:03:24 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Mar 18 04:03:24 volumio systemd[1]: mpd.service: Succeeded. Mar 18 04:03:24 volumio systemd[1]: Stopped Music Player Daemon. Mar 18 04:03:24 volumio systemd[1]: Starting Music Player Daemon... Mar 18 04:03:24 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 18 04:03:24 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:03:24 volumio volumio[19350]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:03:24 volumio volumio[19350]: info: [1742267004600] CoreMusicLibrary::Adding element SoundCloud Mar 18 04:03:24 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:03:24 volumio volumio[19350]: Cannot find translation for source SoundCloud Mar 18 04:03:24 volumio volumio[19350]: info: Creating Spotify config file Mar 18 04:03:24 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:24 volumio volumio[19350]: info: [squeezelite_mc] Starting proxy server... Mar 18 04:03:24 volumio volumio[19350]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 18 04:03:24 volumio volumio[19350]: info: [1742267004716] CoreMusicLibrary::Adding element Radio Paradise Mar 18 04:03:24 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 18 04:03:24 volumio volumio[19350]: Cannot find translation for source SoundCloud Mar 18 04:03:24 volumio volumio[19350]: Cannot find translation for source Radio Paradise Mar 18 04:03:24 volumio sudo[19539]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 18 04:03:24 volumio sudo[19539]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:24 volumio sudo[19539]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:25 volumio volumio[19350]: info: Volumio Calling Home Mar 18 04:03:25 volumio sudo[19597]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Mar 18 04:03:25 volumio sudo[19597]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:25 volumio volumio[19350]: info: [squeezelite_mc] Proxy server started on port 40099 Mar 18 04:03:25 volumio volumio[19350]: info: CoreCommandRouter::volumioRetrievevolume Mar 18 04:03:25 volumio volumio[19350]: info: MPD Permissions set Mar 18 04:03:25 volumio volumio[19350]: info: MPD Permissions set Mar 18 04:03:25 volumio volumio[19350]: info: VolumeController:: Volume=100 Mute =false Mar 18 04:03:25 volumio volumio[19350]: info: CoreStateMachine::pushState Mar 18 04:03:25 volumio volumio[19350]: info: CorePlayQueue::getTrack 0 Mar 18 04:03:25 volumio volumio[19350]: info: CoreCommandRouter::volumioPushState Mar 18 04:03:25 volumio volumio[19350]: info: Spotify config file written Mar 18 04:03:26 volumio sudo[19626]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 18 04:03:26 volumio sudo[19626]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:26 volumio volumio[19350]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio systemd[1]: Stopped go-librespot Daemon. Mar 18 04:03:26 volumio systemd[1]: Started go-librespot Daemon. Mar 18 04:03:26 volumio go-librespot[19641]: Librespot-go daemon starting... Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio sudo[19626]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio go-librespot[19641]: time="2025-03-18T04:03:26+01:00" level=info msg="generated new device id: afe0df13b15b96f0111aa0569c3f94b23125dd9a" Mar 18 04:03:26 volumio go-librespot[19641]: time="2025-03-18T04:03:26+01:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 18 04:03:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 18 04:03:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: No need to fix Spotify hosts Mar 18 04:03:26 volumio volumio[19350]: info: VolumeController:: Volume=100 Mute =false Mar 18 04:03:26 volumio volumio[19350]: info: CoreStateMachine::pushState Mar 18 04:03:26 volumio volumio[19350]: info: CorePlayQueue::getTrack 0 Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::volumioPushState Mar 18 04:03:26 volumio volumio[19350]: info: [squeezelite_mc] Server discovery started Mar 18 04:03:26 volumio volumio[19350]: info: [squeezelite_mc] Player finder started Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 18 04:03:26 volumio volumio[19350]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Mar 18 04:03:26 volumio volumio[19350]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 18 04:03:26 volumio volumio[19350]: Error: send ENETUNREACH 255.255.255.255:3483 Mar 18 04:03:26 volumio volumio[19350]: at doSend (dgram.js:692:16) Mar 18 04:03:26 volumio volumio[19350]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Mar 18 04:03:26 volumio volumio[19350]: at afterDns (dgram.js:638:5) Mar 18 04:03:26 volumio volumio[19350]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Mar 18 04:03:26 volumio volumio[19350]: errno: -101, Mar 18 04:03:26 volumio volumio[19350]: code: 'ENETUNREACH', Mar 18 04:03:26 volumio volumio[19350]: syscall: 'send', Mar 18 04:03:26 volumio volumio[19350]: address: '255.255.255.255', Mar 18 04:03:26 volumio volumio[19350]: port: 3483 Mar 18 04:03:26 volumio volumio[19350]: } Mar 18 04:03:26 volumio volumio[19350]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 18 04:03:26 volumio sudo[19597]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:27 volumio dhcpcd[884]: wlan0: leased 192.168.0.120 for infinity Mar 18 04:03:27 volumio avahi-daemon[548]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.120. Mar 18 04:03:27 volumio avahi-daemon[548]: New relevant interface wlan0.IPv4 for mDNS. Mar 18 04:03:27 volumio avahi-daemon[548]: Registering new address record for 192.168.0.120 on wlan0.IPv4. Mar 18 04:03:27 volumio dhcpcd[884]: wlan0: adding route to 192.168.0.0/24 Mar 18 04:03:27 volumio dhcpcd[884]: wlan0: adding default route via 192.168.0.1 Mar 18 04:03:27 volumio sudo[19707]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-18 04:02 Mar 18 04:03:27 volumio sudo[19707]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 18 04:03:27 volumio mpd[19565]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 18 04:03:27 volumio mpd[19565]: output: No 'audio_output' defined in config file Mar 18 04:03:27 volumio mpd[19565]: output: Successfully detected a sndio audio device Mar 18 04:03:27 volumio mpd[19565]: zeroconf: No global port, disabling zeroconf Mar 18 04:03:28 volumio systemd[1]: Started Music Player Daemon. Mar 18 04:03:28 volumio sudo[19532]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:28 volumio sudo[19526]: pam_unix(sudo:session): session closed for user root Mar 18 04:03:28 volumio systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 11:42:54 AM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4049a67f1c09d4a94e033ba35a80a144"