-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2025-08-31 04:03:29 CEST. -- Aug 31 04:02:00 volumio volumio[27968]: info: MPD Permissions set Aug 31 04:02:00 volumio volumio[27968]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:02:00 volumio volumio[27968]: info: CoreStateMachine::pushState Aug 31 04:02:00 volumio volumio[27968]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:00 volumio volumio[27968]: info: Spotify config file written Aug 31 04:02:00 volumio volumio[27968]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 31 04:02:00 volumio sudo[28203]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 04:02:00 volumio sudo[28203]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: No need to fix Spotify hosts Aug 31 04:02:00 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:00 volumio go-librespot[28213]: Librespot-go daemon starting... Aug 31 04:02:00 volumio sudo[28203]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:00 volumio go-librespot[28213]: time="2025-08-31T04:02:00+02:00" level=info msg="generated new device id: 74ab4eb7e1e1ba9e453d4c063518b4bdca914342" Aug 31 04:02:00 volumio volumio[27968]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:02:00 volumio volumio[27968]: info: CoreStateMachine::pushState Aug 31 04:02:00 volumio volumio[27968]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:00 volumio go-librespot[28213]: time="2025-08-31T04:02:00+02: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" Aug 31 04:02:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:00 volumio volumio[27968]: info: [squeezelite_mc] Server discovery started Aug 31 04:02:00 volumio volumio[27968]: info: [squeezelite_mc] Player finder started Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:02:00 volumio volumio[27968]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Aug 31 04:02:00 volumio volumio[27968]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 04:02:00 volumio volumio[27968]: Error: send ENETUNREACH 255.255.255.255:3483 Aug 31 04:02:00 volumio volumio[27968]: at doSend (dgram.js:692:16) Aug 31 04:02:00 volumio volumio[27968]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Aug 31 04:02:00 volumio volumio[27968]: at afterDns (dgram.js:638:5) Aug 31 04:02:00 volumio volumio[27968]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Aug 31 04:02:00 volumio volumio[27968]: errno: -101, Aug 31 04:02:00 volumio volumio[27968]: code: 'ENETUNREACH', Aug 31 04:02:00 volumio volumio[27968]: syscall: 'send', Aug 31 04:02:00 volumio volumio[27968]: address: '255.255.255.255', Aug 31 04:02:00 volumio volumio[27968]: port: 3483 Aug 31 04:02:00 volumio volumio[27968]: } Aug 31 04:02:00 volumio volumio[27968]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 04:02:00 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Aug 31 04:02:00 volumio sudo[28184]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:00 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Aug 31 04:02:00 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Aug 31 04:02:00 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Aug 31 04:02:00 volumio sudo[28234]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-08-31 04:01 Aug 31 04:02:00 volumio sudo[28234]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:01 volumio sudo[28234]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:01 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:01 volumio sudo[28128]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:01 volumio sudo[28136]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:01 volumio mpd[28170]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 04:02:01 volumio mpd[28170]: output: No 'audio_output' defined in config file Aug 31 04:02:01 volumio mpd[28170]: output: Successfully detected a sndio audio device Aug 31 04:02:01 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 31 04:02:01 volumio mpd[28170]: zeroconf: No global port, disabling zeroconf Aug 31 04:02:01 volumio systemd[1]: Started Music Player Daemon. Aug 31 04:02:01 volumio systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Aug 31 04:02:01 volumio systemd[1]: Started dynamicswap service. Aug 31 04:02:01 volumio systemd[1]: dynamicswap.service: Succeeded. Aug 31 04:02:01 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Aug 31 04:02:01 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9. Aug 31 04:02:01 volumio systemd[1]: Started dynamicswap service. Aug 31 04:02:01 volumio systemd[1]: Stopped Volumio Backend Module. Aug 31 04:02:01 volumio systemd[1]: Started Volumio Backend Module. Aug 31 04:02:01 volumio systemd[1]: dynamicswap.service: Succeeded. Aug 31 04:02:01 volumio volumio[28257]: cset: --> shielding system active with Aug 31 04:02:01 volumio volumio[28257]: cset: "system" cpuset of CPUSPEC(1-3) with 57 tasks running Aug 31 04:02:01 volumio volumio[28257]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Aug 31 04:02:01 volumio systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Aug 31 04:02:02 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Aug 31 04:02:02 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Aug 31 04:02:02 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Aug 31 04:02:02 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Aug 31 04:02:02 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Aug 31 04:02:02 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Aug 31 04:02:03 volumio volumio[28273]: info: ------------------------------------------- Aug 31 04:02:03 volumio volumio[28273]: info: ----- Volumio3 ---- Aug 31 04:02:03 volumio volumio[28273]: info: ------------------------------------------- Aug 31 04:02:03 volumio volumio[28273]: info: ----- System startup ---- Aug 31 04:02:03 volumio volumio[28273]: info: ------------------------------------------- Aug 31 04:02:03 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:02:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Aug 31 04:02:03 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:03 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:03 volumio go-librespot[28299]: Librespot-go daemon starting... Aug 31 04:02:03 volumio go-librespot[28299]: time="2025-08-31T04:02:03+02:00" level=info msg="generated new device id: 823271ef879c77fa8836f6dd768ba3c3d597f129" Aug 31 04:02:03 volumio go-librespot[28299]: time="2025-08-31T04:02:03+02: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" Aug 31 04:02:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:03 volumio volumio[28273]: info: MYVOLUMIO Environment detected Aug 31 04:02:03 volumio volumio[28273]: info: Plugin folders cleanup Aug 31 04:02:03 volumio volumio[28273]: info: Scanning into folder /volumio/app/plugins/ Aug 31 04:02:03 volumio volumio[28273]: info: Scanning category audio_interface Aug 31 04:02:03 volumio volumio[28273]: info: Scanning category miscellanea Aug 31 04:02:03 volumio volumio[28273]: info: Scanning category music_service Aug 31 04:02:03 volumio volumio[28273]: info: Scanning category plugins.json Aug 31 04:02:03 volumio volumio[28273]: info: Scanning category system_controller Aug 31 04:02:03 volumio volumio[28273]: info: Scanning category user_interface Aug 31 04:02:03 volumio volumio[28273]: info: Scanning into folder /data/plugins/ Aug 31 04:02:03 volumio volumio[28273]: info: Scanning category music_service Aug 31 04:02:03 volumio volumio[28273]: info: Scanning category system_controller Aug 31 04:02:03 volumio volumio[28273]: info: Scanning category system_hardware Aug 31 04:02:03 volumio volumio[28273]: info: Scanning category user_interface Aug 31 04:02:03 volumio volumio[28273]: info: Plugin folders cleanup completed Aug 31 04:02:03 volumio volumio[28273]: info: ------------------------------------------- Aug 31 04:02:03 volumio volumio[28273]: info: ----- Core plugins startup ---- Aug 31 04:02:03 volumio volumio[28273]: info: ------------------------------------------- Aug 31 04:02:03 volumio volumio[28273]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 04:02:03 volumio volumio[28273]: info: Adding plugin upnp to MyMusic Plugins Aug 31 04:02:03 volumio volumio[28273]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 04:02:03 volumio volumio[28273]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 04:02:03 volumio volumio[28273]: info: Loading plugins from folder /data/plugins/ Aug 31 04:02:03 volumio volumio[28273]: info: Loading plugin "system"... Aug 31 04:02:03 volumio volumio[28273]: info: Loading plugin "appearance"... Aug 31 04:02:04 volumio volumio[28273]: info: Loading plugin "network"... Aug 31 04:02:04 volumio volumio[28273]: info: Refreshing Cached IP Addresses Aug 31 04:02:04 volumio sudo[28312]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 04:02:04 volumio sudo[28312]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:04 volumio sudo[28314]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 04:02:04 volumio sudo[28314]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:04 volumio sudo[28312]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:04 volumio sudo[28314]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:04 volumio volumio[28273]: info: Loading plugin "services"... Aug 31 04:02:04 volumio volumio[28273]: info: Loading plugin "alsa_controller"... Aug 31 04:02:04 volumio sudo[28323]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 31 04:02:04 volumio sudo[28323]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:04 volumio sudo[28323]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:04 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:02:04 volumio volumio[28273]: info: Loading plugin "wizard"... Aug 31 04:02:04 volumio volumio[28273]: info: Loading plugin "networkfs"... Aug 31 04:02:04 volumio volumio-remote-updater[571]: [2025-08-31 04:02:04] [connect] Successful connection Aug 31 04:02:04 volumio volumio[28273]: info: Cannot mount NAS NasTas at system boot, trial number 1 ,retrying in 5 seconds Aug 31 04:02:05 volumio volumio[28273]: info: Cannot mount NAS Music-Dieter at system boot, trial number 1 ,retrying in 5 seconds Aug 31 04:02:05 volumio volumio[28273]: info: Starting Udev Watcher for removable devices Aug 31 04:02:05 volumio volumio[28273]: info: Ignoring mount for partition: boot Aug 31 04:02:05 volumio volumio[28273]: info: Ignoring mount for partition: volumio Aug 31 04:02:05 volumio volumio[28273]: info: Ignoring mount for partition: volumio_data Aug 31 04:02:05 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 04:02:05 volumio volumio[28273]: info: Loading plugin "volumio_command_line_client"... Aug 31 04:02:05 volumio volumio[28273]: info: Plugin upnp is not enabled Aug 31 04:02:05 volumio volumio[28273]: info: Loading plugin "my_music"... Aug 31 04:02:05 volumio volumio[28273]: info: Loading plugin "mpd"... Aug 31 04:02:05 volumio volumio[28273]: info: Plugin upnp_browser is not enabled Aug 31 04:02:05 volumio volumio[28273]: info: Loading plugin "alarm-clock"... Aug 31 04:02:05 volumio volumio[28273]: info: Plugin airplay_emulation is not enabled Aug 31 04:02:05 volumio volumio[28273]: info: Loading plugin "last_100"... Aug 31 04:02:05 volumio volumio[28273]: info: Loading plugin "webradio"... Aug 31 04:02:05 volumio volumio[28273]: info: Loading plugin "i2s_dacs"... Aug 31 04:02:05 volumio volumio[28273]: info: Loading plugin "volumiodiscovery"... Aug 31 04:02:05 volumio volumio[28273]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:05 volumio volumio[28273]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:05 volumio volumio[28273]: *** WARNING *** For more information see Aug 31 04:02:05 volumio volumio[28273]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:05 volumio node[28273]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:05 volumio volumio[28273]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:05 volumio volumio[28273]: *** WARNING *** For more information see Aug 31 04:02:05 volumio node[28273]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:05 volumio node[28273]: *** WARNING *** For more information see Aug 31 04:02:05 volumio node[28273]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:05 volumio node[28273]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:05 volumio node[28273]: *** WARNING *** For more information see Aug 31 04:02:05 volumio volumio[28273]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 04:02:05 volumio volumio[28273]: info: Discovery: Started advertising with name: Volumio Aug 31 04:02:05 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 04:02:05 volumio volumio[28273]: info: Loading plugin "soundcloud"... Aug 31 04:02:06 volumio volumio[28273]: info: Loading plugin "spop"... Aug 31 04:02:06 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Aug 31 04:02:06 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Aug 31 04:02:06 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:02:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Aug 31 04:02:06 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:06 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:06 volumio go-librespot[28341]: Librespot-go daemon starting... Aug 31 04:02:06 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Aug 31 04:02:06 volumio go-librespot[28341]: time="2025-08-31T04:02:06+02:00" level=info msg="generated new device id: 2485590ad14fee05c49b620ddadde80e966ef460" Aug 31 04:02:06 volumio go-librespot[28341]: time="2025-08-31T04:02:06+02: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" Aug 31 04:02:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:06 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Aug 31 04:02:07 volumio nmbd[730]: [2025/08/31 04:02:07.178849, 0] ../source3/nmbd/nmbd.c:361(reload_interfaces) Aug 31 04:02:07 volumio nmbd[730]: reload_interfaces: No subnets to listen to. Waiting.. Aug 31 04:02:07 volumio volumio[28273]: info: Loading plugin "squeezelite_mc"... Aug 31 04:02:07 volumio volumio[28273]: info: Loading plugin "outputs"... Aug 31 04:02:07 volumio volumio[28273]: info: Loading plugin "albumart"... Aug 31 04:02:07 volumio volumio[28273]: info: Plugin example_plugin is not enabled Aug 31 04:02:07 volumio volumio[28273]: info: Loading plugin "inputs"... Aug 31 04:02:07 volumio volumio[28273]: info: Loading plugin "updater_comm"... Aug 31 04:02:08 volumio volumio[28273]: info: Plugin mpdemulation is not enabled Aug 31 04:02:08 volumio volumio[28273]: info: Loading plugin "rest_api"... Aug 31 04:02:08 volumio volumio[28273]: info: Loading plugin "websocket"... Aug 31 04:02:08 volumio volumio[28273]: info: Starting Socket.io Server version 2.3.0 Aug 31 04:02:08 volumio volumio[28273]: info: Loading plugin "radio_paradise"... Aug 31 04:02:08 volumio volumio[28273]: Forking 3 albumart workers Aug 31 04:02:08 volumio volumio[28273]: info: Applying required configuration parameters for plugin radio_paradise Aug 31 04:02:08 volumio volumio[28273]: info: [1756605728534] [RadioParadise] API delay: 3 Aug 31 04:02:08 volumio volumio[28273]: info: Loading plugin "backup_restore"... Aug 31 04:02:08 volumio wpa_supplicant[867]: wlan0: Failed to initiate sched scan Aug 31 04:02:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Aug 31 04:02:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Aug 31 04:02:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Aug 31 04:02:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Aug 31 04:02:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Aug 31 04:02:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Aug 31 04:02:08 volumio volumio[28273]: info: Applying required configuration parameters for plugin backup_restore Aug 31 04:02:08 volumio volumio[28273]: info: Loading plugin "music_services_shield"... Aug 31 04:02:09 volumio volumio[28273]: info: Applying required configuration parameters for plugin music_services_shield Aug 31 04:02:09 volumio volumio[28273]: info: Loading plugin "Systeminfo"... Aug 31 04:02:09 volumio volumio[28273]: info: Loading i18n strings for locale en Aug 31 04:02:09 volumio volumio[28273]: Updating browse sources language Aug 31 04:02:09 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:09 volumio volumio[28273]: Starting albumart workers Aug 31 04:02:09 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:02:09 volumio volumio[28273]: info: CoreCommandRouter::initPlayerControls Aug 31 04:02:09 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:09 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:09 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:09 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:09 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:09 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:09 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:09 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:09 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:02:09 volumio volumio[28273]: Starting albumart workers Aug 31 04:02:09 volumio volumio[28273]: Express server listening on port 3000 Aug 31 04:02:09 volumio volumio[28273]: [Metrics] WebUI: 7s 108.49ms Aug 31 04:02:09 volumio volumio[28273]: Starting albumart workers Aug 31 04:02:09 volumio volumio[28273]: info: CoreStateMachine::resetVolumioState Aug 31 04:02:09 volumio volumio[28273]: info: CoreStateMachine::getcurrentVolume Aug 31 04:02:09 volumio volumio[28273]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:02:09 volumio volumio[28273]: info: Volumio Network Manager: Network status updated: 0 Aug 31 04:02:09 volumio volumio[28273]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Aug 31 04:02:09 volumio volumio[28273]: wlan0 Interface doesn't support scanning : Device or resource busy Aug 31 04:02:09 volumio volumio[28273]: info: Cannot use regular scanning, forcing with ap-force Aug 31 04:02:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:02:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Aug 31 04:02:09 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:09 volumio sudo[28383]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Aug 31 04:02:09 volumio sudo[28383]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:10 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:10 volumio go-librespot[28384]: Librespot-go daemon starting... Aug 31 04:02:10 volumio go-librespot[28384]: time="2025-08-31T04:02:10+02:00" level=info msg="generated new device id: 34d9ee68cf2f380fa7d361e058a0fa9fa9f053d0" Aug 31 04:02:10 volumio go-librespot[28384]: time="2025-08-31T04:02:10+02: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" Aug 31 04:02:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:13 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:02:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Aug 31 04:02:13 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:13 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:13 volumio go-librespot[28416]: Librespot-go daemon starting... Aug 31 04:02:13 volumio go-librespot[28416]: time="2025-08-31T04:02:13+02:00" level=info msg="generated new device id: d526a60273cf7b4275d15bf2dad8227cef1b7ffa" Aug 31 04:02:13 volumio go-librespot[28416]: time="2025-08-31T04:02:13+02: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" Aug 31 04:02:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:13 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Aug 31 04:02:14 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Aug 31 04:02:14 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Aug 31 04:02:14 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Aug 31 04:02:15 volumio sudo[28383]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Aug 31 04:02:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Aug 31 04:02:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Aug 31 04:02:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Aug 31 04:02:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Aug 31 04:02:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Aug 31 04:02:16 volumio volumio[28273]: info: Cannot mount NAS NasTas at system boot, trial number 2 ,retrying in 5 seconds Aug 31 04:02:16 volumio volumio[28273]: info: Cannot mount NAS Music-Dieter at system boot, trial number 2 ,retrying in 5 seconds Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:16 volumio volumio[28273]: info: Reloading queue from file Aug 31 04:02:16 volumio volumio[28273]: info: CoreStateMachine::setRepeat false single undefined Aug 31 04:02:16 volumio volumio[28273]: info: CoreStateMachine::pushState Aug 31 04:02:16 volumio volumio[28273]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:16 volumio volumio[28273]: info: CoreStateMachine::setRandom false Aug 31 04:02:16 volumio volumio[28273]: info: CoreStateMachine::pushState Aug 31 04:02:16 volumio volumio[28273]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:16 volumio volumio[28273]: info: Setting Device type: Raspberry PI Aug 31 04:02:16 volumio volumio[28273]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:02:16 volumio volumio[28273]: info: CoreStateMachine::pushState Aug 31 04:02:16 volumio volumio[28273]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:16 volumio volumio[28273]: info: CoreStateMachine::updateTrackBlock Aug 31 04:02:16 volumio volumio[28273]: info: CorePlayQueue::getTrackBlock Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:02:16 volumio volumio[28273]: info: Completed loading Core Plugins Aug 31 04:02:16 volumio volumio[28273]: info: Preparing to generate the ALSA configuration file Aug 31 04:02:16 volumio volumio[28273]: info: Asound.conf file unchanged, so no further update is needed Aug 31 04:02:16 volumio volumio[28273]: info: Output device has changed, restarting MPD Aug 31 04:02:16 volumio sudo[28445]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 04:02:16 volumio sudo[28445]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:16 volumio volumio[28273]: info: ___________ START PLUGINS ___________ Aug 31 04:02:16 volumio sudo[28445]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:16 volumio volumio[28273]: info: ControllerMpd::onStart: Initializing MPD Aug 31 04:02:16 volumio volumio[28273]: info: Creating MPD Configuration file Aug 31 04:02:16 volumio sudo[28447]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 04:02:16 volumio sudo[28447]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:16 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:02:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Aug 31 04:02:16 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:16 volumio sudo[28451]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 04:02:16 volumio sudo[28451]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:02:16 volumio volumio[28273]: info: [1756605736345] CoreMusicLibrary::Adding element Last_100 Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:02:16 volumio volumio[28273]: info: [1756605736350] CoreMusicLibrary::Adding element Webradio Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:02:16 volumio volumio[28273]: info: Initializing BBC Radios Aug 31 04:02:16 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:16 volumio sudo[28451]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:16 volumio sudo[28454]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 04:02:16 volumio sudo[28454]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:16 volumio go-librespot[28453]: Librespot-go daemon starting... Aug 31 04:02:16 volumio systemd[1]: musicservicesshield.service: Succeeded. Aug 31 04:02:16 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Aug 31 04:02:16 volumio systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Aug 31 04:02:16 volumio systemd[1]: Stopping Music Player Daemon... Aug 31 04:02:16 volumio go-librespot[28453]: time="2025-08-31T04:02:16+02:00" level=info msg="generated new device id: 4383df082f0e091323b941f0c8832519c21b2a37" Aug 31 04:02:16 volumio go-librespot[28453]: time="2025-08-31T04:02:16+02: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" Aug 31 04:02:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:16 volumio systemd[1]: mpd.service: Succeeded. Aug 31 04:02:16 volumio systemd[1]: Stopped Music Player Daemon. Aug 31 04:02:16 volumio systemd[1]: Starting Music Player Daemon... Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:02:16 volumio volumio[28273]: info: [1756605736484] CoreMusicLibrary::Adding element SoundCloud Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:16 volumio volumio[28273]: Cannot find translation for source SoundCloud Aug 31 04:02:16 volumio volumio[28273]: info: Creating Spotify config file Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:16 volumio volumio[28273]: info: [squeezelite_mc] Starting proxy server... Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:02:16 volumio volumio[28273]: info: [1756605736530] CoreMusicLibrary::Adding element Radio Paradise Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:16 volumio volumio[28273]: Cannot find translation for source SoundCloud Aug 31 04:02:16 volumio volumio[28273]: Cannot find translation for source Radio Paradise Aug 31 04:02:16 volumio sudo[28473]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 04:02:16 volumio sudo[28473]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:16 volumio sudo[28473]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:16 volumio volumio[28273]: info: Volumio Calling Home Aug 31 04:02:16 volumio volumio[28273]: info: [squeezelite_mc] Proxy server started on port 43375 Aug 31 04:02:16 volumio sudo[28502]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Aug 31 04:02:16 volumio sudo[28502]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:16 volumio volumio[28273]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:02:17 volumio volumio[28273]: info: MPD Permissions set Aug 31 04:02:17 volumio volumio[28273]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:02:17 volumio volumio[28273]: info: CoreStateMachine::pushState Aug 31 04:02:17 volumio volumio[28273]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:17 volumio volumio[28273]: info: Spotify config file written Aug 31 04:02:17 volumio sudo[28521]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 04:02:17 volumio sudo[28521]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:17 volumio volumio[28273]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: No need to fix Spotify hosts Aug 31 04:02:17 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:17 volumio go-librespot[28523]: Librespot-go daemon starting... Aug 31 04:02:17 volumio sudo[28521]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:17 volumio go-librespot[28523]: time="2025-08-31T04:02:17+02:00" level=info msg="generated new device id: fddc7aab1aff59fa44449d7adbef41056015fe93" Aug 31 04:02:17 volumio autossh[1647]: starting ssh (count 17) Aug 31 04:02:17 volumio autossh[1647]: ssh child pid is 28539 Aug 31 04:02:17 volumio go-librespot[28523]: time="2025-08-31T04:02:17+02: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" Aug 31 04:02:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:17 volumio volumiossh-tunnel[1646]: ssh: Could not resolve hostname eu4.myvolumio.org: Device or resource busy Aug 31 04:02:17 volumio autossh[1647]: ssh exited with error status 255; restarting ssh Aug 31 04:02:17 volumio volumio[28273]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:02:17 volumio volumio[28273]: info: CoreStateMachine::pushState Aug 31 04:02:17 volumio volumio[28273]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:17 volumio volumio[28273]: info: [squeezelite_mc] Server discovery started Aug 31 04:02:17 volumio volumio[28273]: info: [squeezelite_mc] Player finder started Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:02:17 volumio volumio[28273]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Aug 31 04:02:17 volumio volumio[28273]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 04:02:17 volumio volumio[28273]: Error: send ENETUNREACH 255.255.255.255:3483 Aug 31 04:02:17 volumio volumio[28273]: at doSend (dgram.js:692:16) Aug 31 04:02:17 volumio volumio[28273]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Aug 31 04:02:17 volumio volumio[28273]: at afterDns (dgram.js:638:5) Aug 31 04:02:17 volumio volumio[28273]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Aug 31 04:02:17 volumio volumio[28273]: errno: -101, Aug 31 04:02:17 volumio volumio[28273]: code: 'ENETUNREACH', Aug 31 04:02:17 volumio volumio[28273]: syscall: 'send', Aug 31 04:02:17 volumio volumio[28273]: address: '255.255.255.255', Aug 31 04:02:17 volumio volumio[28273]: port: 3483 Aug 31 04:02:17 volumio volumio[28273]: } Aug 31 04:02:17 volumio volumio[28273]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 04:02:17 volumio sudo[28502]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:18 volumio sudo[28553]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-08-31 04:01 Aug 31 04:02:18 volumio sudo[28553]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:18 volumio sudo[28553]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:18 volumio mpd[28484]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 04:02:18 volumio mpd[28484]: output: No 'audio_output' defined in config file Aug 31 04:02:18 volumio mpd[28484]: output: Successfully detected a sndio audio device Aug 31 04:02:18 volumio mpd[28484]: zeroconf: No global port, disabling zeroconf Aug 31 04:02:18 volumio systemd[1]: Started Music Player Daemon. Aug 31 04:02:18 volumio sudo[28447]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:18 volumio sudo[28454]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:18 volumio systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Aug 31 04:02:18 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:18 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 31 04:02:18 volumio systemd[1]: Started dynamicswap service. Aug 31 04:02:18 volumio systemd[1]: dynamicswap.service: Succeeded. Aug 31 04:02:18 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Aug 31 04:02:18 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10. Aug 31 04:02:18 volumio systemd[1]: Stopped Volumio Backend Module. Aug 31 04:02:18 volumio systemd[1]: Started Volumio Backend Module. Aug 31 04:02:18 volumio systemd[1]: Started dynamicswap service. Aug 31 04:02:18 volumio systemd[1]: dynamicswap.service: Succeeded. Aug 31 04:02:18 volumio volumio[28562]: cset: --> shielding system active with Aug 31 04:02:18 volumio volumio[28562]: cset: "system" cpuset of CPUSPEC(1-3) with 57 tasks running Aug 31 04:02:18 volumio volumio[28562]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Aug 31 04:02:18 volumio systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Aug 31 04:02:19 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Aug 31 04:02:19 volumio volumio-remote-updater[571]: [2025-08-31 04:02:19] [connect] Successful connection Aug 31 04:02:20 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Aug 31 04:02:20 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Aug 31 04:02:20 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Aug 31 04:02:20 volumio volumio[28582]: info: ------------------------------------------- Aug 31 04:02:20 volumio volumio[28582]: info: ----- Volumio3 ---- Aug 31 04:02:20 volumio volumio[28582]: info: ------------------------------------------- Aug 31 04:02:20 volumio volumio[28582]: info: ----- System startup ---- Aug 31 04:02:20 volumio volumio[28582]: info: ------------------------------------------- Aug 31 04:02:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:02:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Aug 31 04:02:20 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:20 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:20 volumio go-librespot[28645]: Librespot-go daemon starting... Aug 31 04:02:20 volumio go-librespot[28645]: time="2025-08-31T04:02:20+02:00" level=info msg="generated new device id: d258a68b4ff19768dc7f7a9698fa99fe2b49f6dc" Aug 31 04:02:20 volumio go-librespot[28645]: time="2025-08-31T04:02:20+02: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" Aug 31 04:02:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:20 volumio volumio[28582]: info: MYVOLUMIO Environment detected Aug 31 04:02:21 volumio volumio[28582]: info: Plugin folders cleanup Aug 31 04:02:21 volumio volumio[28582]: info: Scanning into folder /volumio/app/plugins/ Aug 31 04:02:21 volumio volumio[28582]: info: Scanning category audio_interface Aug 31 04:02:21 volumio volumio[28582]: info: Scanning category miscellanea Aug 31 04:02:21 volumio volumio[28582]: info: Scanning category music_service Aug 31 04:02:21 volumio volumio[28582]: info: Scanning category plugins.json Aug 31 04:02:21 volumio volumio[28582]: info: Scanning category system_controller Aug 31 04:02:21 volumio volumio[28582]: info: Scanning category user_interface Aug 31 04:02:21 volumio volumio[28582]: info: Scanning into folder /data/plugins/ Aug 31 04:02:21 volumio volumio[28582]: info: Scanning category music_service Aug 31 04:02:21 volumio volumio[28582]: info: Scanning category system_controller Aug 31 04:02:21 volumio volumio[28582]: info: Scanning category system_hardware Aug 31 04:02:21 volumio volumio[28582]: info: Scanning category user_interface Aug 31 04:02:21 volumio volumio[28582]: info: Plugin folders cleanup completed Aug 31 04:02:21 volumio volumio[28582]: info: ------------------------------------------- Aug 31 04:02:21 volumio volumio[28582]: info: ----- Core plugins startup ---- Aug 31 04:02:21 volumio volumio[28582]: info: ------------------------------------------- Aug 31 04:02:21 volumio volumio[28582]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 04:02:21 volumio volumio[28582]: info: Adding plugin upnp to MyMusic Plugins Aug 31 04:02:21 volumio volumio[28582]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 04:02:21 volumio volumio[28582]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 04:02:21 volumio volumio[28582]: info: Loading plugins from folder /data/plugins/ Aug 31 04:02:21 volumio volumio[28582]: info: Loading plugin "system"... Aug 31 04:02:21 volumio volumio[28582]: info: Loading plugin "appearance"... Aug 31 04:02:22 volumio volumio[28582]: info: Loading plugin "network"... Aug 31 04:02:22 volumio volumio[28582]: info: Refreshing Cached IP Addresses Aug 31 04:02:22 volumio sudo[28658]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 04:02:22 volumio sudo[28658]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:22 volumio sudo[28660]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 04:02:22 volumio sudo[28660]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:22 volumio sudo[28658]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:22 volumio wpa_supplicant[867]: wlan0: Failed to initiate sched scan Aug 31 04:02:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Aug 31 04:02:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Aug 31 04:02:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Aug 31 04:02:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Aug 31 04:02:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Aug 31 04:02:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Aug 31 04:02:22 volumio sudo[28660]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:22 volumio volumio[28582]: info: Loading plugin "services"... Aug 31 04:02:22 volumio volumio[28582]: info: Loading plugin "alsa_controller"... Aug 31 04:02:22 volumio sudo[28666]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 31 04:02:22 volumio sudo[28666]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:22 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:02:22 volumio volumio[28582]: info: Loading plugin "wizard"... Aug 31 04:02:22 volumio volumio[28582]: info: Loading plugin "networkfs"... Aug 31 04:02:22 volumio volumio[28582]: info: Cannot mount NAS NasTas at system boot, trial number 1 ,retrying in 5 seconds Aug 31 04:02:22 volumio volumio[28582]: info: Cannot mount NAS Music-Dieter at system boot, trial number 1 ,retrying in 5 seconds Aug 31 04:02:22 volumio volumio[28582]: info: Starting Udev Watcher for removable devices Aug 31 04:02:22 volumio volumio[28582]: info: Ignoring mount for partition: boot Aug 31 04:02:22 volumio volumio[28582]: info: Ignoring mount for partition: volumio Aug 31 04:02:22 volumio volumio[28582]: info: Ignoring mount for partition: volumio_data Aug 31 04:02:22 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 04:02:22 volumio volumio[28582]: info: Loading plugin "volumio_command_line_client"... Aug 31 04:02:22 volumio volumio[28582]: info: Plugin upnp is not enabled Aug 31 04:02:22 volumio volumio[28582]: info: Loading plugin "my_music"... Aug 31 04:02:22 volumio volumio[28582]: info: Loading plugin "mpd"... Aug 31 04:02:22 volumio volumio[28582]: info: Plugin upnp_browser is not enabled Aug 31 04:02:22 volumio volumio[28582]: info: Loading plugin "alarm-clock"... Aug 31 04:02:22 volumio volumio[28582]: info: Plugin airplay_emulation is not enabled Aug 31 04:02:22 volumio volumio[28582]: info: Loading plugin "last_100"... Aug 31 04:02:22 volumio volumio[28582]: info: Loading plugin "webradio"... Aug 31 04:02:22 volumio volumio[28582]: info: Loading plugin "i2s_dacs"... Aug 31 04:02:22 volumio volumio[28582]: info: Loading plugin "volumiodiscovery"... Aug 31 04:02:22 volumio volumio[28582]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:22 volumio volumio[28582]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:22 volumio volumio[28582]: *** WARNING *** For more information see Aug 31 04:02:22 volumio node[28582]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:22 volumio volumio[28582]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:22 volumio volumio[28582]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:22 volumio volumio[28582]: *** WARNING *** For more information see Aug 31 04:02:22 volumio node[28582]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:22 volumio node[28582]: *** WARNING *** For more information see Aug 31 04:02:22 volumio node[28582]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:22 volumio node[28582]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:22 volumio node[28582]: *** WARNING *** For more information see Aug 31 04:02:22 volumio volumio[28582]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 04:02:22 volumio volumio[28582]: info: Discovery: Started advertising with name: Volumio Aug 31 04:02:22 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 04:02:22 volumio volumio[28582]: info: Loading plugin "soundcloud"... Aug 31 04:02:23 volumio volumio[28582]: info: Loading plugin "spop"... Aug 31 04:02:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:02:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Aug 31 04:02:23 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:23 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:23 volumio go-librespot[28687]: Librespot-go daemon starting... Aug 31 04:02:23 volumio go-librespot[28687]: time="2025-08-31T04:02:23+02:00" level=info msg="generated new device id: 2c65f56e40acd6dd514461ae0ec5ad2f2d4316fb" Aug 31 04:02:23 volumio go-librespot[28687]: time="2025-08-31T04:02:23+02: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" Aug 31 04:02:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:24 volumio volumio[28582]: info: Loading plugin "squeezelite_mc"... Aug 31 04:02:24 volumio sudo[28666]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:25 volumio volumio[28582]: info: Loading plugin "outputs"... Aug 31 04:02:25 volumio volumio[28582]: info: Loading plugin "albumart"... Aug 31 04:02:25 volumio volumio[28582]: info: Plugin example_plugin is not enabled Aug 31 04:02:25 volumio volumio[28582]: info: Loading plugin "inputs"... Aug 31 04:02:25 volumio volumio[28582]: info: Loading plugin "updater_comm"... Aug 31 04:02:25 volumio volumio[28582]: info: Plugin mpdemulation is not enabled Aug 31 04:02:25 volumio volumio[28582]: info: Loading plugin "rest_api"... Aug 31 04:02:25 volumio volumio[28582]: info: Loading plugin "websocket"... Aug 31 04:02:25 volumio volumio[28582]: info: Starting Socket.io Server version 2.3.0 Aug 31 04:02:25 volumio volumio[28582]: info: Loading plugin "radio_paradise"... Aug 31 04:02:25 volumio volumio[28582]: Forking 3 albumart workers Aug 31 04:02:25 volumio volumio[28582]: info: Applying required configuration parameters for plugin radio_paradise Aug 31 04:02:25 volumio volumio[28582]: info: [1756605745602] [RadioParadise] API delay: 3 Aug 31 04:02:25 volumio volumio[28582]: info: Loading plugin "backup_restore"... Aug 31 04:02:25 volumio volumio[28582]: info: Applying required configuration parameters for plugin backup_restore Aug 31 04:02:25 volumio volumio[28582]: info: Loading plugin "music_services_shield"... Aug 31 04:02:26 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Aug 31 04:02:26 volumio volumio[28582]: info: Applying required configuration parameters for plugin music_services_shield Aug 31 04:02:26 volumio volumio[28582]: info: Loading plugin "Systeminfo"... Aug 31 04:02:26 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Aug 31 04:02:26 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Aug 31 04:02:26 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Aug 31 04:02:26 volumio volumio[28582]: Starting albumart workers Aug 31 04:02:26 volumio volumio[28582]: info: Loading i18n strings for locale en Aug 31 04:02:26 volumio volumio[28582]: Updating browse sources language Aug 31 04:02:26 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:26 volumio volumio[28582]: Starting albumart workers Aug 31 04:02:26 volumio volumio[28582]: Starting albumart workers Aug 31 04:02:26 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:02:26 volumio volumio[28582]: info: CoreCommandRouter::initPlayerControls Aug 31 04:02:26 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:26 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:26 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:26 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:26 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:26 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:26 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:26 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:26 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:02:26 volumio volumio[28582]: Express server listening on port 3000 Aug 31 04:02:26 volumio volumio[28582]: [Metrics] WebUI: 7s 121.49ms Aug 31 04:02:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:02:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Aug 31 04:02:27 volumio volumio[28582]: info: CoreStateMachine::resetVolumioState Aug 31 04:02:27 volumio volumio[28582]: info: CoreStateMachine::getcurrentVolume Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:02:26 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:27 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:27 volumio go-librespot[28722]: Librespot-go daemon starting... Aug 31 04:02:27 volumio go-librespot[28722]: time="2025-08-31T04:02:27+02:00" level=info msg="generated new device id: 5739a9b4a2db92493715f58013ced13b63948711" Aug 31 04:02:27 volumio go-librespot[28722]: time="2025-08-31T04:02:27+02: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" Aug 31 04:02:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:27 volumio volumio[28582]: info: Volumio Network Manager: Network status updated: 0 Aug 31 04:02:27 volumio volumio[28582]: info: Cannot mount NAS NasTas at system boot, trial number 2 ,retrying in 5 seconds Aug 31 04:02:27 volumio volumio[28582]: info: Cannot mount NAS Music-Dieter at system boot, trial number 2 ,retrying in 5 seconds Aug 31 04:02:27 volumio volumio[28582]: info: Reloading queue from file Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:27 volumio volumio[28582]: info: CoreStateMachine::setRepeat false single undefined Aug 31 04:02:27 volumio volumio[28582]: info: CoreStateMachine::pushState Aug 31 04:02:27 volumio volumio[28582]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:27 volumio volumio[28582]: info: CoreStateMachine::setRandom false Aug 31 04:02:27 volumio volumio[28582]: info: CoreStateMachine::pushState Aug 31 04:02:27 volumio volumio[28582]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:27 volumio volumio[28582]: info: Setting Device type: Raspberry PI Aug 31 04:02:27 volumio volumio[28582]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:02:27 volumio volumio[28582]: info: CoreStateMachine::pushState Aug 31 04:02:27 volumio volumio[28582]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:27 volumio volumio[28582]: info: CoreStateMachine::updateTrackBlock Aug 31 04:02:27 volumio volumio[28582]: info: CorePlayQueue::getTrackBlock Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:02:27 volumio volumio[28582]: info: Completed loading Core Plugins Aug 31 04:02:27 volumio volumio[28582]: info: Preparing to generate the ALSA configuration file Aug 31 04:02:27 volumio volumio[28582]: info: Asound.conf file unchanged, so no further update is needed Aug 31 04:02:27 volumio volumio[28582]: info: Output device has changed, restarting MPD Aug 31 04:02:27 volumio sudo[28764]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 04:02:27 volumio sudo[28764]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:27 volumio volumio[28582]: info: ___________ START PLUGINS ___________ Aug 31 04:02:27 volumio sudo[28764]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:27 volumio volumio[28582]: info: ControllerMpd::onStart: Initializing MPD Aug 31 04:02:27 volumio volumio[28582]: info: Creating MPD Configuration file Aug 31 04:02:27 volumio sudo[28766]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 04:02:27 volumio sudo[28766]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:27 volumio sudo[28770]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 04:02:27 volumio systemd[1]: musicservicesshield.service: Succeeded. Aug 31 04:02:27 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Aug 31 04:02:27 volumio sudo[28770]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:27 volumio systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Aug 31 04:02:27 volumio systemd[1]: Stopping Music Player Daemon... Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:02:27 volumio volumio[28582]: info: [1756605747764] CoreMusicLibrary::Adding element Last_100 Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:27 volumio sudo[28770]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:02:27 volumio volumio[28582]: info: [1756605747771] CoreMusicLibrary::Adding element Webradio Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:02:27 volumio systemd[1]: mpd.service: Succeeded. Aug 31 04:02:27 volumio systemd[1]: Stopped Music Player Daemon. Aug 31 04:02:27 volumio sudo[28773]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 04:02:27 volumio volumio[28582]: info: Initializing BBC Radios Aug 31 04:02:27 volumio sudo[28773]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:02:27 volumio volumio[28582]: info: [1756605747875] CoreMusicLibrary::Adding element SoundCloud Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:27 volumio volumio[28582]: Cannot find translation for source SoundCloud Aug 31 04:02:27 volumio systemd[1]: Starting Music Player Daemon... Aug 31 04:02:27 volumio volumio[28582]: info: Creating Spotify config file Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:27 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Aug 31 04:02:27 volumio systemd[1]: mpd.service: Succeeded. Aug 31 04:02:27 volumio systemd[1]: Stopped Music Player Daemon. Aug 31 04:02:27 volumio systemd[1]: Starting Music Player Daemon... Aug 31 04:02:27 volumio volumio[28582]: info: [squeezelite_mc] Starting proxy server... Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:02:27 volumio volumio[28582]: info: [1756605747931] CoreMusicLibrary::Adding element Radio Paradise Aug 31 04:02:27 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:27 volumio volumio[28582]: Cannot find translation for source SoundCloud Aug 31 04:02:27 volumio volumio[28582]: Cannot find translation for source Radio Paradise Aug 31 04:02:28 volumio sudo[28786]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 04:02:28 volumio sudo[28786]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:28 volumio sudo[28786]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:28 volumio volumio[28582]: info: Volumio Calling Home Aug 31 04:02:28 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Aug 31 04:02:28 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Aug 31 04:02:28 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Aug 31 04:02:28 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Aug 31 04:02:28 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Aug 31 04:02:28 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Aug 31 04:02:28 volumio sudo[28815]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Aug 31 04:02:28 volumio sudo[28815]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:28 volumio volumio[28582]: info: [squeezelite_mc] Proxy server started on port 38247 Aug 31 04:02:28 volumio volumio[28582]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:02:28 volumio volumio[28582]: info: MPD Permissions set Aug 31 04:02:28 volumio volumio[28582]: info: MPD Permissions set Aug 31 04:02:28 volumio volumio[28582]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:02:28 volumio volumio[28582]: info: CoreStateMachine::pushState Aug 31 04:02:28 volumio volumio[28582]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:28 volumio volumio[28582]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:28 volumio volumio[28582]: info: Spotify config file written Aug 31 04:02:28 volumio sudo[28834]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 04:02:28 volumio sudo[28834]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:28 volumio volumio[28582]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 31 04:02:28 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:28 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:28 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:28 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:28 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:28 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:28 volumio sudo[28834]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:28 volumio go-librespot[28842]: Librespot-go daemon starting... Aug 31 04:02:28 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:28 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:28 volumio volumio[28582]: info: No need to fix Spotify hosts Aug 31 04:02:28 volumio go-librespot[28842]: time="2025-08-31T04:02:28+02:00" level=info msg="generated new device id: 0d9fd9ef63bf793b98e303f0f51821bfed9d82ca" Aug 31 04:02:28 volumio go-librespot[28842]: time="2025-08-31T04:02:28+02: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" Aug 31 04:02:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:28 volumio volumio[28582]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:02:28 volumio volumio[28582]: info: CoreStateMachine::pushState Aug 31 04:02:28 volumio volumio[28582]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:28 volumio volumio[28582]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:28 volumio volumio[28582]: info: [squeezelite_mc] Server discovery started Aug 31 04:02:28 volumio volumio[28582]: info: [squeezelite_mc] Player finder started Aug 31 04:02:28 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:28 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:28 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:28 volumio volumio[28582]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:02:28 volumio volumio[28582]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Aug 31 04:02:28 volumio volumio[28582]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 04:02:28 volumio volumio[28582]: Error: send ENETUNREACH 255.255.255.255:3483 Aug 31 04:02:28 volumio volumio[28582]: at doSend (dgram.js:692:16) Aug 31 04:02:28 volumio volumio[28582]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Aug 31 04:02:28 volumio volumio[28582]: at afterDns (dgram.js:638:5) Aug 31 04:02:28 volumio volumio[28582]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Aug 31 04:02:28 volumio volumio[28582]: errno: -101, Aug 31 04:02:28 volumio volumio[28582]: code: 'ENETUNREACH', Aug 31 04:02:28 volumio volumio[28582]: syscall: 'send', Aug 31 04:02:28 volumio volumio[28582]: address: '255.255.255.255', Aug 31 04:02:28 volumio volumio[28582]: port: 3483 Aug 31 04:02:28 volumio volumio[28582]: } Aug 31 04:02:28 volumio volumio[28582]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 04:02:28 volumio sudo[28815]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:29 volumio sudo[28865]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-08-31 04:01 Aug 31 04:02:29 volumio sudo[28865]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:29 volumio sudo[28865]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:29 volumio mpd[28804]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 04:02:29 volumio mpd[28804]: output: No 'audio_output' defined in config file Aug 31 04:02:29 volumio mpd[28804]: output: Successfully detected a sndio audio device Aug 31 04:02:29 volumio mpd[28804]: zeroconf: No global port, disabling zeroconf Aug 31 04:02:29 volumio systemd[1]: Started Music Player Daemon. Aug 31 04:02:29 volumio sudo[28773]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:29 volumio sudo[28766]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:29 volumio systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Aug 31 04:02:29 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:29 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 31 04:02:29 volumio systemd[1]: Started dynamicswap service. Aug 31 04:02:29 volumio systemd[1]: dynamicswap.service: Succeeded. Aug 31 04:02:29 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Aug 31 04:02:29 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 11. Aug 31 04:02:29 volumio systemd[1]: Stopped Volumio Backend Module. Aug 31 04:02:30 volumio systemd[1]: Started Volumio Backend Module. Aug 31 04:02:30 volumio systemd[1]: Started dynamicswap service. Aug 31 04:02:30 volumio systemd[1]: dynamicswap.service: Succeeded. Aug 31 04:02:30 volumio volumio[28874]: cset: --> shielding system active with Aug 31 04:02:30 volumio volumio[28874]: cset: "system" cpuset of CPUSPEC(1-3) with 57 tasks running Aug 31 04:02:30 volumio volumio[28874]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Aug 31 04:02:30 volumio systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Aug 31 04:02:31 volumio volumio[28891]: info: ------------------------------------------- Aug 31 04:02:31 volumio volumio[28891]: info: ----- Volumio3 ---- Aug 31 04:02:31 volumio volumio[28891]: info: ------------------------------------------- Aug 31 04:02:31 volumio volumio[28891]: info: ----- System startup ---- Aug 31 04:02:31 volumio volumio[28891]: info: ------------------------------------------- Aug 31 04:02:31 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:02:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Aug 31 04:02:31 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:32 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:32 volumio go-librespot[28916]: Librespot-go daemon starting... Aug 31 04:02:32 volumio go-librespot[28916]: time="2025-08-31T04:02:32+02:00" level=info msg="generated new device id: 96c6390ff8d1a079f2e52e9e91e03c94cffe2e4f" Aug 31 04:02:32 volumio go-librespot[28916]: time="2025-08-31T04:02:32+02: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" Aug 31 04:02:32 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Aug 31 04:02:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:32 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Aug 31 04:02:32 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Aug 31 04:02:32 volumio volumio[28891]: info: MYVOLUMIO Environment detected Aug 31 04:02:32 volumio volumio[28891]: info: Plugin folders cleanup Aug 31 04:02:32 volumio volumio[28891]: info: Scanning into folder /volumio/app/plugins/ Aug 31 04:02:32 volumio volumio[28891]: info: Scanning category audio_interface Aug 31 04:02:32 volumio volumio[28891]: info: Scanning category miscellanea Aug 31 04:02:32 volumio volumio[28891]: info: Scanning category music_service Aug 31 04:02:32 volumio volumio[28891]: info: Scanning category plugins.json Aug 31 04:02:32 volumio volumio[28891]: info: Scanning category system_controller Aug 31 04:02:32 volumio volumio[28891]: info: Scanning category user_interface Aug 31 04:02:32 volumio volumio[28891]: info: Scanning into folder /data/plugins/ Aug 31 04:02:32 volumio volumio[28891]: info: Scanning category music_service Aug 31 04:02:32 volumio volumio[28891]: info: Scanning category system_controller Aug 31 04:02:32 volumio volumio[28891]: info: Scanning category system_hardware Aug 31 04:02:32 volumio volumio[28891]: info: Scanning category user_interface Aug 31 04:02:32 volumio volumio[28891]: info: Plugin folders cleanup completed Aug 31 04:02:32 volumio volumio[28891]: info: ------------------------------------------- Aug 31 04:02:32 volumio volumio[28891]: info: ----- Core plugins startup ---- Aug 31 04:02:32 volumio volumio[28891]: info: ------------------------------------------- Aug 31 04:02:32 volumio volumio[28891]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 04:02:32 volumio volumio[28891]: info: Adding plugin upnp to MyMusic Plugins Aug 31 04:02:32 volumio volumio[28891]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 04:02:32 volumio volumio[28891]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 04:02:32 volumio volumio[28891]: info: Loading plugins from folder /data/plugins/ Aug 31 04:02:32 volumio volumio[28891]: info: Loading plugin "system"... Aug 31 04:02:32 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Aug 31 04:02:32 volumio volumio[28891]: info: Loading plugin "appearance"... Aug 31 04:02:33 volumio volumio[28891]: info: Loading plugin "network"... Aug 31 04:02:33 volumio volumio[28891]: info: Refreshing Cached IP Addresses Aug 31 04:02:33 volumio sudo[28929]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 04:02:33 volumio sudo[28929]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:33 volumio sudo[28929]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:33 volumio sudo[28931]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 04:02:33 volumio sudo[28931]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:33 volumio sudo[28931]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:33 volumio volumio[28891]: info: Loading plugin "services"... Aug 31 04:02:33 volumio volumio[28891]: info: Loading plugin "alsa_controller"... Aug 31 04:02:33 volumio sudo[28940]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 31 04:02:33 volumio sudo[28940]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:33 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:02:33 volumio volumio[28891]: info: Loading plugin "wizard"... Aug 31 04:02:33 volumio volumio[28891]: info: Loading plugin "networkfs"... Aug 31 04:02:33 volumio volumio[28891]: info: Cannot mount NAS NasTas at system boot, trial number 1 ,retrying in 5 seconds Aug 31 04:02:33 volumio volumio[28891]: info: Cannot mount NAS Music-Dieter at system boot, trial number 1 ,retrying in 5 seconds Aug 31 04:02:33 volumio volumio[28891]: info: Starting Udev Watcher for removable devices Aug 31 04:02:33 volumio volumio[28891]: info: Ignoring mount for partition: boot Aug 31 04:02:33 volumio volumio[28891]: info: Ignoring mount for partition: volumio Aug 31 04:02:33 volumio volumio[28891]: info: Ignoring mount for partition: volumio_data Aug 31 04:02:33 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 04:02:33 volumio volumio[28891]: info: Loading plugin "volumio_command_line_client"... Aug 31 04:02:33 volumio volumio[28891]: info: Plugin upnp is not enabled Aug 31 04:02:33 volumio volumio[28891]: info: Loading plugin "my_music"... Aug 31 04:02:33 volumio volumio[28891]: info: Loading plugin "mpd"... Aug 31 04:02:33 volumio volumio[28891]: info: Plugin upnp_browser is not enabled Aug 31 04:02:33 volumio volumio[28891]: info: Loading plugin "alarm-clock"... Aug 31 04:02:34 volumio volumio[28891]: info: Plugin airplay_emulation is not enabled Aug 31 04:02:34 volumio volumio[28891]: info: Loading plugin "last_100"... Aug 31 04:02:34 volumio volumio[28891]: info: Loading plugin "webradio"... Aug 31 04:02:34 volumio volumio[28891]: info: Loading plugin "i2s_dacs"... Aug 31 04:02:34 volumio wpa_supplicant[867]: wlan0: Failed to initiate sched scan Aug 31 04:02:34 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Aug 31 04:02:34 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Aug 31 04:02:34 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Aug 31 04:02:34 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Aug 31 04:02:34 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Aug 31 04:02:34 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Aug 31 04:02:34 volumio volumio[28891]: info: Loading plugin "volumiodiscovery"... Aug 31 04:02:34 volumio volumio[28891]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:34 volumio volumio[28891]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:34 volumio volumio[28891]: *** WARNING *** For more information see Aug 31 04:02:34 volumio node[28891]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:34 volumio volumio[28891]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:34 volumio volumio[28891]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:34 volumio volumio[28891]: *** WARNING *** For more information see Aug 31 04:02:34 volumio node[28891]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:34 volumio node[28891]: *** WARNING *** For more information see Aug 31 04:02:34 volumio node[28891]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:34 volumio node[28891]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:34 volumio node[28891]: *** WARNING *** For more information see Aug 31 04:02:34 volumio volumio[28891]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 04:02:34 volumio volumio[28891]: info: Discovery: Started advertising with name: Volumio Aug 31 04:02:34 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 04:02:34 volumio volumio[28891]: info: Loading plugin "soundcloud"... Aug 31 04:02:34 volumio volumio[28891]: info: Loading plugin "spop"... Aug 31 04:02:34 volumio volumio-remote-updater[571]: [2025-08-31 04:02:34] [connect] Successful connection Aug 31 04:02:35 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:02:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Aug 31 04:02:35 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:35 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:35 volumio go-librespot[28958]: Librespot-go daemon starting... Aug 31 04:02:35 volumio go-librespot[28958]: time="2025-08-31T04:02:35+02:00" level=info msg="generated new device id: 3a00bfcdcadb6176e424b0c3370c124821d787e3" Aug 31 04:02:35 volumio go-librespot[28958]: time="2025-08-31T04:02:35+02: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" Aug 31 04:02:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:35 volumio volumio[28891]: info: Loading plugin "squeezelite_mc"... Aug 31 04:02:36 volumio volumio[28891]: info: Loading plugin "outputs"... Aug 31 04:02:36 volumio volumio[28891]: info: Loading plugin "albumart"... Aug 31 04:02:36 volumio volumio[28891]: info: Plugin example_plugin is not enabled Aug 31 04:02:36 volumio volumio[28891]: info: Loading plugin "inputs"... Aug 31 04:02:36 volumio volumio[28891]: info: Loading plugin "updater_comm"... Aug 31 04:02:36 volumio volumio[28891]: info: Plugin mpdemulation is not enabled Aug 31 04:02:36 volumio volumio[28891]: info: Loading plugin "rest_api"... Aug 31 04:02:36 volumio volumio[28891]: info: Loading plugin "websocket"... Aug 31 04:02:36 volumio volumio[28891]: info: Starting Socket.io Server version 2.3.0 Aug 31 04:02:36 volumio volumio[28891]: info: Loading plugin "radio_paradise"... Aug 31 04:02:36 volumio sudo[28940]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:36 volumio volumio[28891]: Forking 3 albumart workers Aug 31 04:02:37 volumio volumio[28891]: info: Applying required configuration parameters for plugin radio_paradise Aug 31 04:02:37 volumio volumio[28891]: info: [1756605757008] [RadioParadise] API delay: 3 Aug 31 04:02:37 volumio volumio[28891]: info: Loading plugin "backup_restore"... Aug 31 04:02:37 volumio volumio[28891]: info: Applying required configuration parameters for plugin backup_restore Aug 31 04:02:37 volumio volumio[28891]: info: Loading plugin "music_services_shield"... Aug 31 04:02:37 volumio volumio[28891]: info: Applying required configuration parameters for plugin music_services_shield Aug 31 04:02:37 volumio volumio[28891]: info: Loading plugin "Systeminfo"... Aug 31 04:02:37 volumio volumio[28891]: Starting albumart workers Aug 31 04:02:37 volumio volumio[28891]: info: Loading i18n strings for locale en Aug 31 04:02:37 volumio volumio[28891]: Updating browse sources language Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:38 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Aug 31 04:02:38 volumio volumio[28891]: Starting albumart workers Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::initPlayerControls Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:02:38 volumio volumio[28891]: Starting albumart workers Aug 31 04:02:38 volumio volumio[28891]: Express server listening on port 3000 Aug 31 04:02:38 volumio volumio[28891]: [Metrics] WebUI: 7s 129.53ms Aug 31 04:02:38 volumio volumio[28891]: info: CoreStateMachine::resetVolumioState Aug 31 04:02:38 volumio volumio[28891]: info: CoreStateMachine::getcurrentVolume Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:02:38 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Aug 31 04:02:38 volumio volumio[28891]: info: Volumio Network Manager: Network status updated: 0 Aug 31 04:02:38 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Aug 31 04:02:38 volumio volumio-remote-updater[571]: [2025-08-31 04:02:38] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1756605754 101 Aug 31 04:02:38 volumio volumio[28891]: 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 Aug 31 04:02:38 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:02:38 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Aug 31 04:02:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Aug 31 04:02:38 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:38 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:38 volumio go-librespot[28998]: Librespot-go daemon starting... Aug 31 04:02:38 volumio go-librespot[28998]: time="2025-08-31T04:02:38+02:00" level=info msg="generated new device id: 6ab174fc88085c7455aa4d76eb9589b852a60fee" Aug 31 04:02:38 volumio go-librespot[28998]: time="2025-08-31T04:02:38+02: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" Aug 31 04:02:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:38 volumio volumio[28891]: info: Reloading queue from file Aug 31 04:02:38 volumio volumio[28891]: info: Cannot mount NAS NasTas at system boot, trial number 2 ,retrying in 5 seconds Aug 31 04:02:38 volumio volumio[28891]: info: Cannot mount NAS Music-Dieter at system boot, trial number 2 ,retrying in 5 seconds Aug 31 04:02:38 volumio volumio[28891]: info: Setting Device type: Raspberry PI Aug 31 04:02:38 volumio volumio[28891]: info: CoreStateMachine::setRepeat false single undefined Aug 31 04:02:38 volumio volumio[28891]: info: CoreStateMachine::pushState Aug 31 04:02:38 volumio volumio[28891]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:38 volumio volumio[28891]: info: CoreStateMachine::setRandom false Aug 31 04:02:38 volumio volumio[28891]: info: CoreStateMachine::pushState Aug 31 04:02:38 volumio volumio[28891]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:38 volumio volumio[28891]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:02:38 volumio volumio[28891]: info: CoreStateMachine::pushState Aug 31 04:02:38 volumio volumio[28891]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:38 volumio volumio[28891]: info: CoreStateMachine::updateTrackBlock Aug 31 04:02:38 volumio volumio[28891]: info: CorePlayQueue::getTrackBlock Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:02:38 volumio volumio[28891]: info: Completed loading Core Plugins Aug 31 04:02:38 volumio volumio[28891]: info: Preparing to generate the ALSA configuration file Aug 31 04:02:38 volumio volumio[28891]: info: Asound.conf file unchanged, so no further update is needed Aug 31 04:02:38 volumio volumio[28891]: info: Output device has changed, restarting MPD Aug 31 04:02:38 volumio sudo[29012]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 04:02:38 volumio sudo[29012]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:38 volumio volumio[28891]: info: ___________ START PLUGINS ___________ Aug 31 04:02:38 volumio volumio[28891]: info: ControllerMpd::onStart: Initializing MPD Aug 31 04:02:38 volumio volumio[28891]: info: Creating MPD Configuration file Aug 31 04:02:38 volumio sudo[29012]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:38 volumio sudo[29015]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 04:02:38 volumio sudo[29015]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:02:38 volumio volumio[28891]: info: [1756605758936] CoreMusicLibrary::Adding element Last_100 Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:02:38 volumio volumio[28891]: info: [1756605758942] CoreMusicLibrary::Adding element Webradio Aug 31 04:02:38 volumio sudo[29021]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 04:02:38 volumio sudo[29021]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:38 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:02:38 volumio systemd[1]: musicservicesshield.service: Succeeded. Aug 31 04:02:38 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Aug 31 04:02:38 volumio systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Aug 31 04:02:38 volumio systemd[1]: Stopping Music Player Daemon... Aug 31 04:02:38 volumio sudo[29021]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:38 volumio volumio[28891]: info: Initializing BBC Radios Aug 31 04:02:38 volumio systemd[1]: mpd.service: Succeeded. Aug 31 04:02:38 volumio systemd[1]: Stopped Music Player Daemon. Aug 31 04:02:39 volumio sudo[29023]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 04:02:39 volumio sudo[29023]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:39 volumio systemd[1]: Starting Music Player Daemon... Aug 31 04:02:39 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Aug 31 04:02:39 volumio systemd[1]: mpd.service: Succeeded. Aug 31 04:02:39 volumio systemd[1]: Stopped Music Player Daemon. Aug 31 04:02:39 volumio systemd[1]: Starting Music Player Daemon... Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:02:39 volumio volumio[28891]: info: [1756605759138] CoreMusicLibrary::Adding element SoundCloud Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:39 volumio volumio[28891]: Cannot find translation for source SoundCloud Aug 31 04:02:39 volumio volumio[28891]: info: Creating Spotify config file Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:39 volumio sudo[29045]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 04:02:39 volumio sudo[29045]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:39 volumio sudo[29045]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:39 volumio volumio[28891]: info: [squeezelite_mc] Starting proxy server... Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:02:39 volumio volumio[28891]: info: [1756605759253] CoreMusicLibrary::Adding element Radio Paradise Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:39 volumio volumio[28891]: Cannot find translation for source SoundCloud Aug 31 04:02:39 volumio volumio[28891]: Cannot find translation for source Radio Paradise Aug 31 04:02:39 volumio volumio[28891]: info: Volumio Calling Home Aug 31 04:02:39 volumio sudo[29090]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Aug 31 04:02:39 volumio sudo[29090]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:39 volumio volumio[28891]: info: [squeezelite_mc] Proxy server started on port 33607 Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:02:39 volumio volumio[28891]: info: MPD Permissions set Aug 31 04:02:39 volumio volumio[28891]: info: MPD Permissions set Aug 31 04:02:39 volumio volumio[28891]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:02:39 volumio volumio[28891]: info: CoreStateMachine::pushState Aug 31 04:02:39 volumio volumio[28891]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:39 volumio volumio[28891]: info: Spotify config file written Aug 31 04:02:39 volumio volumio[28891]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:39 volumio sudo[29109]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 04:02:39 volumio sudo[29109]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:39 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:39 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:40 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:40 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:40 volumio volumio[28891]: info: No need to fix Spotify hosts Aug 31 04:02:40 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:40 volumio go-librespot[29115]: Librespot-go daemon starting... Aug 31 04:02:40 volumio volumio[28891]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:02:40 volumio volumio[28891]: info: CoreStateMachine::pushState Aug 31 04:02:40 volumio volumio[28891]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:40 volumio volumio[28891]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:40 volumio sudo[29109]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:40 volumio go-librespot[29115]: time="2025-08-31T04:02:40+02:00" level=info msg="generated new device id: 72b81d83fe3f949b7bd875386b8b436e51a695b4" Aug 31 04:02:40 volumio volumio[28891]: info: [squeezelite_mc] Server discovery started Aug 31 04:02:40 volumio volumio[28891]: info: [squeezelite_mc] Player finder started Aug 31 04:02:40 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:40 volumio go-librespot[29115]: time="2025-08-31T04:02:40+02: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" Aug 31 04:02:40 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:40 volumio volumio[28891]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:02:40 volumio volumio[28891]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Aug 31 04:02:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:40 volumio volumio[28891]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 04:02:40 volumio volumio[28891]: Error: send ENETUNREACH 255.255.255.255:3483 Aug 31 04:02:40 volumio volumio[28891]: at doSend (dgram.js:692:16) Aug 31 04:02:40 volumio volumio[28891]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Aug 31 04:02:40 volumio volumio[28891]: at afterDns (dgram.js:638:5) Aug 31 04:02:40 volumio volumio[28891]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Aug 31 04:02:40 volumio volumio[28891]: errno: -101, Aug 31 04:02:40 volumio volumio[28891]: code: 'ENETUNREACH', Aug 31 04:02:40 volumio volumio[28891]: syscall: 'send', Aug 31 04:02:40 volumio volumio[28891]: address: '255.255.255.255', Aug 31 04:02:40 volumio volumio[28891]: port: 3483 Aug 31 04:02:40 volumio volumio[28891]: } Aug 31 04:02:40 volumio volumio[28891]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 04:02:40 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Aug 31 04:02:40 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Aug 31 04:02:40 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Aug 31 04:02:40 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Aug 31 04:02:40 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Aug 31 04:02:40 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Aug 31 04:02:40 volumio sudo[29090]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:40 volumio sudo[29140]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-08-31 04:01 Aug 31 04:02:40 volumio sudo[29140]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:40 volumio mpd[29055]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 04:02:40 volumio mpd[29055]: output: No 'audio_output' defined in config file Aug 31 04:02:40 volumio mpd[29055]: output: Successfully detected a sndio audio device Aug 31 04:02:40 volumio mpd[29055]: zeroconf: No global port, disabling zeroconf Aug 31 04:02:40 volumio systemd[1]: Started Music Player Daemon. Aug 31 04:02:40 volumio sudo[29015]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:40 volumio sudo[29023]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:40 volumio sudo[29140]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:40 volumio systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Aug 31 04:02:41 volumio volumio-remote-updater[571]: [2025-08-31 04:02:41] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 31 04:02:41 volumio volumio-remote-updater[571]: [2025-08-31 04:02:41] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 31 04:02:41 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:41 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 31 04:02:41 volumio systemd[1]: Started dynamicswap service. Aug 31 04:02:41 volumio systemd[1]: dynamicswap.service: Succeeded. Aug 31 04:02:41 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Aug 31 04:02:41 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 12. Aug 31 04:02:41 volumio systemd[1]: Stopped Volumio Backend Module. Aug 31 04:02:41 volumio systemd[1]: Started Volumio Backend Module. Aug 31 04:02:41 volumio systemd[1]: Started dynamicswap service. Aug 31 04:02:41 volumio systemd[1]: dynamicswap.service: Succeeded. Aug 31 04:02:41 volumio volumio[29144]: cset: --> shielding system active with Aug 31 04:02:41 volumio volumio[29144]: cset: "system" cpuset of CPUSPEC(1-3) with 57 tasks running Aug 31 04:02:41 volumio volumio[29144]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Aug 31 04:02:41 volumio systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Aug 31 04:02:42 volumio volumio[29167]: info: ------------------------------------------- Aug 31 04:02:42 volumio volumio[29167]: info: ----- Volumio3 ---- Aug 31 04:02:42 volumio volumio[29167]: info: ------------------------------------------- Aug 31 04:02:42 volumio volumio[29167]: info: ----- System startup ---- Aug 31 04:02:42 volumio volumio[29167]: info: ------------------------------------------- Aug 31 04:02:43 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:02:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Aug 31 04:02:43 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:43 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:43 volumio go-librespot[29191]: Librespot-go daemon starting... Aug 31 04:02:43 volumio go-librespot[29191]: time="2025-08-31T04:02:43+02:00" level=info msg="generated new device id: 0cd4cfa859c7f0a9f5fdb6d6631cf815e9b67ccd" Aug 31 04:02:43 volumio go-librespot[29191]: time="2025-08-31T04:02:43+02: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" Aug 31 04:02:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:43 volumio volumio[29167]: info: MYVOLUMIO Environment detected Aug 31 04:02:43 volumio volumio[29167]: info: Plugin folders cleanup Aug 31 04:02:43 volumio volumio[29167]: info: Scanning into folder /volumio/app/plugins/ Aug 31 04:02:43 volumio volumio[29167]: info: Scanning category audio_interface Aug 31 04:02:43 volumio volumio[29167]: info: Scanning category miscellanea Aug 31 04:02:43 volumio volumio[29167]: info: Scanning category music_service Aug 31 04:02:43 volumio volumio[29167]: info: Scanning category plugins.json Aug 31 04:02:43 volumio volumio[29167]: info: Scanning category system_controller Aug 31 04:02:43 volumio volumio[29167]: info: Scanning category user_interface Aug 31 04:02:43 volumio volumio[29167]: info: Scanning into folder /data/plugins/ Aug 31 04:02:43 volumio volumio[29167]: info: Scanning category music_service Aug 31 04:02:43 volumio volumio[29167]: info: Scanning category system_controller Aug 31 04:02:43 volumio volumio[29167]: info: Scanning category system_hardware Aug 31 04:02:43 volumio volumio[29167]: info: Scanning category user_interface Aug 31 04:02:43 volumio volumio[29167]: info: Plugin folders cleanup completed Aug 31 04:02:43 volumio volumio[29167]: info: ------------------------------------------- Aug 31 04:02:43 volumio volumio[29167]: info: ----- Core plugins startup ---- Aug 31 04:02:43 volumio volumio[29167]: info: ------------------------------------------- Aug 31 04:02:43 volumio volumio[29167]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 04:02:43 volumio volumio[29167]: info: Adding plugin upnp to MyMusic Plugins Aug 31 04:02:43 volumio volumio[29167]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 04:02:43 volumio volumio[29167]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 04:02:43 volumio volumio[29167]: info: Loading plugins from folder /data/plugins/ Aug 31 04:02:43 volumio volumio[29167]: info: Loading plugin "system"... Aug 31 04:02:43 volumio volumio[29167]: info: Loading plugin "appearance"... Aug 31 04:02:44 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Aug 31 04:02:44 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Aug 31 04:02:44 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Aug 31 04:02:44 volumio volumio[29167]: info: Loading plugin "network"... Aug 31 04:02:44 volumio volumio[29167]: info: Refreshing Cached IP Addresses Aug 31 04:02:44 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Aug 31 04:02:44 volumio sudo[29204]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 04:02:44 volumio sudo[29204]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:44 volumio sudo[29204]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:44 volumio sudo[29206]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 04:02:44 volumio volumio[29167]: info: Loading plugin "services"... Aug 31 04:02:44 volumio sudo[29206]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:44 volumio volumio[29167]: info: Loading plugin "alsa_controller"... Aug 31 04:02:44 volumio sudo[29206]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:44 volumio sudo[29214]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 31 04:02:44 volumio sudo[29214]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:44 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:02:44 volumio volumio[29167]: info: Loading plugin "wizard"... Aug 31 04:02:44 volumio volumio[29167]: info: Loading plugin "networkfs"... Aug 31 04:02:44 volumio volumio[29167]: info: Cannot mount NAS NasTas at system boot, trial number 1 ,retrying in 5 seconds Aug 31 04:02:44 volumio volumio[29167]: info: Cannot mount NAS Music-Dieter at system boot, trial number 1 ,retrying in 5 seconds Aug 31 04:02:44 volumio volumio[29167]: info: Starting Udev Watcher for removable devices Aug 31 04:02:44 volumio volumio[29167]: info: Ignoring mount for partition: boot Aug 31 04:02:44 volumio volumio[29167]: info: Ignoring mount for partition: volumio Aug 31 04:02:44 volumio volumio[29167]: info: Ignoring mount for partition: volumio_data Aug 31 04:02:44 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 04:02:44 volumio volumio[29167]: info: Loading plugin "volumio_command_line_client"... Aug 31 04:02:44 volumio volumio[29167]: info: Plugin upnp is not enabled Aug 31 04:02:44 volumio volumio[29167]: info: Loading plugin "my_music"... Aug 31 04:02:44 volumio volumio[29167]: info: Loading plugin "mpd"... Aug 31 04:02:45 volumio volumio[29167]: info: Plugin upnp_browser is not enabled Aug 31 04:02:45 volumio volumio[29167]: info: Loading plugin "alarm-clock"... Aug 31 04:02:45 volumio volumio[29167]: info: Plugin airplay_emulation is not enabled Aug 31 04:02:45 volumio volumio[29167]: info: Loading plugin "last_100"... Aug 31 04:02:45 volumio volumio[29167]: info: Loading plugin "webradio"... Aug 31 04:02:45 volumio volumio[29167]: info: Loading plugin "i2s_dacs"... Aug 31 04:02:45 volumio volumio[29167]: info: Loading plugin "volumiodiscovery"... Aug 31 04:02:45 volumio volumio[29167]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:45 volumio volumio[29167]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:45 volumio volumio[29167]: *** WARNING *** For more information see Aug 31 04:02:45 volumio node[29167]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:45 volumio volumio[29167]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:45 volumio volumio[29167]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:45 volumio volumio[29167]: *** WARNING *** For more information see Aug 31 04:02:45 volumio node[29167]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:45 volumio node[29167]: *** WARNING *** For more information see Aug 31 04:02:45 volumio node[29167]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:45 volumio node[29167]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:45 volumio node[29167]: *** WARNING *** For more information see Aug 31 04:02:45 volumio volumio[29167]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 04:02:45 volumio volumio[29167]: info: Discovery: Started advertising with name: Volumio Aug 31 04:02:45 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 04:02:45 volumio volumio[29167]: info: Loading plugin "soundcloud"... Aug 31 04:02:45 volumio volumio[29167]: info: Loading plugin "spop"... Aug 31 04:02:46 volumio volumio-remote-updater[571]: [2025-08-31 04:02:46] [connect] Successful connection Aug 31 04:02:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Aug 31 04:02:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Aug 31 04:02:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Aug 31 04:02:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Aug 31 04:02:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Aug 31 04:02:46 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Aug 31 04:02:46 volumio wpa_supplicant[867]: wlan0: Failed to initiate sched scan Aug 31 04:02:46 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:02:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Aug 31 04:02:46 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:46 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:46 volumio go-librespot[29233]: Librespot-go daemon starting... Aug 31 04:02:46 volumio go-librespot[29233]: time="2025-08-31T04:02:46+02:00" level=info msg="generated new device id: bc079343e1c0d16e5d7dd3e262f394ef3281929f" Aug 31 04:02:46 volumio go-librespot[29233]: time="2025-08-31T04:02:46+02: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" Aug 31 04:02:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:46 volumio volumio[29167]: info: Loading plugin "squeezelite_mc"... Aug 31 04:02:47 volumio volumio[29167]: info: Loading plugin "outputs"... Aug 31 04:02:47 volumio volumio[29167]: info: Loading plugin "albumart"... Aug 31 04:02:47 volumio volumio[29167]: info: Plugin example_plugin is not enabled Aug 31 04:02:47 volumio volumio[29167]: info: Loading plugin "inputs"... Aug 31 04:02:47 volumio volumio[29167]: info: Loading plugin "updater_comm"... Aug 31 04:02:47 volumio volumio[29167]: info: Plugin mpdemulation is not enabled Aug 31 04:02:47 volumio volumio[29167]: info: Loading plugin "rest_api"... Aug 31 04:02:47 volumio volumio[29167]: info: Loading plugin "websocket"... Aug 31 04:02:47 volumio volumio[29167]: info: Starting Socket.io Server version 2.3.0 Aug 31 04:02:47 volumio volumio[29167]: info: Loading plugin "radio_paradise"... Aug 31 04:02:47 volumio volumio[29167]: Forking 3 albumart workers Aug 31 04:02:48 volumio volumio[29167]: info: Applying required configuration parameters for plugin radio_paradise Aug 31 04:02:48 volumio volumio[29167]: info: [1756605768135] [RadioParadise] API delay: 3 Aug 31 04:02:48 volumio volumio[29167]: info: Loading plugin "backup_restore"... Aug 31 04:02:48 volumio volumio[29167]: info: Applying required configuration parameters for plugin backup_restore Aug 31 04:02:48 volumio volumio[29167]: info: Loading plugin "music_services_shield"... Aug 31 04:02:48 volumio volumio[29167]: info: Applying required configuration parameters for plugin music_services_shield Aug 31 04:02:48 volumio volumio[29167]: info: Loading plugin "Systeminfo"... Aug 31 04:02:48 volumio sudo[29214]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:48 volumio volumio[29167]: Starting albumart workers Aug 31 04:02:48 volumio volumio[29167]: Starting albumart workers Aug 31 04:02:49 volumio autossh[1647]: starting ssh (count 18) Aug 31 04:02:49 volumio autossh[1647]: ssh child pid is 29268 Aug 31 04:02:49 volumio volumio[29167]: info: Loading i18n strings for locale en Aug 31 04:02:49 volumio volumiossh-tunnel[1646]: ssh: Could not resolve hostname eu4.myvolumio.org: Device or resource busy Aug 31 04:02:49 volumio autossh[1647]: ssh exited with error status 255; restarting ssh Aug 31 04:02:49 volumio volumio[29167]: Updating browse sources language Aug 31 04:02:49 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:49 volumio volumio[29167]: Starting albumart workers Aug 31 04:02:49 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:02:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Aug 31 04:02:49 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:49 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:02:49 volumio volumio[29167]: info: CoreCommandRouter::initPlayerControls Aug 31 04:02:49 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:49 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:49 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:49 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:49 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:49 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:49 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:49 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:49 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:49 volumio go-librespot[29277]: Librespot-go daemon starting... Aug 31 04:02:49 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:02:49 volumio go-librespot[29277]: time="2025-08-31T04:02:49+02:00" level=info msg="generated new device id: 3a700a0e13d195b652768e834485029398dc2089" Aug 31 04:02:49 volumio volumio[29167]: Express server listening on port 3000 Aug 31 04:02:49 volumio volumio[29167]: [Metrics] WebUI: 7s 532.86ms Aug 31 04:02:49 volumio go-librespot[29277]: time="2025-08-31T04:02:49+02: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" Aug 31 04:02:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:49 volumio volumio[29167]: info: CoreStateMachine::resetVolumioState Aug 31 04:02:49 volumio volumio[29167]: info: CoreStateMachine::getcurrentVolume Aug 31 04:02:49 volumio volumio[29167]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:02:49 volumio volumio[29167]: info: Cannot mount NAS NasTas at system boot, trial number 2 ,retrying in 5 seconds Aug 31 04:02:49 volumio volumio[29167]: info: Cannot mount NAS Music-Dieter at system boot, trial number 2 ,retrying in 5 seconds Aug 31 04:02:49 volumio volumio[29167]: info: Volumio Network Manager: Network status updated: 0 Aug 31 04:02:50 volumio volumio-remote-updater[571]: [2025-08-31 04:02:50] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1756605766 101 Aug 31 04:02:50 volumio volumio[29167]: 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 Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:50 volumio volumio[29167]: info: Reloading queue from file Aug 31 04:02:50 volumio volumio[29167]: info: Setting Device type: Raspberry PI Aug 31 04:02:50 volumio volumio[29167]: info: CoreStateMachine::setRepeat false single undefined Aug 31 04:02:50 volumio volumio[29167]: info: CoreStateMachine::pushState Aug 31 04:02:50 volumio volumio[29167]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:50 volumio volumio[29167]: info: CoreStateMachine::setRandom false Aug 31 04:02:50 volumio volumio[29167]: info: CoreStateMachine::pushState Aug 31 04:02:50 volumio volumio[29167]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:50 volumio volumio[29167]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:02:50 volumio volumio[29167]: info: CoreStateMachine::pushState Aug 31 04:02:50 volumio volumio[29167]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:50 volumio volumio[29167]: info: CoreStateMachine::updateTrackBlock Aug 31 04:02:50 volumio volumio[29167]: info: CorePlayQueue::getTrackBlock Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:02:50 volumio volumio[29167]: info: Completed loading Core Plugins Aug 31 04:02:50 volumio volumio[29167]: info: Preparing to generate the ALSA configuration file Aug 31 04:02:50 volumio volumio[29167]: info: Asound.conf file unchanged, so no further update is needed Aug 31 04:02:50 volumio volumio[29167]: info: Output device has changed, restarting MPD Aug 31 04:02:50 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Aug 31 04:02:50 volumio sudo[29312]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 04:02:50 volumio sudo[29312]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:50 volumio volumio[29167]: info: ___________ START PLUGINS ___________ Aug 31 04:02:50 volumio sudo[29312]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:50 volumio volumio[29167]: info: ControllerMpd::onStart: Initializing MPD Aug 31 04:02:50 volumio volumio[29167]: info: Creating MPD Configuration file Aug 31 04:02:50 volumio sudo[29315]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 04:02:50 volumio sudo[29315]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:50 volumio sudo[29318]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 04:02:50 volumio sudo[29318]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:50 volumio sudo[29318]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:50 volumio systemd[1]: musicservicesshield.service: Succeeded. Aug 31 04:02:50 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Aug 31 04:02:50 volumio systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Aug 31 04:02:50 volumio systemd[1]: Stopping Music Player Daemon... Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:02:50 volumio volumio[29167]: info: [1756605770357] CoreMusicLibrary::Adding element Last_100 Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:02:50 volumio volumio[29167]: info: [1756605770364] CoreMusicLibrary::Adding element Webradio Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:02:50 volumio volumio[29167]: info: Initializing BBC Radios Aug 31 04:02:50 volumio sudo[29321]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 04:02:50 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Aug 31 04:02:50 volumio systemd[1]: mpd.service: Succeeded. Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:02:50 volumio volumio[29167]: info: [1756605770470] CoreMusicLibrary::Adding element SoundCloud Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:50 volumio volumio[29167]: Cannot find translation for source SoundCloud Aug 31 04:02:50 volumio sudo[29321]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:50 volumio systemd[1]: Stopped Music Player Daemon. Aug 31 04:02:50 volumio systemd[1]: Starting Music Player Daemon... Aug 31 04:02:50 volumio volumio[29167]: info: Creating Spotify config file Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:50 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Aug 31 04:02:50 volumio systemd[1]: mpd.service: Succeeded. Aug 31 04:02:50 volumio systemd[1]: Stopped Music Player Daemon. Aug 31 04:02:50 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Aug 31 04:02:50 volumio systemd[1]: Starting Music Player Daemon... Aug 31 04:02:50 volumio volumio[29167]: info: [squeezelite_mc] Starting proxy server... Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:02:50 volumio volumio[29167]: info: [1756605770527] CoreMusicLibrary::Adding element Radio Paradise Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:02:50 volumio volumio[29167]: Cannot find translation for source SoundCloud Aug 31 04:02:50 volumio volumio[29167]: Cannot find translation for source Radio Paradise Aug 31 04:02:50 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Aug 31 04:02:50 volumio sudo[29334]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 04:02:50 volumio sudo[29334]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:50 volumio sudo[29334]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:50 volumio volumio[29167]: info: Volumio Calling Home Aug 31 04:02:50 volumio volumio[29167]: info: [squeezelite_mc] Proxy server started on port 37775 Aug 31 04:02:50 volumio sudo[29363]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Aug 31 04:02:50 volumio sudo[29363]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:50 volumio volumio[29167]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:02:51 volumio volumio[29167]: info: MPD Permissions set Aug 31 04:02:51 volumio volumio[29167]: info: MPD Permissions set Aug 31 04:02:51 volumio volumio[29167]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:02:51 volumio volumio[29167]: info: CoreStateMachine::pushState Aug 31 04:02:51 volumio volumio[29167]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:51 volumio volumio[29167]: info: Spotify config file written Aug 31 04:02:51 volumio sudo[29381]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 04:02:51 volumio volumio[29167]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 31 04:02:51 volumio sudo[29381]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:51 volumio go-librespot[29384]: Librespot-go daemon starting... Aug 31 04:02:51 volumio sudo[29381]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: No need to fix Spotify hosts Aug 31 04:02:51 volumio go-librespot[29384]: time="2025-08-31T04:02:51+02:00" level=info msg="generated new device id: 9701e917080b534b1d1fe1a616400af5447ed3fe" Aug 31 04:02:51 volumio go-librespot[29384]: time="2025-08-31T04:02:51+02: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" Aug 31 04:02:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:51 volumio volumio[29167]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:02:51 volumio volumio[29167]: info: CoreStateMachine::pushState Aug 31 04:02:51 volumio volumio[29167]: info: CorePlayQueue::getTrack 0 Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::volumioPushState Aug 31 04:02:51 volumio volumio[29167]: info: [squeezelite_mc] Server discovery started Aug 31 04:02:51 volumio volumio[29167]: info: [squeezelite_mc] Player finder started Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:02:51 volumio volumio[29167]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Aug 31 04:02:51 volumio volumio[29167]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 04:02:51 volumio volumio[29167]: Error: send ENETUNREACH 255.255.255.255:3483 Aug 31 04:02:51 volumio volumio[29167]: at doSend (dgram.js:692:16) Aug 31 04:02:51 volumio volumio[29167]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Aug 31 04:02:51 volumio volumio[29167]: at afterDns (dgram.js:638:5) Aug 31 04:02:51 volumio volumio[29167]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Aug 31 04:02:51 volumio volumio[29167]: errno: -101, Aug 31 04:02:51 volumio volumio[29167]: code: 'ENETUNREACH', Aug 31 04:02:51 volumio volumio[29167]: syscall: 'send', Aug 31 04:02:51 volumio volumio[29167]: address: '255.255.255.255', Aug 31 04:02:51 volumio volumio[29167]: port: 3483 Aug 31 04:02:51 volumio volumio[29167]: } Aug 31 04:02:51 volumio volumio[29167]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 04:02:51 volumio sudo[29363]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:52 volumio sudo[29413]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-08-31 04:01 Aug 31 04:02:52 volumio sudo[29413]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:52 volumio sudo[29413]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:52 volumio mpd[29352]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 04:02:52 volumio mpd[29352]: output: No 'audio_output' defined in config file Aug 31 04:02:52 volumio mpd[29352]: output: Successfully detected a sndio audio device Aug 31 04:02:52 volumio mpd[29352]: zeroconf: No global port, disabling zeroconf Aug 31 04:02:52 volumio systemd[1]: Started Music Player Daemon. Aug 31 04:02:52 volumio sudo[29321]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:52 volumio sudo[29315]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:52 volumio volumio-remote-updater[571]: [2025-08-31 04:02:52] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 31 04:02:52 volumio volumio-remote-updater[571]: [2025-08-31 04:02:52] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 31 04:02:52 volumio systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Aug 31 04:02:52 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:52 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 31 04:02:52 volumio systemd[1]: Started dynamicswap service. Aug 31 04:02:52 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Aug 31 04:02:52 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Aug 31 04:02:52 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Aug 31 04:02:52 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Aug 31 04:02:52 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Aug 31 04:02:52 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Aug 31 04:02:52 volumio systemd[1]: dynamicswap.service: Succeeded. Aug 31 04:02:52 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Aug 31 04:02:52 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 13. Aug 31 04:02:52 volumio systemd[1]: Started dynamicswap service. Aug 31 04:02:52 volumio systemd[1]: Stopped Volumio Backend Module. Aug 31 04:02:52 volumio systemd[1]: Started Volumio Backend Module. Aug 31 04:02:52 volumio systemd[1]: dynamicswap.service: Succeeded. Aug 31 04:02:52 volumio volumio[29422]: cset: --> shielding system active with Aug 31 04:02:52 volumio volumio[29422]: cset: "system" cpuset of CPUSPEC(1-3) with 57 tasks running Aug 31 04:02:52 volumio volumio[29422]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Aug 31 04:02:52 volumio systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Aug 31 04:02:54 volumio volumio[29441]: info: ------------------------------------------- Aug 31 04:02:54 volumio volumio[29441]: info: ----- Volumio3 ---- Aug 31 04:02:54 volumio volumio[29441]: info: ------------------------------------------- Aug 31 04:02:54 volumio volumio[29441]: info: ----- System startup ---- Aug 31 04:02:54 volumio volumio[29441]: info: ------------------------------------------- Aug 31 04:02:54 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:02:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Aug 31 04:02:54 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:54 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:54 volumio go-librespot[29464]: Librespot-go daemon starting... Aug 31 04:02:54 volumio go-librespot[29464]: time="2025-08-31T04:02:54+02:00" level=info msg="generated new device id: 5fb4d9855ae0fd71730398a18f140e7517d1d441" Aug 31 04:02:54 volumio go-librespot[29464]: time="2025-08-31T04:02:54+02: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" Aug 31 04:02:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:55 volumio volumio[29441]: info: MYVOLUMIO Environment detected Aug 31 04:02:55 volumio volumio[29441]: info: Plugin folders cleanup Aug 31 04:02:55 volumio volumio[29441]: info: Scanning into folder /volumio/app/plugins/ Aug 31 04:02:55 volumio volumio[29441]: info: Scanning category audio_interface Aug 31 04:02:55 volumio volumio[29441]: info: Scanning category miscellanea Aug 31 04:02:55 volumio volumio[29441]: info: Scanning category music_service Aug 31 04:02:55 volumio volumio[29441]: info: Scanning category plugins.json Aug 31 04:02:55 volumio volumio[29441]: info: Scanning category system_controller Aug 31 04:02:55 volumio volumio[29441]: info: Scanning category user_interface Aug 31 04:02:55 volumio volumio[29441]: info: Scanning into folder /data/plugins/ Aug 31 04:02:55 volumio volumio[29441]: info: Scanning category music_service Aug 31 04:02:55 volumio volumio[29441]: info: Scanning category system_controller Aug 31 04:02:55 volumio volumio[29441]: info: Scanning category system_hardware Aug 31 04:02:55 volumio volumio[29441]: info: Scanning category user_interface Aug 31 04:02:55 volumio volumio[29441]: info: Plugin folders cleanup completed Aug 31 04:02:55 volumio volumio[29441]: info: ------------------------------------------- Aug 31 04:02:55 volumio volumio[29441]: info: ----- Core plugins startup ---- Aug 31 04:02:55 volumio volumio[29441]: info: ------------------------------------------- Aug 31 04:02:55 volumio volumio[29441]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 04:02:55 volumio volumio[29441]: info: Adding plugin upnp to MyMusic Plugins Aug 31 04:02:55 volumio volumio[29441]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 04:02:55 volumio volumio[29441]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 04:02:55 volumio volumio[29441]: info: Loading plugins from folder /data/plugins/ Aug 31 04:02:55 volumio volumio[29441]: info: Loading plugin "system"... Aug 31 04:02:55 volumio volumio[29441]: info: Loading plugin "appearance"... Aug 31 04:02:56 volumio volumio[29441]: info: Loading plugin "network"... Aug 31 04:02:56 volumio volumio[29441]: info: Refreshing Cached IP Addresses Aug 31 04:02:56 volumio sudo[29477]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 04:02:56 volumio sudo[29477]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:56 volumio sudo[29477]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:56 volumio sudo[29479]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 04:02:56 volumio sudo[29479]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:56 volumio volumio[29441]: info: Loading plugin "services"... Aug 31 04:02:56 volumio sudo[29479]: pam_unix(sudo:session): session closed for user root Aug 31 04:02:56 volumio volumio[29441]: info: Loading plugin "alsa_controller"... Aug 31 04:02:56 volumio sudo[29488]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 31 04:02:56 volumio sudo[29488]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:02:56 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:02:56 volumio volumio[29441]: info: Loading plugin "wizard"... Aug 31 04:02:56 volumio volumio[29441]: info: Loading plugin "networkfs"... Aug 31 04:02:56 volumio volumio[29441]: info: Cannot mount NAS NasTas at system boot, trial number 1 ,retrying in 5 seconds Aug 31 04:02:56 volumio volumio[29441]: info: Cannot mount NAS Music-Dieter at system boot, trial number 1 ,retrying in 5 seconds Aug 31 04:02:56 volumio volumio[29441]: info: Starting Udev Watcher for removable devices Aug 31 04:02:56 volumio volumio[29441]: info: Ignoring mount for partition: boot Aug 31 04:02:56 volumio volumio[29441]: info: Ignoring mount for partition: volumio Aug 31 04:02:56 volumio volumio[29441]: info: Ignoring mount for partition: volumio_data Aug 31 04:02:56 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 04:02:56 volumio volumio[29441]: info: Loading plugin "volumio_command_line_client"... Aug 31 04:02:56 volumio volumio[29441]: info: Plugin upnp is not enabled Aug 31 04:02:56 volumio volumio[29441]: info: Loading plugin "my_music"... Aug 31 04:02:56 volumio volumio[29441]: info: Loading plugin "mpd"... Aug 31 04:02:56 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Aug 31 04:02:56 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Aug 31 04:02:56 volumio volumio[29441]: info: Plugin upnp_browser is not enabled Aug 31 04:02:56 volumio volumio[29441]: info: Loading plugin "alarm-clock"... Aug 31 04:02:56 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Aug 31 04:02:56 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Aug 31 04:02:56 volumio volumio[29441]: info: Plugin airplay_emulation is not enabled Aug 31 04:02:56 volumio volumio[29441]: info: Loading plugin "last_100"... Aug 31 04:02:56 volumio volumio[29441]: info: Loading plugin "webradio"... Aug 31 04:02:56 volumio volumio[29441]: info: Loading plugin "i2s_dacs"... Aug 31 04:02:56 volumio volumio[29441]: info: Loading plugin "volumiodiscovery"... Aug 31 04:02:56 volumio volumio[29441]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:56 volumio volumio[29441]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:56 volumio volumio[29441]: *** WARNING *** For more information see Aug 31 04:02:56 volumio node[29441]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:56 volumio volumio[29441]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:56 volumio volumio[29441]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:56 volumio volumio[29441]: *** WARNING *** For more information see Aug 31 04:02:56 volumio node[29441]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:56 volumio node[29441]: *** WARNING *** For more information see Aug 31 04:02:56 volumio node[29441]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 04:02:56 volumio node[29441]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:02:56 volumio node[29441]: *** WARNING *** For more information see Aug 31 04:02:56 volumio volumio[29441]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 04:02:56 volumio volumio[29441]: info: Discovery: Started advertising with name: Volumio Aug 31 04:02:56 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 04:02:56 volumio volumio[29441]: info: Loading plugin "soundcloud"... Aug 31 04:02:57 volumio volumio[29441]: info: Loading plugin "spop"... Aug 31 04:02:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:02:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Aug 31 04:02:57 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:02:57 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:02:57 volumio go-librespot[29505]: Librespot-go daemon starting... Aug 31 04:02:57 volumio go-librespot[29505]: time="2025-08-31T04:02:57+02:00" level=info msg="generated new device id: 4996aadf5abfcd5fcb0fd182c390e2cc3ab08f25" Aug 31 04:02:57 volumio go-librespot[29505]: time="2025-08-31T04:02:57+02: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" Aug 31 04:02:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:02:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:02:58 volumio volumio[29441]: info: Loading plugin "squeezelite_mc"... Aug 31 04:02:58 volumio volumio-remote-updater[571]: [2025-08-31 04:02:58] [connect] Successful connection Aug 31 04:02:58 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Aug 31 04:02:58 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Aug 31 04:02:58 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Aug 31 04:02:58 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Aug 31 04:02:58 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Aug 31 04:02:58 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Aug 31 04:02:58 volumio wpa_supplicant[867]: wlan0: Failed to initiate sched scan Aug 31 04:02:59 volumio volumio[29441]: info: Loading plugin "outputs"... Aug 31 04:02:59 volumio volumio[29441]: info: Loading plugin "albumart"... Aug 31 04:02:59 volumio volumio[29441]: info: Plugin example_plugin is not enabled Aug 31 04:02:59 volumio volumio[29441]: info: Loading plugin "inputs"... Aug 31 04:02:59 volumio volumio[29441]: info: Loading plugin "updater_comm"... Aug 31 04:02:59 volumio volumio[29441]: info: Plugin mpdemulation is not enabled Aug 31 04:02:59 volumio volumio[29441]: info: Loading plugin "rest_api"... Aug 31 04:02:59 volumio volumio[29441]: info: Loading plugin "websocket"... Aug 31 04:02:59 volumio volumio[29441]: info: Starting Socket.io Server version 2.3.0 Aug 31 04:02:59 volumio volumio[29441]: info: Loading plugin "radio_paradise"... Aug 31 04:02:59 volumio volumio[29441]: Forking 3 albumart workers Aug 31 04:02:59 volumio volumio[29441]: info: Applying required configuration parameters for plugin radio_paradise Aug 31 04:02:59 volumio volumio[29441]: info: [1756605779688] [RadioParadise] API delay: 3 Aug 31 04:02:59 volumio volumio[29441]: info: Loading plugin "backup_restore"... Aug 31 04:02:59 volumio volumio[29441]: info: Applying required configuration parameters for plugin backup_restore Aug 31 04:02:59 volumio volumio[29441]: info: Loading plugin "music_services_shield"... Aug 31 04:03:00 volumio volumio[29441]: info: Applying required configuration parameters for plugin music_services_shield Aug 31 04:03:00 volumio volumio[29441]: info: Loading plugin "Systeminfo"... Aug 31 04:03:00 volumio volumio[29441]: Starting albumart workers Aug 31 04:03:00 volumio volumio[29441]: Starting albumart workers Aug 31 04:03:00 volumio volumio[29441]: info: Loading i18n strings for locale en Aug 31 04:03:00 volumio volumio[29441]: Updating browse sources language Aug 31 04:03:00 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:03:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:03:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Aug 31 04:03:00 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:03:01 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:03:01 volumio go-librespot[29544]: Librespot-go daemon starting... Aug 31 04:03:01 volumio go-librespot[29544]: time="2025-08-31T04:03:01+02:00" level=info msg="generated new device id: 9dec2eb5478ad07883731e6fc6b8d1dac8def366" Aug 31 04:03:01 volumio go-librespot[29544]: time="2025-08-31T04:03:01+02: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" Aug 31 04:03:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:03:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:03:01 volumio sudo[29488]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:01 volumio volumio[29441]: Starting albumart workers Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::initPlayerControls Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:03:01 volumio volumio[29441]: Express server listening on port 3000 Aug 31 04:03:01 volumio volumio[29441]: [Metrics] WebUI: 7s 486.56ms Aug 31 04:03:01 volumio volumio[29441]: info: CoreStateMachine::resetVolumioState Aug 31 04:03:01 volumio volumio[29441]: info: CoreStateMachine::getcurrentVolume Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:03:01 volumio volumio[29441]: info: Cannot mount NAS NasTas at system boot, trial number 2 ,retrying in 5 seconds Aug 31 04:03:01 volumio volumio[29441]: info: Cannot mount NAS Music-Dieter at system boot, trial number 2 ,retrying in 5 seconds Aug 31 04:03:01 volumio volumio[29441]: info: Volumio Network Manager: Network status updated: 0 Aug 31 04:03:01 volumio volumio-remote-updater[571]: [2025-08-31 04:03:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1756605777 101 Aug 31 04:03:01 volumio volumio[29441]: 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 Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:03:01 volumio volumio[29441]: info: Reloading queue from file Aug 31 04:03:01 volumio volumio[29441]: info: CoreStateMachine::setRepeat false single undefined Aug 31 04:03:01 volumio volumio[29441]: info: CoreStateMachine::pushState Aug 31 04:03:01 volumio volumio[29441]: info: CorePlayQueue::getTrack 0 Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::volumioPushState Aug 31 04:03:01 volumio volumio[29441]: info: CoreStateMachine::setRandom false Aug 31 04:03:01 volumio volumio[29441]: info: CoreStateMachine::pushState Aug 31 04:03:01 volumio volumio[29441]: info: CorePlayQueue::getTrack 0 Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::volumioPushState Aug 31 04:03:01 volumio volumio[29441]: info: Setting Device type: Raspberry PI Aug 31 04:03:01 volumio volumio[29441]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:03:01 volumio volumio[29441]: info: CoreStateMachine::pushState Aug 31 04:03:01 volumio volumio[29441]: info: CorePlayQueue::getTrack 0 Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::volumioPushState Aug 31 04:03:01 volumio volumio[29441]: info: CoreStateMachine::updateTrackBlock Aug 31 04:03:01 volumio volumio[29441]: info: CorePlayQueue::getTrackBlock Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:03:01 volumio volumio[29441]: info: Completed loading Core Plugins Aug 31 04:03:01 volumio volumio[29441]: info: Preparing to generate the ALSA configuration file Aug 31 04:03:01 volumio volumio[29441]: info: Asound.conf file unchanged, so no further update is needed Aug 31 04:03:01 volumio volumio[29441]: info: Output device has changed, restarting MPD Aug 31 04:03:01 volumio sudo[29584]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 04:03:01 volumio sudo[29584]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:01 volumio volumio[29441]: info: ___________ START PLUGINS ___________ Aug 31 04:03:01 volumio volumio[29441]: info: ControllerMpd::onStart: Initializing MPD Aug 31 04:03:01 volumio volumio[29441]: info: Creating MPD Configuration file Aug 31 04:03:01 volumio sudo[29584]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:01 volumio sudo[29589]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 04:03:01 volumio sudo[29589]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:01 volumio systemd[1]: musicservicesshield.service: Succeeded. Aug 31 04:03:01 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Aug 31 04:03:01 volumio systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Aug 31 04:03:01 volumio systemd[1]: Stopping Music Player Daemon... Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:03:01 volumio volumio[29441]: info: [1756605781881] CoreMusicLibrary::Adding element Last_100 Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:03:01 volumio sudo[29593]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 04:03:01 volumio sudo[29593]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:03:01 volumio sudo[29593]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:01 volumio volumio[29441]: info: [1756605781895] CoreMusicLibrary::Adding element Webradio Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:03:01 volumio systemd[1]: mpd.service: Succeeded. Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:03:01 volumio sudo[29595]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 04:03:01 volumio systemd[1]: Stopped Music Player Daemon. Aug 31 04:03:01 volumio volumio[29441]: info: Initializing BBC Radios Aug 31 04:03:01 volumio sudo[29595]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:03:01 volumio systemd[1]: Starting Music Player Daemon... Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:03:01 volumio volumio[29441]: info: [1756605781997] CoreMusicLibrary::Adding element SoundCloud Aug 31 04:03:01 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:03:01 volumio volumio[29441]: Cannot find translation for source SoundCloud Aug 31 04:03:02 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Aug 31 04:03:02 volumio systemd[1]: mpd.service: Succeeded. Aug 31 04:03:02 volumio systemd[1]: Stopped Music Player Daemon. Aug 31 04:03:02 volumio systemd[1]: Starting Music Player Daemon... Aug 31 04:03:02 volumio volumio[29441]: info: Creating Spotify config file Aug 31 04:03:02 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:02 volumio volumio[29441]: info: [squeezelite_mc] Starting proxy server... Aug 31 04:03:02 volumio volumio[29441]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:03:02 volumio volumio[29441]: info: [1756605782051] CoreMusicLibrary::Adding element Radio Paradise Aug 31 04:03:02 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:03:02 volumio volumio[29441]: Cannot find translation for source SoundCloud Aug 31 04:03:02 volumio volumio[29441]: Cannot find translation for source Radio Paradise Aug 31 04:03:02 volumio sudo[29609]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 04:03:02 volumio sudo[29609]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:02 volumio sudo[29609]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:02 volumio volumio[29441]: info: Volumio Calling Home Aug 31 04:03:02 volumio sudo[29638]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Aug 31 04:03:02 volumio sudo[29638]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:02 volumio volumio[29441]: info: [squeezelite_mc] Proxy server started on port 39123 Aug 31 04:03:02 volumio volumio[29441]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:03:02 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Aug 31 04:03:02 volumio volumio[29441]: info: MPD Permissions set Aug 31 04:03:02 volumio volumio[29441]: info: MPD Permissions set Aug 31 04:03:02 volumio volumio[29441]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:03:02 volumio volumio[29441]: info: CoreStateMachine::pushState Aug 31 04:03:02 volumio volumio[29441]: info: CorePlayQueue::getTrack 0 Aug 31 04:03:02 volumio volumio[29441]: info: CoreCommandRouter::volumioPushState Aug 31 04:03:02 volumio volumio[29441]: info: Spotify config file written Aug 31 04:03:02 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Aug 31 04:03:02 volumio sudo[29657]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 04:03:02 volumio sudo[29657]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:02 volumio volumio[29441]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 31 04:03:02 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:02 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Aug 31 04:03:02 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:02 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:03:02 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:02 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:03:02 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:03:02 volumio go-librespot[29664]: Librespot-go daemon starting... Aug 31 04:03:02 volumio sudo[29657]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:02 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:03:02 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:02 volumio volumio[29441]: info: No need to fix Spotify hosts Aug 31 04:03:02 volumio go-librespot[29664]: time="2025-08-31T04:03:02+02:00" level=info msg="generated new device id: b5aff1c1f1a20dfdba0a15e8fbc5b698d462117b" Aug 31 04:03:02 volumio go-librespot[29664]: time="2025-08-31T04:03:02+02: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" Aug 31 04:03:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:03:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:03:02 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Aug 31 04:03:02 volumio volumio[29441]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:03:02 volumio volumio[29441]: info: CoreStateMachine::pushState Aug 31 04:03:02 volumio volumio[29441]: info: CorePlayQueue::getTrack 0 Aug 31 04:03:02 volumio volumio[29441]: info: CoreCommandRouter::volumioPushState Aug 31 04:03:02 volumio volumio[29441]: info: [squeezelite_mc] Server discovery started Aug 31 04:03:02 volumio volumio[29441]: info: [squeezelite_mc] Player finder started Aug 31 04:03:02 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:02 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:02 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:02 volumio volumio[29441]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:03:02 volumio volumio[29441]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Aug 31 04:03:02 volumio volumio[29441]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 04:03:02 volumio volumio[29441]: Error: send ENETUNREACH 255.255.255.255:3483 Aug 31 04:03:02 volumio volumio[29441]: at doSend (dgram.js:692:16) Aug 31 04:03:02 volumio volumio[29441]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Aug 31 04:03:02 volumio volumio[29441]: at afterDns (dgram.js:638:5) Aug 31 04:03:02 volumio volumio[29441]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Aug 31 04:03:02 volumio volumio[29441]: errno: -101, Aug 31 04:03:02 volumio volumio[29441]: code: 'ENETUNREACH', Aug 31 04:03:02 volumio volumio[29441]: syscall: 'send', Aug 31 04:03:02 volumio volumio[29441]: address: '255.255.255.255', Aug 31 04:03:02 volumio volumio[29441]: port: 3483 Aug 31 04:03:02 volumio volumio[29441]: } Aug 31 04:03:02 volumio volumio[29441]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 04:03:03 volumio sudo[29638]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:03 volumio sudo[29688]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-08-31 04:02 Aug 31 04:03:03 volumio sudo[29688]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:03 volumio sudo[29688]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:03 volumio mpd[29623]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 04:03:03 volumio mpd[29623]: output: No 'audio_output' defined in config file Aug 31 04:03:03 volumio mpd[29623]: output: Successfully detected a sndio audio device Aug 31 04:03:03 volumio mpd[29623]: zeroconf: No global port, disabling zeroconf Aug 31 04:03:03 volumio systemd[1]: Started Music Player Daemon. Aug 31 04:03:03 volumio sudo[29595]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:03 volumio sudo[29589]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:03 volumio systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Aug 31 04:03:03 volumio volumio-remote-updater[571]: [2025-08-31 04:03:03] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 31 04:03:03 volumio volumio-remote-updater[571]: [2025-08-31 04:03:03] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 31 04:03:03 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:03:03 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 31 04:03:03 volumio systemd[1]: Started dynamicswap service. Aug 31 04:03:03 volumio systemd[1]: dynamicswap.service: Succeeded. Aug 31 04:03:04 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Aug 31 04:03:04 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 14. Aug 31 04:03:04 volumio systemd[1]: Started dynamicswap service. Aug 31 04:03:04 volumio systemd[1]: Stopped Volumio Backend Module. Aug 31 04:03:04 volumio systemd[1]: Started Volumio Backend Module. Aug 31 04:03:04 volumio systemd[1]: dynamicswap.service: Succeeded. Aug 31 04:03:04 volumio volumio[29697]: cset: --> shielding system active with Aug 31 04:03:04 volumio volumio[29697]: cset: "system" cpuset of CPUSPEC(1-3) with 57 tasks running Aug 31 04:03:04 volumio volumio[29697]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Aug 31 04:03:04 volumio systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Aug 31 04:03:04 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Aug 31 04:03:04 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Aug 31 04:03:04 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Aug 31 04:03:04 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Aug 31 04:03:04 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Aug 31 04:03:04 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Aug 31 04:03:05 volumio volumio[29716]: info: ------------------------------------------- Aug 31 04:03:05 volumio volumio[29716]: info: ----- Volumio3 ---- Aug 31 04:03:05 volumio volumio[29716]: info: ------------------------------------------- Aug 31 04:03:05 volumio volumio[29716]: info: ----- System startup ---- Aug 31 04:03:05 volumio volumio[29716]: info: ------------------------------------------- Aug 31 04:03:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:03:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Aug 31 04:03:05 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:03:06 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:03:06 volumio go-librespot[29739]: Librespot-go daemon starting... Aug 31 04:03:06 volumio go-librespot[29739]: time="2025-08-31T04:03:06+02:00" level=info msg="generated new device id: 7ded21c4bb3de1f9c2376c5c57adce793c51e7a4" Aug 31 04:03:06 volumio go-librespot[29739]: time="2025-08-31T04:03:06+02: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" Aug 31 04:03:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:03:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:03:06 volumio volumio[29716]: info: MYVOLUMIO Environment detected Aug 31 04:03:06 volumio volumio[29716]: info: Plugin folders cleanup Aug 31 04:03:06 volumio volumio[29716]: info: Scanning into folder /volumio/app/plugins/ Aug 31 04:03:06 volumio volumio[29716]: info: Scanning category audio_interface Aug 31 04:03:06 volumio volumio[29716]: info: Scanning category miscellanea Aug 31 04:03:06 volumio volumio[29716]: info: Scanning category music_service Aug 31 04:03:06 volumio volumio[29716]: info: Scanning category plugins.json Aug 31 04:03:06 volumio volumio[29716]: info: Scanning category system_controller Aug 31 04:03:06 volumio volumio[29716]: info: Scanning category user_interface Aug 31 04:03:06 volumio volumio[29716]: info: Scanning into folder /data/plugins/ Aug 31 04:03:06 volumio volumio[29716]: info: Scanning category music_service Aug 31 04:03:06 volumio volumio[29716]: info: Scanning category system_controller Aug 31 04:03:06 volumio volumio[29716]: info: Scanning category system_hardware Aug 31 04:03:06 volumio volumio[29716]: info: Scanning category user_interface Aug 31 04:03:06 volumio volumio[29716]: info: Plugin folders cleanup completed Aug 31 04:03:06 volumio volumio[29716]: info: ------------------------------------------- Aug 31 04:03:06 volumio volumio[29716]: info: ----- Core plugins startup ---- Aug 31 04:03:06 volumio volumio[29716]: info: ------------------------------------------- Aug 31 04:03:06 volumio volumio[29716]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 04:03:06 volumio volumio[29716]: info: Adding plugin upnp to MyMusic Plugins Aug 31 04:03:06 volumio volumio[29716]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 04:03:06 volumio volumio[29716]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 04:03:06 volumio volumio[29716]: info: Loading plugins from folder /data/plugins/ Aug 31 04:03:06 volumio volumio[29716]: info: Loading plugin "system"... Aug 31 04:03:06 volumio volumio[29716]: info: Loading plugin "appearance"... Aug 31 04:03:07 volumio volumio[29716]: info: Loading plugin "network"... Aug 31 04:03:07 volumio volumio[29716]: info: Refreshing Cached IP Addresses Aug 31 04:03:07 volumio sudo[29752]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 04:03:07 volumio sudo[29752]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:07 volumio sudo[29752]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:07 volumio sudo[29754]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 04:03:07 volumio sudo[29754]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:07 volumio sudo[29754]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:07 volumio volumio[29716]: info: Loading plugin "services"... Aug 31 04:03:07 volumio volumio[29716]: info: Loading plugin "alsa_controller"... Aug 31 04:03:07 volumio sudo[29763]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 31 04:03:07 volumio sudo[29763]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:07 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:03:07 volumio volumio[29716]: info: Loading plugin "wizard"... Aug 31 04:03:07 volumio volumio[29716]: info: Loading plugin "networkfs"... Aug 31 04:03:07 volumio volumio[29716]: info: Cannot mount NAS NasTas at system boot, trial number 1 ,retrying in 5 seconds Aug 31 04:03:07 volumio volumio[29716]: info: Cannot mount NAS Music-Dieter at system boot, trial number 1 ,retrying in 5 seconds Aug 31 04:03:07 volumio volumio[29716]: info: Starting Udev Watcher for removable devices Aug 31 04:03:07 volumio volumio[29716]: info: Ignoring mount for partition: boot Aug 31 04:03:07 volumio volumio[29716]: info: Ignoring mount for partition: volumio Aug 31 04:03:07 volumio volumio[29716]: info: Ignoring mount for partition: volumio_data Aug 31 04:03:07 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 04:03:07 volumio volumio[29716]: info: Loading plugin "volumio_command_line_client"... Aug 31 04:03:07 volumio volumio[29716]: info: Plugin upnp is not enabled Aug 31 04:03:07 volumio volumio[29716]: info: Loading plugin "my_music"... Aug 31 04:03:07 volumio volumio[29716]: info: Loading plugin "mpd"... Aug 31 04:03:08 volumio volumio[29716]: info: Plugin upnp_browser is not enabled Aug 31 04:03:08 volumio volumio[29716]: info: Loading plugin "alarm-clock"... Aug 31 04:03:08 volumio volumio[29716]: info: Plugin airplay_emulation is not enabled Aug 31 04:03:08 volumio volumio[29716]: info: Loading plugin "last_100"... Aug 31 04:03:08 volumio volumio[29716]: info: Loading plugin "webradio"... Aug 31 04:03:08 volumio volumio[29716]: info: Loading plugin "i2s_dacs"... Aug 31 04:03:08 volumio volumio[29716]: info: Loading plugin "volumiodiscovery"... Aug 31 04:03:08 volumio volumio[29716]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 04:03:08 volumio volumio[29716]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:03:08 volumio volumio[29716]: *** WARNING *** For more information see Aug 31 04:03:08 volumio node[29716]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 04:03:08 volumio volumio[29716]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 04:03:08 volumio volumio[29716]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:03:08 volumio volumio[29716]: *** WARNING *** For more information see Aug 31 04:03:08 volumio node[29716]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:03:08 volumio node[29716]: *** WARNING *** For more information see Aug 31 04:03:08 volumio node[29716]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 04:03:08 volumio node[29716]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:03:08 volumio node[29716]: *** WARNING *** For more information see Aug 31 04:03:08 volumio volumio[29716]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 04:03:08 volumio volumio[29716]: info: Discovery: Started advertising with name: Volumio Aug 31 04:03:08 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 04:03:08 volumio volumio[29716]: info: Loading plugin "soundcloud"... Aug 31 04:03:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Aug 31 04:03:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Aug 31 04:03:08 volumio volumio[29716]: info: Loading plugin "spop"... Aug 31 04:03:08 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Aug 31 04:03:09 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Aug 31 04:03:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:03:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Aug 31 04:03:09 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:03:09 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:03:09 volumio go-librespot[29781]: Librespot-go daemon starting... Aug 31 04:03:09 volumio go-librespot[29781]: time="2025-08-31T04:03:09+02:00" level=info msg="generated new device id: 5c9af76a11f77d54375bafa2a245aa60d2c28a86" Aug 31 04:03:09 volumio go-librespot[29781]: time="2025-08-31T04:03:09+02: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" Aug 31 04:03:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:03:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:03:09 volumio volumio[29716]: info: Loading plugin "squeezelite_mc"... Aug 31 04:03:10 volumio volumio[29716]: info: Loading plugin "outputs"... Aug 31 04:03:10 volumio volumio[29716]: info: Loading plugin "albumart"... Aug 31 04:03:10 volumio volumio[29716]: info: Plugin example_plugin is not enabled Aug 31 04:03:10 volumio volumio[29716]: info: Loading plugin "inputs"... Aug 31 04:03:10 volumio volumio[29716]: info: Loading plugin "updater_comm"... Aug 31 04:03:10 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Aug 31 04:03:10 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Aug 31 04:03:10 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Aug 31 04:03:10 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Aug 31 04:03:10 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Aug 31 04:03:10 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Aug 31 04:03:10 volumio volumio-remote-updater[571]: [2025-08-31 04:03:10] [connect] Successful connection Aug 31 04:03:10 volumio wpa_supplicant[867]: wlan0: Failed to initiate sched scan Aug 31 04:03:10 volumio volumio[29716]: info: Plugin mpdemulation is not enabled Aug 31 04:03:10 volumio volumio[29716]: info: Loading plugin "rest_api"... Aug 31 04:03:10 volumio volumio[29716]: info: Loading plugin "websocket"... Aug 31 04:03:10 volumio volumio[29716]: info: Starting Socket.io Server version 2.3.0 Aug 31 04:03:10 volumio volumio[29716]: info: Loading plugin "radio_paradise"... Aug 31 04:03:11 volumio volumio[29716]: Forking 3 albumart workers Aug 31 04:03:11 volumio volumio[29716]: info: Applying required configuration parameters for plugin radio_paradise Aug 31 04:03:11 volumio volumio[29716]: info: [1756605791162] [RadioParadise] API delay: 3 Aug 31 04:03:11 volumio volumio[29716]: info: Loading plugin "backup_restore"... Aug 31 04:03:11 volumio volumio[29716]: info: Applying required configuration parameters for plugin backup_restore Aug 31 04:03:11 volumio volumio[29716]: info: Loading plugin "music_services_shield"... Aug 31 04:03:11 volumio volumio[29716]: info: Applying required configuration parameters for plugin music_services_shield Aug 31 04:03:11 volumio volumio[29716]: info: Loading plugin "Systeminfo"... Aug 31 04:03:12 volumio volumio[29716]: info: Loading i18n strings for locale en Aug 31 04:03:12 volumio volumio[29716]: Updating browse sources language Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::initPlayerControls Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:03:12 volumio volumio[29716]: Express server listening on port 3000 Aug 31 04:03:12 volumio volumio[29716]: [Metrics] WebUI: 6s 959.55ms Aug 31 04:03:12 volumio volumio[29716]: Starting albumart workers Aug 31 04:03:12 volumio volumio[29716]: info: CoreStateMachine::resetVolumioState Aug 31 04:03:12 volumio volumio[29716]: info: CoreStateMachine::getcurrentVolume Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:03:12 volumio volumio[29716]: Starting albumart workers Aug 31 04:03:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:03:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Aug 31 04:03:12 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:03:12 volumio volumio[29716]: info: Volumio Network Manager: Network status updated: 0 Aug 31 04:03:12 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:03:12 volumio go-librespot[29820]: Librespot-go daemon starting... Aug 31 04:03:12 volumio volumio-remote-updater[571]: [2025-08-31 04:03:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1756605788 101 Aug 31 04:03:12 volumio go-librespot[29820]: time="2025-08-31T04:03:12+02:00" level=info msg="generated new device id: 97e29e344beacc707b0abe7d65dd319d25fb6e51" Aug 31 04:03:12 volumio go-librespot[29820]: time="2025-08-31T04:03:12+02: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" Aug 31 04:03:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:03:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:03:12 volumio volumio[29716]: Starting albumart workers Aug 31 04:03:12 volumio volumio[29716]: 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 Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:03:12 volumio volumio[29716]: info: Reloading queue from file Aug 31 04:03:12 volumio volumio[29716]: info: Cannot mount NAS NasTas at system boot, trial number 2 ,retrying in 5 seconds Aug 31 04:03:12 volumio volumio[29716]: info: Cannot mount NAS Music-Dieter at system boot, trial number 2 ,retrying in 5 seconds Aug 31 04:03:12 volumio volumio[29716]: info: Setting Device type: Raspberry PI Aug 31 04:03:12 volumio volumio[29716]: info: CoreStateMachine::setRepeat false single undefined Aug 31 04:03:12 volumio volumio[29716]: info: CoreStateMachine::pushState Aug 31 04:03:12 volumio volumio[29716]: info: CorePlayQueue::getTrack 0 Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::volumioPushState Aug 31 04:03:12 volumio volumio[29716]: info: CoreStateMachine::setRandom false Aug 31 04:03:12 volumio volumio[29716]: info: CoreStateMachine::pushState Aug 31 04:03:12 volumio volumio[29716]: info: CorePlayQueue::getTrack 0 Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::volumioPushState Aug 31 04:03:12 volumio volumio[29716]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:03:12 volumio volumio[29716]: info: CoreStateMachine::pushState Aug 31 04:03:12 volumio volumio[29716]: info: CorePlayQueue::getTrack 0 Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::volumioPushState Aug 31 04:03:12 volumio volumio[29716]: info: CoreStateMachine::updateTrackBlock Aug 31 04:03:12 volumio volumio[29716]: info: CorePlayQueue::getTrackBlock Aug 31 04:03:12 volumio volumio[29716]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:03:13 volumio volumio[29716]: info: Completed loading Core Plugins Aug 31 04:03:13 volumio volumio[29716]: info: Preparing to generate the ALSA configuration file Aug 31 04:03:13 volumio volumio[29716]: info: Asound.conf file unchanged, so no further update is needed Aug 31 04:03:13 volumio volumio[29716]: info: Output device has changed, restarting MPD Aug 31 04:03:13 volumio volumio[29716]: info: ___________ START PLUGINS ___________ Aug 31 04:03:13 volumio volumio[29716]: info: ControllerMpd::onStart: Initializing MPD Aug 31 04:03:13 volumio sudo[29844]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 04:03:13 volumio sudo[29844]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:13 volumio sudo[29845]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 04:03:13 volumio sudo[29845]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:13 volumio volumio[29716]: info: Creating MPD Configuration file Aug 31 04:03:13 volumio sudo[29844]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:13 volumio systemd[1]: musicservicesshield.service: Succeeded. Aug 31 04:03:13 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Aug 31 04:03:13 volumio systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Aug 31 04:03:13 volumio systemd[1]: Stopping Music Player Daemon... Aug 31 04:03:13 volumio systemd[1]: mpd.service: Succeeded. Aug 31 04:03:13 volumio systemd[1]: Stopped Music Player Daemon. Aug 31 04:03:13 volumio sudo[29853]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 04:03:13 volumio sudo[29853]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:13 volumio volumio[29716]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:03:13 volumio volumio[29716]: info: [1756605793322] CoreMusicLibrary::Adding element Last_100 Aug 31 04:03:13 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:03:13 volumio volumio[29716]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:03:13 volumio volumio[29716]: info: [1756605793329] CoreMusicLibrary::Adding element Webradio Aug 31 04:03:13 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:03:13 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:03:13 volumio volumio[29716]: info: Initializing BBC Radios Aug 31 04:03:13 volumio sudo[29853]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:13 volumio sudo[29861]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 04:03:13 volumio sudo[29861]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:13 volumio systemd[1]: Starting Music Player Daemon... Aug 31 04:03:13 volumio sudo[29763]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:13 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Aug 31 04:03:13 volumio systemd[1]: mpd.service: Succeeded. Aug 31 04:03:13 volumio systemd[1]: Stopped Music Player Daemon. Aug 31 04:03:13 volumio systemd[1]: Starting Music Player Daemon... Aug 31 04:03:13 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:03:13 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:03:13 volumio volumio[29716]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:03:13 volumio volumio[29716]: info: [1756605793469] CoreMusicLibrary::Adding element SoundCloud Aug 31 04:03:13 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:03:13 volumio volumio[29716]: Cannot find translation for source SoundCloud Aug 31 04:03:13 volumio volumio[29716]: info: Creating Spotify config file Aug 31 04:03:13 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:13 volumio volumio[29716]: info: [squeezelite_mc] Starting proxy server... Aug 31 04:03:13 volumio volumio[29716]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:03:13 volumio volumio[29716]: info: [1756605793513] CoreMusicLibrary::Adding element Radio Paradise Aug 31 04:03:13 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:03:13 volumio volumio[29716]: Cannot find translation for source SoundCloud Aug 31 04:03:13 volumio volumio[29716]: Cannot find translation for source Radio Paradise Aug 31 04:03:13 volumio sudo[29874]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 04:03:13 volumio sudo[29874]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:13 volumio sudo[29874]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:13 volumio volumio[29716]: info: Volumio Calling Home Aug 31 04:03:13 volumio sudo[29910]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Aug 31 04:03:13 volumio sudo[29910]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:13 volumio volumio[29716]: info: [squeezelite_mc] Proxy server started on port 34303 Aug 31 04:03:13 volumio volumio[29716]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:03:14 volumio volumio[29716]: info: MPD Permissions set Aug 31 04:03:14 volumio volumio[29716]: info: MPD Permissions set Aug 31 04:03:14 volumio volumio[29716]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:03:14 volumio volumio[29716]: info: CoreStateMachine::pushState Aug 31 04:03:14 volumio volumio[29716]: info: CorePlayQueue::getTrack 0 Aug 31 04:03:14 volumio volumio[29716]: info: CoreCommandRouter::volumioPushState Aug 31 04:03:14 volumio volumio[29716]: info: Spotify config file written Aug 31 04:03:14 volumio sudo[29929]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 04:03:14 volumio sudo[29929]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:14 volumio volumio[29716]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Aug 31 04:03:14 volumio volumio[29716]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:03:14 volumio volumio[29716]: info: CoreStateMachine::pushState Aug 31 04:03:14 volumio volumio[29716]: info: CorePlayQueue::getTrack 0 Aug 31 04:03:14 volumio volumio[29716]: info: CoreCommandRouter::volumioPushState Aug 31 04:03:14 volumio volumio[29716]: info: [squeezelite_mc] Server discovery started Aug 31 04:03:14 volumio volumio[29716]: info: [squeezelite_mc] Player finder started Aug 31 04:03:14 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:03:14 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:14 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:14 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:14 volumio volumio[29716]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:03:14 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:03:14 volumio volumio[29716]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Aug 31 04:03:14 volumio go-librespot[29931]: Librespot-go daemon starting... Aug 31 04:03:14 volumio sudo[29929]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:14 volumio go-librespot[29931]: time="2025-08-31T04:03:14+02:00" level=info msg="generated new device id: ddad2d43735540f333b6303d9dcabf3afa0afff3" Aug 31 04:03:14 volumio go-librespot[29931]: time="2025-08-31T04:03:14+02: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" Aug 31 04:03:14 volumio volumio[29716]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 04:03:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:03:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:03:14 volumio volumio[29716]: Error: send ENETUNREACH 255.255.255.255:3483 Aug 31 04:03:14 volumio volumio[29716]: at doSend (dgram.js:692:16) Aug 31 04:03:14 volumio volumio[29716]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Aug 31 04:03:14 volumio volumio[29716]: at afterDns (dgram.js:638:5) Aug 31 04:03:14 volumio volumio[29716]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Aug 31 04:03:14 volumio volumio[29716]: errno: -101, Aug 31 04:03:14 volumio volumio[29716]: code: 'ENETUNREACH', Aug 31 04:03:14 volumio volumio[29716]: syscall: 'send', Aug 31 04:03:14 volumio volumio[29716]: address: '255.255.255.255', Aug 31 04:03:14 volumio volumio[29716]: port: 3483 Aug 31 04:03:14 volumio volumio[29716]: } Aug 31 04:03:14 volumio volumio[29716]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 04:03:14 volumio sudo[29910]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:14 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Aug 31 04:03:14 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Aug 31 04:03:14 volumio sudo[29953]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-08-31 04:02 Aug 31 04:03:14 volumio sudo[29953]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:14 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Aug 31 04:03:15 volumio sudo[29953]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:15 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Aug 31 04:03:15 volumio mpd[29887]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 04:03:15 volumio mpd[29887]: output: No 'audio_output' defined in config file Aug 31 04:03:15 volumio mpd[29887]: output: Successfully detected a sndio audio device Aug 31 04:03:15 volumio mpd[29887]: zeroconf: No global port, disabling zeroconf Aug 31 04:03:15 volumio systemd[1]: Started Music Player Daemon. Aug 31 04:03:15 volumio sudo[29861]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:15 volumio sudo[29845]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:15 volumio volumio-remote-updater[571]: [2025-08-31 04:03:15] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 31 04:03:15 volumio volumio-remote-updater[571]: [2025-08-31 04:03:15] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 31 04:03:15 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:03:15 volumio systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Aug 31 04:03:15 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 31 04:03:15 volumio systemd[1]: Started dynamicswap service. Aug 31 04:03:15 volumio systemd[1]: dynamicswap.service: Succeeded. Aug 31 04:03:15 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Aug 31 04:03:15 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 15. Aug 31 04:03:15 volumio systemd[1]: Stopped Volumio Backend Module. Aug 31 04:03:15 volumio systemd[1]: Started Volumio Backend Module. Aug 31 04:03:15 volumio systemd[1]: Started dynamicswap service. Aug 31 04:03:15 volumio systemd[1]: dynamicswap.service: Succeeded. Aug 31 04:03:15 volumio volumio[29962]: cset: --> shielding system active with Aug 31 04:03:15 volumio volumio[29962]: cset: "system" cpuset of CPUSPEC(1-3) with 57 tasks running Aug 31 04:03:15 volumio volumio[29962]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Aug 31 04:03:15 volumio systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Aug 31 04:03:16 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Aug 31 04:03:16 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Aug 31 04:03:16 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Aug 31 04:03:16 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Aug 31 04:03:16 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Aug 31 04:03:16 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Aug 31 04:03:17 volumio volumio[29980]: info: ------------------------------------------- Aug 31 04:03:17 volumio volumio[29980]: info: ----- Volumio3 ---- Aug 31 04:03:17 volumio volumio[29980]: info: ------------------------------------------- Aug 31 04:03:17 volumio volumio[29980]: info: ----- System startup ---- Aug 31 04:03:17 volumio volumio[29980]: info: ------------------------------------------- Aug 31 04:03:17 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:03:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Aug 31 04:03:17 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:03:17 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:03:17 volumio go-librespot[30004]: Librespot-go daemon starting... Aug 31 04:03:17 volumio go-librespot[30004]: time="2025-08-31T04:03:17+02:00" level=info msg="generated new device id: 5fff578fed0315749cbde0a0774e80b6c7c62055" Aug 31 04:03:17 volumio go-librespot[30004]: time="2025-08-31T04:03:17+02: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" Aug 31 04:03:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:03:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:03:17 volumio volumio[29980]: info: MYVOLUMIO Environment detected Aug 31 04:03:17 volumio volumio[29980]: info: Plugin folders cleanup Aug 31 04:03:17 volumio volumio[29980]: info: Scanning into folder /volumio/app/plugins/ Aug 31 04:03:17 volumio volumio[29980]: info: Scanning category audio_interface Aug 31 04:03:17 volumio volumio[29980]: info: Scanning category miscellanea Aug 31 04:03:17 volumio volumio[29980]: info: Scanning category music_service Aug 31 04:03:17 volumio volumio[29980]: info: Scanning category plugins.json Aug 31 04:03:17 volumio volumio[29980]: info: Scanning category system_controller Aug 31 04:03:17 volumio volumio[29980]: info: Scanning category user_interface Aug 31 04:03:17 volumio volumio[29980]: info: Scanning into folder /data/plugins/ Aug 31 04:03:17 volumio volumio[29980]: info: Scanning category music_service Aug 31 04:03:17 volumio volumio[29980]: info: Scanning category system_controller Aug 31 04:03:17 volumio volumio[29980]: info: Scanning category system_hardware Aug 31 04:03:17 volumio volumio[29980]: info: Scanning category user_interface Aug 31 04:03:17 volumio volumio[29980]: info: Plugin folders cleanup completed Aug 31 04:03:17 volumio volumio[29980]: info: ------------------------------------------- Aug 31 04:03:17 volumio volumio[29980]: info: ----- Core plugins startup ---- Aug 31 04:03:17 volumio volumio[29980]: info: ------------------------------------------- Aug 31 04:03:17 volumio volumio[29980]: info: Loading plugins from folder /volumio/app/plugins/ Aug 31 04:03:17 volumio volumio[29980]: info: Adding plugin upnp to MyMusic Plugins Aug 31 04:03:17 volumio volumio[29980]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 31 04:03:17 volumio volumio[29980]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 31 04:03:17 volumio volumio[29980]: info: Loading plugins from folder /data/plugins/ Aug 31 04:03:17 volumio volumio[29980]: info: Loading plugin "system"... Aug 31 04:03:17 volumio volumio[29980]: info: Loading plugin "appearance"... Aug 31 04:03:18 volumio volumio[29980]: info: Loading plugin "network"... Aug 31 04:03:18 volumio volumio[29980]: info: Refreshing Cached IP Addresses Aug 31 04:03:18 volumio sudo[30017]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 04:03:18 volumio sudo[30017]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:18 volumio sudo[30017]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:18 volumio sudo[30019]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 04:03:18 volumio sudo[30019]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:18 volumio sudo[30019]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:18 volumio volumio[29980]: info: Loading plugin "services"... Aug 31 04:03:18 volumio volumio[29980]: info: Loading plugin "alsa_controller"... Aug 31 04:03:18 volumio sudo[30032]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 31 04:03:18 volumio sudo[30032]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:18 volumio sudo[30032]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:19 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:03:19 volumio volumio[29980]: info: Loading plugin "wizard"... Aug 31 04:03:19 volumio volumio[29980]: info: Loading plugin "networkfs"... Aug 31 04:03:19 volumio volumio[29980]: info: Cannot mount NAS NasTas at system boot, trial number 1 ,retrying in 5 seconds Aug 31 04:03:19 volumio volumio[29980]: info: Cannot mount NAS Music-Dieter at system boot, trial number 1 ,retrying in 5 seconds Aug 31 04:03:19 volumio volumio[29980]: info: Starting Udev Watcher for removable devices Aug 31 04:03:19 volumio volumio[29980]: info: Ignoring mount for partition: boot Aug 31 04:03:19 volumio volumio[29980]: info: Ignoring mount for partition: volumio Aug 31 04:03:19 volumio volumio[29980]: info: Ignoring mount for partition: volumio_data Aug 31 04:03:19 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 04:03:19 volumio volumio[29980]: info: Loading plugin "volumio_command_line_client"... Aug 31 04:03:19 volumio volumio[29980]: info: Plugin upnp is not enabled Aug 31 04:03:19 volumio volumio[29980]: info: Loading plugin "my_music"... Aug 31 04:03:19 volumio volumio[29980]: info: Loading plugin "mpd"... Aug 31 04:03:19 volumio volumio[29980]: info: Plugin upnp_browser is not enabled Aug 31 04:03:19 volumio volumio[29980]: info: Loading plugin "alarm-clock"... Aug 31 04:03:19 volumio volumio[29980]: info: Plugin airplay_emulation is not enabled Aug 31 04:03:19 volumio volumio[29980]: info: Loading plugin "last_100"... Aug 31 04:03:19 volumio volumio[29980]: info: Loading plugin "webradio"... Aug 31 04:03:19 volumio volumio[29980]: info: Loading plugin "i2s_dacs"... Aug 31 04:03:19 volumio volumio[29980]: info: Loading plugin "volumiodiscovery"... Aug 31 04:03:19 volumio volumio[29980]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 04:03:19 volumio volumio[29980]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:03:19 volumio volumio[29980]: *** WARNING *** For more information see Aug 31 04:03:19 volumio node[29980]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 04:03:19 volumio volumio[29980]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 04:03:19 volumio volumio[29980]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:03:19 volumio volumio[29980]: *** WARNING *** For more information see Aug 31 04:03:19 volumio node[29980]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:03:19 volumio node[29980]: *** WARNING *** For more information see Aug 31 04:03:19 volumio node[29980]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 31 04:03:19 volumio node[29980]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 04:03:19 volumio node[29980]: *** WARNING *** For more information see Aug 31 04:03:19 volumio volumio[29980]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 04:03:19 volumio volumio[29980]: info: Discovery: Started advertising with name: Volumio Aug 31 04:03:19 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 04:03:19 volumio volumio[29980]: info: Loading plugin "soundcloud"... Aug 31 04:03:20 volumio volumio-remote-updater[571]: [2025-08-31 04:03:20] [connect] Successful connection Aug 31 04:03:20 volumio volumio[29980]: info: Loading plugin "spop"... Aug 31 04:03:20 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:03:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Aug 31 04:03:20 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:03:20 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:03:20 volumio go-librespot[30087]: Librespot-go daemon starting... Aug 31 04:03:20 volumio go-librespot[30087]: time="2025-08-31T04:03:20+02:00" level=info msg="generated new device id: 7b12f73f1c2b3c418cdc26ce4388d861af4e1177" Aug 31 04:03:20 volumio go-librespot[30087]: time="2025-08-31T04:03:20+02: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" Aug 31 04:03:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:03:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:03:20 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Aug 31 04:03:20 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Aug 31 04:03:21 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Aug 31 04:03:21 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Aug 31 04:03:21 volumio volumio[29980]: info: Loading plugin "squeezelite_mc"... Aug 31 04:03:21 volumio volumio[29980]: info: Loading plugin "outputs"... Aug 31 04:03:21 volumio volumio[29980]: info: Loading plugin "albumart"... Aug 31 04:03:21 volumio volumio[29980]: info: Plugin example_plugin is not enabled Aug 31 04:03:21 volumio volumio[29980]: info: Loading plugin "inputs"... Aug 31 04:03:21 volumio volumio[29980]: info: Loading plugin "updater_comm"... Aug 31 04:03:22 volumio volumio[29980]: info: Plugin mpdemulation is not enabled Aug 31 04:03:22 volumio volumio[29980]: info: Loading plugin "rest_api"... Aug 31 04:03:22 volumio volumio[29980]: info: Loading plugin "websocket"... Aug 31 04:03:22 volumio volumio[29980]: info: Starting Socket.io Server version 2.3.0 Aug 31 04:03:22 volumio volumio[29980]: info: Loading plugin "radio_paradise"... Aug 31 04:03:22 volumio volumio[29980]: Forking 3 albumart workers Aug 31 04:03:22 volumio volumio[29980]: info: Applying required configuration parameters for plugin radio_paradise Aug 31 04:03:22 volumio volumio[29980]: info: [1756605802589] [RadioParadise] API delay: 3 Aug 31 04:03:22 volumio volumio[29980]: info: Loading plugin "backup_restore"... Aug 31 04:03:22 volumio volumio[29980]: info: Applying required configuration parameters for plugin backup_restore Aug 31 04:03:22 volumio volumio[29980]: info: Loading plugin "music_services_shield"... Aug 31 04:03:22 volumio wpa_supplicant[867]: wlan0: Trying to associate with SSID 'DAVINCHI-5G' Aug 31 04:03:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Aug 31 04:03:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Aug 31 04:03:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Aug 31 04:03:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Aug 31 04:03:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Aug 31 04:03:22 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Aug 31 04:03:23 volumio volumio[29980]: info: Applying required configuration parameters for plugin music_services_shield Aug 31 04:03:23 volumio volumio[29980]: info: Loading plugin "Systeminfo"... Aug 31 04:03:23 volumio wpa_supplicant[867]: wlan0: Associated with f0:b4:d2:6b:1f:7b Aug 31 04:03:23 volumio wpa_supplicant[867]: wlan0: CTRL-EVENT-CONNECTED - Connection to f0:b4:d2:6b:1f:7b completed [id=0 id_str=] Aug 31 04:03:23 volumio dhcpcd[879]: wlan0: carrier acquired Aug 31 04:03:23 volumio wpa_supplicant[867]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Aug 31 04:03:23 volumio dhcpcd[879]: wlan0: IAID eb:2a:05:b2 Aug 31 04:03:23 volumio dhcpcd[879]: wlan0: carrier lost Aug 31 04:03:23 volumio dhcpcd[879]: wlan0: carrier acquired Aug 31 04:03:23 volumio dhcpcd[879]: wlan0: IAID eb:2a:05:b2 Aug 31 04:03:23 volumio volumio[29980]: Starting albumart workers Aug 31 04:03:23 volumio dhcpcd[879]: wlan0: soliciting an IPv6 router Aug 31 04:03:23 volumio volumio[29980]: Starting albumart workers Aug 31 04:03:23 volumio volumio[29980]: Starting albumart workers Aug 31 04:03:23 volumio volumio[29980]: info: Loading i18n strings for locale en Aug 31 04:03:23 volumio volumio[29980]: Updating browse sources language Aug 31 04:03:23 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:03:23 volumio dhcpcd[879]: wlan0: rebinding lease of 192.168.0.120 Aug 31 04:03:23 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:03:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Aug 31 04:03:23 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:03:24 volumio dhcpcd[879]: wlan0: probing address 192.168.0.120/24 Aug 31 04:03:24 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:03:24 volumio go-librespot[30134]: Librespot-go daemon starting... Aug 31 04:03:24 volumio go-librespot[30134]: time="2025-08-31T04:03:24+02:00" level=info msg="generated new device id: 9b8a90cfd67022ea6140bed30b87f0cf9bb0b25d" Aug 31 04:03:24 volumio go-librespot[30134]: time="2025-08-31T04:03:24+02: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" Aug 31 04:03:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:03:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:03:24 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:03:24 volumio volumio[29980]: info: CoreCommandRouter::initPlayerControls Aug 31 04:03:24 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:24 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:24 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:24 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:24 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:24 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:24 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:24 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:24 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:03:24 volumio volumio[29980]: Express server listening on port 3000 Aug 31 04:03:24 volumio volumio[29980]: [Metrics] WebUI: 7s 602.52ms Aug 31 04:03:24 volumio volumio[29980]: info: CoreStateMachine::resetVolumioState Aug 31 04:03:24 volumio volumio[29980]: info: CoreStateMachine::getcurrentVolume Aug 31 04:03:24 volumio volumio[29980]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:03:24 volumio volumio[29980]: info: Cannot mount NAS NasTas at system boot, trial number 2 ,retrying in 5 seconds Aug 31 04:03:24 volumio volumio[29980]: info: Cannot mount NAS Music-Dieter at system boot, trial number 2 ,retrying in 5 seconds Aug 31 04:03:24 volumio volumio[29980]: info: Volumio Network Manager: Network status updated: 0 Aug 31 04:03:24 volumio volumio[29980]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Aug 31 04:03:24 volumio volumio[29980]: wlan0 Interface doesn't support scanning : Device or resource busy Aug 31 04:03:24 volumio volumio[29980]: info: Cannot use regular scanning, forcing with ap-force Aug 31 04:03:24 volumio sudo[30167]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Aug 31 04:03:24 volumio sudo[30167]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:27 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Aug 31 04:03:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Aug 31 04:03:27 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:03:27 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:03:27 volumio go-librespot[30173]: Librespot-go daemon starting... Aug 31 04:03:27 volumio go-librespot[30173]: time="2025-08-31T04:03:27+02:00" level=info msg="generated new device id: 6bb73e59ad231ea61671a77857c6b20289d5c45b" Aug 31 04:03:27 volumio go-librespot[30173]: time="2025-08-31T04:03:27+02: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" Aug 31 04:03:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:03:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:03:27 volumio sudo[30167]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:27 volumio volumio[29980]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:03:27 volumio volumio[29980]: info: CoreStateMachine::pushState Aug 31 04:03:27 volumio volumio[29980]: info: CorePlayQueue::getTrack 0 Aug 31 04:03:27 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:03:27 volumio volumio[29980]: info: CoreCommandRouter::volumioPushState Aug 31 04:03:27 volumio volumio[29980]: info: CoreStateMachine::updateTrackBlock Aug 31 04:03:27 volumio volumio[29980]: info: CorePlayQueue::getTrackBlock Aug 31 04:03:27 volumio volumio[29980]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:03:27 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:03:27 volumio volumio[29980]: info: Reloading queue from file Aug 31 04:03:27 volumio volumio[29980]: info: CoreStateMachine::setRepeat false single undefined Aug 31 04:03:27 volumio volumio[29980]: info: CoreStateMachine::pushState Aug 31 04:03:27 volumio volumio[29980]: info: CorePlayQueue::getTrack 0 Aug 31 04:03:27 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:03:27 volumio volumio[29980]: info: CoreCommandRouter::volumioPushState Aug 31 04:03:27 volumio volumio[29980]: info: CoreStateMachine::setRandom false Aug 31 04:03:27 volumio volumio[29980]: info: CoreStateMachine::pushState Aug 31 04:03:27 volumio volumio[29980]: info: CorePlayQueue::getTrack 0 Aug 31 04:03:27 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 04:03:27 volumio volumio[29980]: info: CoreCommandRouter::volumioPushState Aug 31 04:03:27 volumio volumio[29980]: info: Setting Device type: Raspberry PI Aug 31 04:03:27 volumio volumio[29980]: info: Completed loading Core Plugins Aug 31 04:03:27 volumio volumio[29980]: info: Preparing to generate the ALSA configuration file Aug 31 04:03:27 volumio volumio[29980]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:03:27 volumio volumio[29980]: info: CoreStateMachine::pushState Aug 31 04:03:27 volumio volumio[29980]: info: CorePlayQueue::getTrack 0 Aug 31 04:03:27 volumio volumio[29980]: info: CoreCommandRouter::volumioPushState Aug 31 04:03:27 volumio volumio[29980]: info: Asound.conf file unchanged, so no further update is needed Aug 31 04:03:27 volumio volumio[29980]: info: Output device has changed, restarting MPD Aug 31 04:03:27 volumio sudo[30187]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 04:03:27 volumio sudo[30187]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:27 volumio volumio[29980]: info: ___________ START PLUGINS ___________ Aug 31 04:03:27 volumio sudo[30187]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:27 volumio volumio[29980]: info: ControllerMpd::onStart: Initializing MPD Aug 31 04:03:27 volumio volumio[29980]: info: Creating MPD Configuration file Aug 31 04:03:27 volumio sudo[30190]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 04:03:27 volumio sudo[30190]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:27 volumio systemd[1]: musicservicesshield.service: Succeeded. Aug 31 04:03:27 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Aug 31 04:03:27 volumio sudo[30193]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 04:03:27 volumio systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Aug 31 04:03:27 volumio systemd[1]: Stopping Music Player Daemon... Aug 31 04:03:27 volumio sudo[30193]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:27 volumio sudo[30193]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:27 volumio volumio[29980]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:03:27 volumio volumio[29980]: info: [1756605807912] CoreMusicLibrary::Adding element Last_100 Aug 31 04:03:27 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:03:27 volumio volumio[29980]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:03:27 volumio volumio[29980]: info: [1756605807917] CoreMusicLibrary::Adding element Webradio Aug 31 04:03:27 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:03:27 volumio systemd[1]: mpd.service: Succeeded. Aug 31 04:03:27 volumio systemd[1]: Stopped Music Player Daemon. Aug 31 04:03:27 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:03:27 volumio volumio[29980]: info: Initializing BBC Radios Aug 31 04:03:27 volumio sudo[30196]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 04:03:27 volumio sudo[30196]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:28 volumio systemd[1]: Starting Music Player Daemon... Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:03:28 volumio volumio[29980]: info: [1756605808024] CoreMusicLibrary::Adding element SoundCloud Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:03:28 volumio volumio[29980]: Cannot find translation for source SoundCloud Aug 31 04:03:28 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Aug 31 04:03:28 volumio systemd[1]: mpd.service: Succeeded. Aug 31 04:03:28 volumio systemd[1]: Stopped Music Player Daemon. Aug 31 04:03:28 volumio systemd[1]: Starting Music Player Daemon... Aug 31 04:03:28 volumio volumio[29980]: info: Creating Spotify config file Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:28 volumio volumio[29980]: info: [squeezelite_mc] Starting proxy server... Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 04:03:28 volumio volumio[29980]: info: [1756605808073] CoreMusicLibrary::Adding element Radio Paradise Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 04:03:28 volumio volumio[29980]: Cannot find translation for source SoundCloud Aug 31 04:03:28 volumio volumio[29980]: Cannot find translation for source Radio Paradise Aug 31 04:03:28 volumio sudo[30209]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 31 04:03:28 volumio sudo[30209]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:28 volumio sudo[30209]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:28 volumio volumio[29980]: info: Volumio Calling Home Aug 31 04:03:28 volumio sudo[30238]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Aug 31 04:03:28 volumio sudo[30238]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:28 volumio volumio[29980]: info: [squeezelite_mc] Proxy server started on port 35465 Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 04:03:28 volumio volumio[29980]: info: MPD Permissions set Aug 31 04:03:28 volumio volumio[29980]: info: MPD Permissions set Aug 31 04:03:28 volumio volumio[29980]: info: Spotify config file written Aug 31 04:03:28 volumio volumio[29980]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:28 volumio sudo[30257]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 04:03:28 volumio sudo[30257]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 04:03:28 volumio systemd[1]: Stopped go-librespot Daemon. Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:28 volumio volumio[29980]: info: No need to fix Spotify hosts Aug 31 04:03:28 volumio systemd[1]: Started go-librespot Daemon. Aug 31 04:03:28 volumio sudo[30257]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:28 volumio go-librespot[30267]: Librespot-go daemon starting... Aug 31 04:03:28 volumio volumio[29980]: info: VolumeController:: Volume=100 Mute =false Aug 31 04:03:28 volumio volumio[29980]: info: CoreStateMachine::pushState Aug 31 04:03:28 volumio volumio[29980]: info: CorePlayQueue::getTrack 0 Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::volumioPushState Aug 31 04:03:28 volumio go-librespot[30267]: time="2025-08-31T04:03:28+02:00" level=info msg="generated new device id: 596b6247616edd9190639c60576d24a736119c07" Aug 31 04:03:28 volumio go-librespot[30267]: time="2025-08-31T04:03:28+02: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" Aug 31 04:03:28 volumio volumio[29980]: info: [squeezelite_mc] Server discovery started Aug 31 04:03:28 volumio volumio[29980]: info: [squeezelite_mc] Player finder started Aug 31 04:03:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 31 04:03:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 04:03:28 volumio volumio[29980]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 04:03:28 volumio volumio[29980]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true Aug 31 04:03:28 volumio volumio[29980]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 04:03:28 volumio volumio[29980]: Error: send ENETUNREACH 255.255.255.255:3483 Aug 31 04:03:28 volumio volumio[29980]: at doSend (dgram.js:692:16) Aug 31 04:03:28 volumio volumio[29980]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Aug 31 04:03:28 volumio volumio[29980]: at afterDns (dgram.js:638:5) Aug 31 04:03:28 volumio volumio[29980]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Aug 31 04:03:28 volumio volumio[29980]: errno: -101, Aug 31 04:03:28 volumio volumio[29980]: code: 'ENETUNREACH', Aug 31 04:03:28 volumio volumio[29980]: syscall: 'send', Aug 31 04:03:28 volumio volumio[29980]: address: '255.255.255.255', Aug 31 04:03:28 volumio volumio[29980]: port: 3483 Aug 31 04:03:28 volumio volumio[29980]: } Aug 31 04:03:28 volumio volumio[29980]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 04:03:29 volumio sudo[30238]: pam_unix(sudo:session): session closed for user root Aug 31 04:03:29 volumio dhcpcd[879]: wlan0: leased 192.168.0.120 for infinity Aug 31 04:03:29 volumio avahi-daemon[597]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.120. Aug 31 04:03:29 volumio dhcpcd[879]: wlan0: adding route to 192.168.0.0/24 Aug 31 04:03:29 volumio avahi-daemon[597]: New relevant interface wlan0.IPv4 for mDNS. Aug 31 04:03:29 volumio avahi-daemon[597]: Registering new address record for 192.168.0.120 on wlan0.IPv4. Aug 31 04:03:29 volumio dhcpcd[879]: wlan0: adding default route via 192.168.0.1 Aug 31 04:03:29 volumio sudo[30323]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-08-31 04:02 Aug 31 04:03:29 volumio sudo[30323]: pam_unix(sudo:session): session opened for user root by (uid=0) 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="811ff8312d42f9da0260be1d353081a805678820" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 02 Jul 2025 04:07:25 PM CEST" VOLUMIO_VERSION="3.819" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3b9115b1943141a9d7186aa434f8f3c2"