-- Logs begin at Thu 2025-03-13 13:32:34 CET, end at Thu 2025-03-13 20:16:29 CET. -- Mar 13 20:15:00 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 13 20:15:00 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 13 20:15:00 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 13 20:15:00 fabiocasa volumio[637]: info: ------------------------------------------- Mar 13 20:15:00 fabiocasa volumio[637]: info: ----- Volumio3 ---- Mar 13 20:15:00 fabiocasa volumio[637]: info: ------------------------------------------- Mar 13 20:15:00 fabiocasa volumio[637]: info: ----- System startup ---- Mar 13 20:15:00 fabiocasa volumio[637]: info: ------------------------------------------- Mar 13 20:15:01 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:01 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 13 20:15:01 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:01 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:01 fabiocasa go-librespot[657]: Librespot-go daemon starting... Mar 13 20:15:01 fabiocasa go-librespot[657]: time="2025-03-13T20:15:01+01:00" level=info msg="generated new device id: be5b6d445b25944445a9e3c1c4b94624d22ff9cc" Mar 13 20:15:01 fabiocasa go-librespot[657]: time="2025-03-13T20:15:01+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:01 fabiocasa go-librespot[657]: time="2025-03-13T20:15:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:01 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:01 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:01 fabiocasa volumio[637]: info: MYVOLUMIO Environment detected Mar 13 20:15:01 fabiocasa volumio[637]: info: Plugin folders cleanup Mar 13 20:15:01 fabiocasa volumio[637]: info: Scanning into folder /volumio/app/plugins/ Mar 13 20:15:01 fabiocasa volumio[637]: info: Scanning category audio_interface Mar 13 20:15:01 fabiocasa volumio[637]: info: Scanning category miscellanea Mar 13 20:15:01 fabiocasa volumio[637]: info: Scanning category music_service Mar 13 20:15:01 fabiocasa volumio[637]: info: Scanning category plugins.json Mar 13 20:15:01 fabiocasa volumio[637]: info: Scanning category system_controller Mar 13 20:15:01 fabiocasa volumio[637]: info: Scanning category user_interface Mar 13 20:15:01 fabiocasa volumio[637]: info: Scanning into folder /data/plugins/ Mar 13 20:15:01 fabiocasa volumio[637]: info: Scanning category music_service Mar 13 20:15:01 fabiocasa volumio[637]: info: Plugin folders cleanup completed Mar 13 20:15:01 fabiocasa volumio[637]: info: ------------------------------------------- Mar 13 20:15:01 fabiocasa volumio[637]: info: ----- Core plugins startup ---- Mar 13 20:15:01 fabiocasa volumio[637]: info: ------------------------------------------- Mar 13 20:15:01 fabiocasa volumio[637]: info: Loading plugins from folder /volumio/app/plugins/ Mar 13 20:15:01 fabiocasa volumio[637]: info: Adding plugin upnp to MyMusic Plugins Mar 13 20:15:01 fabiocasa volumio[637]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 13 20:15:01 fabiocasa volumio[637]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 13 20:15:01 fabiocasa volumio[637]: info: Loading plugins from folder /data/plugins/ Mar 13 20:15:01 fabiocasa volumio[637]: info: Loading plugin "system"... Mar 13 20:15:01 fabiocasa volumio[637]: info: Loading plugin "appearance"... Mar 13 20:15:02 fabiocasa wpa_supplicant[877]: wlan0: Failed to initiate sched scan Mar 13 20:15:02 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 13 20:15:02 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 13 20:15:02 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 13 20:15:02 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 13 20:15:02 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 13 20:15:02 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 13 20:15:02 fabiocasa volumio[637]: info: Loading plugin "network"... Mar 13 20:15:02 fabiocasa volumio[637]: info: Refreshing Cached IP Addresses Mar 13 20:15:02 fabiocasa sudo[671]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 13 20:15:02 fabiocasa sudo[671]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:02 fabiocasa sudo[671]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:02 fabiocasa sudo[673]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 13 20:15:02 fabiocasa sudo[673]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:02 fabiocasa sudo[673]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:02 fabiocasa volumio[637]: info: Loading plugin "services"... Mar 13 20:15:02 fabiocasa volumio[637]: info: Loading plugin "alsa_controller"... Mar 13 20:15:02 fabiocasa sudo[683]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 13 20:15:02 fabiocasa sudo[683]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:02 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:15:02 fabiocasa volumio[637]: info: Loading plugin "wizard"... Mar 13 20:15:02 fabiocasa volumio[637]: info: Loading plugin "networkfs"... Mar 13 20:15:02 fabiocasa volumio[637]: info: Starting Udev Watcher for removable devices Mar 13 20:15:02 fabiocasa volumio[637]: info: Ignoring mount for partition: boot Mar 13 20:15:02 fabiocasa volumio[637]: info: Ignoring mount for partition: volumio Mar 13 20:15:02 fabiocasa volumio[637]: info: Ignoring mount for partition: volumio_data Mar 13 20:15:02 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:15:02 fabiocasa volumio[637]: info: Loading plugin "volumio_command_line_client"... Mar 13 20:15:02 fabiocasa volumio[637]: info: Loading plugin "upnp"... Mar 13 20:15:02 fabiocasa volumio[637]: info: [1741893302842] Starting Upmpd Daemon Mar 13 20:15:02 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:15:02 fabiocasa volumio[637]: info: Loading plugin "my_music"... Mar 13 20:15:02 fabiocasa volumio[637]: info: Loading plugin "mpd"... Mar 13 20:15:03 fabiocasa volumio[637]: info: Loading plugin "upnp_browser"... Mar 13 20:15:03 fabiocasa volumio[637]: info: Loading plugin "alarm-clock"... Mar 13 20:15:03 fabiocasa volumio[637]: info: Loading plugin "airplay_emulation"... Mar 13 20:15:03 fabiocasa volumio[637]: info: Starting Shairport Sync Mar 13 20:15:03 fabiocasa volumio[637]: info: Loading plugin "last_100"... Mar 13 20:15:03 fabiocasa volumio[637]: info: Loading plugin "webradio"... Mar 13 20:15:03 fabiocasa volumio[637]: info: Loading plugin "i2s_dacs"... Mar 13 20:15:03 fabiocasa volumio[637]: info: Loading plugin "volumiodiscovery"... Mar 13 20:15:03 fabiocasa volumio[637]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:03 fabiocasa volumio[637]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:03 fabiocasa volumio[637]: *** WARNING *** For more information see Mar 13 20:15:03 fabiocasa node[637]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:03 fabiocasa volumio[637]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:03 fabiocasa volumio[637]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:03 fabiocasa volumio[637]: *** WARNING *** For more information see Mar 13 20:15:03 fabiocasa node[637]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:03 fabiocasa node[637]: *** WARNING *** For more information see Mar 13 20:15:03 fabiocasa node[637]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:03 fabiocasa node[637]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:03 fabiocasa node[637]: *** WARNING *** For more information see Mar 13 20:15:03 fabiocasa volumio[637]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 13 20:15:03 fabiocasa volumio[637]: info: Discovery: Started advertising with name: FabioCasa Mar 13 20:15:03 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:15:03 fabiocasa volumio[637]: info: Loading plugin "spop"... Mar 13 20:15:04 fabiocasa volumio-remote-updater[576]: [2025-03-13 20:15:04] [connect] Successful connection Mar 13 20:15:04 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:04 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 13 20:15:04 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:04 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:04 fabiocasa go-librespot[703]: Librespot-go daemon starting... Mar 13 20:15:04 fabiocasa go-librespot[703]: time="2025-03-13T20:15:04+01:00" level=info msg="generated new device id: ea282830cace8b5c99b4c0820741878465b81710" Mar 13 20:15:04 fabiocasa go-librespot[703]: time="2025-03-13T20:15:04+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:04 fabiocasa go-librespot[703]: time="2025-03-13T20:15:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:04 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:04 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:04 fabiocasa volumio[637]: info: Loading plugin "squeezelite_mc"... Mar 13 20:15:05 fabiocasa sudo[683]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:05 fabiocasa volumio[637]: info: Loading plugin "ytmusic"... Mar 13 20:15:06 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 13 20:15:06 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 13 20:15:06 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 13 20:15:07 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 13 20:15:07 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:07 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 13 20:15:07 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:07 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:07 fabiocasa go-librespot[710]: Librespot-go daemon starting... Mar 13 20:15:07 fabiocasa go-librespot[710]: time="2025-03-13T20:15:07+01:00" level=info msg="generated new device id: e5b9dee20e7e7efea77fdfa8298939bd1f45f7af" Mar 13 20:15:07 fabiocasa go-librespot[710]: time="2025-03-13T20:15:07+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:07 fabiocasa go-librespot[710]: time="2025-03-13T20:15:07+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:07 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:07 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:08 fabiocasa volumio[637]: info: Loading plugin "outputs"... Mar 13 20:15:08 fabiocasa volumio[637]: info: Loading plugin "albumart"... Mar 13 20:15:08 fabiocasa volumio[637]: info: Plugin example_plugin is not enabled Mar 13 20:15:08 fabiocasa volumio[637]: info: Loading plugin "inputs"... Mar 13 20:15:08 fabiocasa volumio[637]: info: Loading plugin "updater_comm"... Mar 13 20:15:08 fabiocasa volumio[637]: info: Plugin mpdemulation is not enabled Mar 13 20:15:08 fabiocasa volumio[637]: info: Loading plugin "rest_api"... Mar 13 20:15:08 fabiocasa volumio[637]: info: Loading plugin "websocket"... Mar 13 20:15:08 fabiocasa volumio[637]: info: Starting Socket.io Server version 2.3.0 Mar 13 20:15:08 fabiocasa volumio[637]: info: Loading plugin "radio_paradise"... Mar 13 20:15:08 fabiocasa volumio[637]: Forking 3 albumart workers Mar 13 20:15:08 fabiocasa volumio[637]: info: Applying required configuration parameters for plugin radio_paradise Mar 13 20:15:08 fabiocasa volumio[637]: info: [1741893308695] [RadioParadise] API delay: 5 Mar 13 20:15:08 fabiocasa volumio[637]: info: Loading i18n strings for locale it Mar 13 20:15:08 fabiocasa volumio[637]: Updating browse sources language Mar 13 20:15:08 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:08 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:15:08 fabiocasa volumio[637]: info: CoreCommandRouter::initPlayerControls Mar 13 20:15:08 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:08 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:08 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:08 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:08 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:08 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:08 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:08 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:08 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:15:08 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 13 20:15:08 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 13 20:15:08 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 13 20:15:08 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 13 20:15:08 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 13 20:15:08 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 13 20:15:08 fabiocasa volumio[637]: Express server listening on port 3000 Mar 13 20:15:08 fabiocasa volumio[637]: [Metrics] WebUI: 8s 556.05ms Mar 13 20:15:08 fabiocasa volumio[637]: info: CoreStateMachine::resetVolumioState Mar 13 20:15:08 fabiocasa volumio[637]: info: CoreStateMachine::getcurrentVolume Mar 13 20:15:08 fabiocasa volumio[637]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:15:09 fabiocasa volumio[637]: info: Volumio Network Manager: Network status updated: 0 Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:09 fabiocasa volumio[637]: info: Reloading queue from file Mar 13 20:15:09 fabiocasa volumio[637]: info: Setting Device type: Raspberry PI Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreStateMachine::setRepeat null single undefined Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreStateMachine::pushState Mar 13 20:15:09 fabiocasa volumio[637]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreStateMachine::setRandom true Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreStateMachine::pushState Mar 13 20:15:09 fabiocasa volumio[637]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:09 fabiocasa volumio[637]: info: Completed loading Core Plugins Mar 13 20:15:09 fabiocasa volumio[637]: info: Preparing to generate the ALSA configuration file Mar 13 20:15:09 fabiocasa volumio[637]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreStateMachine::pushState Mar 13 20:15:09 fabiocasa volumio[637]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreStateMachine::updateTrackBlock Mar 13 20:15:09 fabiocasa volumio[637]: info: CorePlayQueue::getTrackBlock Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:15:09 fabiocasa volumio[637]: info: Asound.conf file unchanged, so no further update is needed Mar 13 20:15:09 fabiocasa volumio[637]: info: Output device has changed, restarting MPD Mar 13 20:15:09 fabiocasa sudo[761]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 13 20:15:09 fabiocasa sudo[761]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:09 fabiocasa sudo[761]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:09 fabiocasa volumio[637]: info: Output device has changed, restarting Shairport Sync Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:09 fabiocasa volumio[637]: Starting albumart workers Mar 13 20:15:09 fabiocasa volumio[637]: Starting albumart workers Mar 13 20:15:09 fabiocasa sudo[764]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 13 20:15:09 fabiocasa sudo[764]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:09 fabiocasa volumio[637]: Starting albumart workers Mar 13 20:15:09 fabiocasa systemd[1]: Stopping Music Player Daemon... Mar 13 20:15:09 fabiocasa systemd[1]: mpd.service: Succeeded. Mar 13 20:15:09 fabiocasa systemd[1]: Stopped Music Player Daemon. Mar 13 20:15:09 fabiocasa volumio[637]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:15:09 fabiocasa volumio[637]: info: ___________ START PLUGINS ___________ Mar 13 20:15:09 fabiocasa volumio[637]: info: ControllerMpd::onStart: Initializing MPD Mar 13 20:15:09 fabiocasa volumio[637]: info: Creating MPD Configuration file Mar 13 20:15:09 fabiocasa systemd[1]: Starting Music Player Daemon... Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:09 fabiocasa volumio[637]: info: [1741893309743] CoreMusicLibrary::Adding element Server multimediali Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:09 fabiocasa sudo[774]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:09 fabiocasa sudo[776]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 13 20:15:09 fabiocasa sudo[776]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:09 fabiocasa sudo[774]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:09 fabiocasa sudo[774]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:09 fabiocasa systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Mar 13 20:15:09 fabiocasa systemd[1]: mpd.service: Succeeded. Mar 13 20:15:09 fabiocasa systemd[1]: Stopped Music Player Daemon. Mar 13 20:15:09 fabiocasa systemd[1]: Starting Music Player Daemon... Mar 13 20:15:09 fabiocasa volumio[637]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:09 fabiocasa volumio[637]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:09 fabiocasa volumio[637]: info: [1741893309911] CoreMusicLibrary::Adding element Last_100 Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:09 fabiocasa volumio[637]: info: [1741893309920] CoreMusicLibrary::Adding element Webradio Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:09 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:15:09 fabiocasa volumio[637]: info: Initializing BBC Radios Mar 13 20:15:09 fabiocasa sudo[784]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 13 20:15:09 fabiocasa sudo[784]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:09 fabiocasa sudo[784]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: Creating Spotify config file Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: [squeezelite_mc] Starting proxy server... Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:10 fabiocasa volumio[637]: info: [1741893310435] CoreMusicLibrary::Adding element YouTube Music Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:10 fabiocasa volumio[637]: Cannot find translation for source YouTube Music Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:10 fabiocasa volumio[637]: info: [1741893310454] CoreMusicLibrary::Adding element Radio Paradise Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:10 fabiocasa volumio[637]: Cannot find translation for source YouTube Music Mar 13 20:15:10 fabiocasa volumio[637]: Cannot find translation for source Radio Paradise Mar 13 20:15:10 fabiocasa volumio[637]: info: Volumio Calling Home Mar 13 20:15:10 fabiocasa volumio[637]: info: [squeezelite_mc] Proxy server started on port 40483 Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:15:10 fabiocasa volumio[637]: Unhandled rejection Error: No sockets available, cannot start. Mar 13 20:15:10 fabiocasa volumio[637]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Mar 13 20:15:10 fabiocasa volumio[637]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Mar 13 20:15:10 fabiocasa volumio[637]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Mar 13 20:15:10 fabiocasa volumio[637]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Mar 13 20:15:10 fabiocasa volumio[637]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Mar 13 20:15:10 fabiocasa volumio[637]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Mar 13 20:15:10 fabiocasa volumio[637]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Mar 13 20:15:10 fabiocasa volumio[637]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Mar 13 20:15:10 fabiocasa volumio[637]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Mar 13 20:15:10 fabiocasa volumio[637]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Mar 13 20:15:10 fabiocasa volumio[637]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Mar 13 20:15:10 fabiocasa volumio[637]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Mar 13 20:15:10 fabiocasa volumio[637]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Mar 13 20:15:10 fabiocasa volumio[637]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Mar 13 20:15:10 fabiocasa volumio[637]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Mar 13 20:15:10 fabiocasa volumio[637]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 13 20:15:10 fabiocasa volumio[637]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Mar 13 20:15:10 fabiocasa volumio[637]: info: MPD Permissions set Mar 13 20:15:10 fabiocasa volumio[637]: info: MPD Permissions set Mar 13 20:15:10 fabiocasa volumio[637]: info: Spotify config file written Mar 13 20:15:10 fabiocasa sudo[832]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 13 20:15:10 fabiocasa sudo[832]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:10 fabiocasa volumio[637]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 13 20:15:10 fabiocasa volumio[637]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:15:10 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreStateMachine::pushState Mar 13 20:15:10 fabiocasa volumio[637]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:10 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:10 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:10 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:10 fabiocasa go-librespot[834]: Librespot-go daemon starting... Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:10 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:11 fabiocasa systemd[1]: Stopping go-librespot Daemon... Mar 13 20:15:11 fabiocasa volumio[637]: info: No need to fix Spotify hosts Mar 13 20:15:11 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Mar 13 20:15:11 fabiocasa systemd[1]: go-librespot-daemon.service: Succeeded. Mar 13 20:15:11 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:11 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:11 fabiocasa sudo[832]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:11 fabiocasa go-librespot[848]: Librespot-go daemon starting... Mar 13 20:15:11 fabiocasa go-librespot[848]: time="2025-03-13T20:15:11+01:00" level=info msg="generated new device id: b9931841f70508362b1912afdeef7460f4c5ddc0" Mar 13 20:15:11 fabiocasa go-librespot[848]: time="2025-03-13T20:15:11+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:11 fabiocasa go-librespot[848]: time="2025-03-13T20:15:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:11 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:11 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:11 fabiocasa volumio[637]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:15:11 fabiocasa volumio[637]: info: CoreStateMachine::pushState Mar 13 20:15:11 fabiocasa volumio[637]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:11 fabiocasa volumio[637]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:11 fabiocasa volumio[637]: info: [squeezelite_mc] Server discovery started Mar 13 20:15:11 fabiocasa volumio[637]: info: [squeezelite_mc] Player finder started Mar 13 20:15:11 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:11 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:11 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:11 fabiocasa volumio[637]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:15:11 fabiocasa volumio[637]: info: [squeezelite_mc] Executing aplay -D hw:2 --nonblock -f MPEG /dev/zero 2>&1 || true Mar 13 20:15:11 fabiocasa volumio[637]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 13 20:15:11 fabiocasa volumio[637]: Error: send ENETUNREACH 255.255.255.255:3483 Mar 13 20:15:11 fabiocasa volumio[637]: at doSend (dgram.js:692:16) Mar 13 20:15:11 fabiocasa volumio[637]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Mar 13 20:15:11 fabiocasa volumio[637]: at afterDns (dgram.js:638:5) Mar 13 20:15:11 fabiocasa volumio[637]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Mar 13 20:15:11 fabiocasa volumio[637]: errno: -101, Mar 13 20:15:11 fabiocasa volumio[637]: code: 'ENETUNREACH', Mar 13 20:15:11 fabiocasa volumio[637]: syscall: 'send', Mar 13 20:15:11 fabiocasa volumio[637]: address: '255.255.255.255', Mar 13 20:15:11 fabiocasa volumio[637]: port: 3483 Mar 13 20:15:11 fabiocasa volumio[637]: } Mar 13 20:15:11 fabiocasa volumio[637]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 13 20:15:11 fabiocasa kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 13 20:15:11 fabiocasa mpd[790]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 13 20:15:11 fabiocasa mpd[790]: output: No 'audio_output' defined in config file Mar 13 20:15:11 fabiocasa sudo[866]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-13 20:14 Mar 13 20:15:11 fabiocasa sudo[866]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:11 fabiocasa mpd[790]: output: Successfully detected a sndio audio device Mar 13 20:15:11 fabiocasa mpd[790]: zeroconf: No global port, disabling zeroconf Mar 13 20:15:11 fabiocasa systemd[1]: Started Music Player Daemon. Mar 13 20:15:11 fabiocasa sudo[764]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:11 fabiocasa sudo[776]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:11 fabiocasa sudo[866]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:11 fabiocasa systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:11 fabiocasa systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 13 20:15:12 fabiocasa systemd[1]: Started dynamicswap service. Mar 13 20:15:12 fabiocasa systemd[1]: dynamicswap.service: Succeeded. Mar 13 20:15:12 fabiocasa systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Mar 13 20:15:12 fabiocasa systemd[1]: volumio.service: Scheduled restart job, restart counter is at 33. Mar 13 20:15:12 fabiocasa systemd[1]: Stopped Volumio Backend Module. Mar 13 20:15:12 fabiocasa systemd[1]: Started Volumio Backend Module. Mar 13 20:15:12 fabiocasa systemd[1]: Started dynamicswap service. Mar 13 20:15:12 fabiocasa systemd[1]: dynamicswap.service: Succeeded. Mar 13 20:15:12 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 13 20:15:13 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 13 20:15:13 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 13 20:15:13 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 13 20:15:13 fabiocasa volumio[882]: info: ------------------------------------------- Mar 13 20:15:13 fabiocasa volumio[882]: info: ----- Volumio3 ---- Mar 13 20:15:13 fabiocasa volumio[882]: info: ------------------------------------------- Mar 13 20:15:13 fabiocasa volumio[882]: info: ----- System startup ---- Mar 13 20:15:13 fabiocasa volumio[882]: info: ------------------------------------------- Mar 13 20:15:14 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:14 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 13 20:15:14 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:14 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:14 fabiocasa go-librespot[904]: Librespot-go daemon starting... Mar 13 20:15:14 fabiocasa go-librespot[904]: time="2025-03-13T20:15:14+01:00" level=info msg="generated new device id: 8a8f043f6d8585914fce4d69cfaf4b9a461e1609" Mar 13 20:15:14 fabiocasa go-librespot[904]: time="2025-03-13T20:15:14+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:14 fabiocasa go-librespot[904]: time="2025-03-13T20:15:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:14 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:14 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:14 fabiocasa volumio[882]: info: MYVOLUMIO Environment detected Mar 13 20:15:14 fabiocasa volumio[882]: info: Plugin folders cleanup Mar 13 20:15:14 fabiocasa volumio[882]: info: Scanning into folder /volumio/app/plugins/ Mar 13 20:15:14 fabiocasa volumio[882]: info: Scanning category audio_interface Mar 13 20:15:14 fabiocasa volumio[882]: info: Scanning category miscellanea Mar 13 20:15:14 fabiocasa volumio[882]: info: Scanning category music_service Mar 13 20:15:14 fabiocasa volumio[882]: info: Scanning category plugins.json Mar 13 20:15:14 fabiocasa volumio[882]: info: Scanning category system_controller Mar 13 20:15:14 fabiocasa volumio[882]: info: Scanning category user_interface Mar 13 20:15:14 fabiocasa volumio[882]: info: Scanning into folder /data/plugins/ Mar 13 20:15:14 fabiocasa volumio[882]: info: Scanning category music_service Mar 13 20:15:14 fabiocasa volumio[882]: info: Plugin folders cleanup completed Mar 13 20:15:14 fabiocasa volumio[882]: info: ------------------------------------------- Mar 13 20:15:14 fabiocasa volumio[882]: info: ----- Core plugins startup ---- Mar 13 20:15:14 fabiocasa volumio[882]: info: ------------------------------------------- Mar 13 20:15:14 fabiocasa volumio[882]: info: Loading plugins from folder /volumio/app/plugins/ Mar 13 20:15:14 fabiocasa volumio[882]: info: Adding plugin upnp to MyMusic Plugins Mar 13 20:15:14 fabiocasa volumio[882]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 13 20:15:14 fabiocasa volumio[882]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 13 20:15:14 fabiocasa volumio[882]: info: Loading plugins from folder /data/plugins/ Mar 13 20:15:14 fabiocasa volumio[882]: info: Loading plugin "system"... Mar 13 20:15:14 fabiocasa volumio[882]: info: Loading plugin "appearance"... Mar 13 20:15:15 fabiocasa wpa_supplicant[877]: wlan0: Failed to initiate sched scan Mar 13 20:15:15 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 13 20:15:15 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 13 20:15:15 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 13 20:15:15 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 13 20:15:15 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 13 20:15:15 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 13 20:15:15 fabiocasa volumio[882]: info: Loading plugin "network"... Mar 13 20:15:15 fabiocasa volumio[882]: info: Refreshing Cached IP Addresses Mar 13 20:15:15 fabiocasa sudo[918]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 13 20:15:15 fabiocasa sudo[918]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:15 fabiocasa sudo[918]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:15 fabiocasa sudo[920]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 13 20:15:15 fabiocasa sudo[920]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:15 fabiocasa sudo[920]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:15 fabiocasa volumio[882]: info: Loading plugin "services"... Mar 13 20:15:15 fabiocasa volumio[882]: info: Loading plugin "alsa_controller"... Mar 13 20:15:15 fabiocasa sudo[933]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 13 20:15:15 fabiocasa sudo[933]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:15 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:15:15 fabiocasa volumio[882]: info: Loading plugin "wizard"... Mar 13 20:15:15 fabiocasa volumio[882]: info: Loading plugin "networkfs"... Mar 13 20:15:15 fabiocasa volumio[882]: info: Starting Udev Watcher for removable devices Mar 13 20:15:15 fabiocasa volumio[882]: info: Ignoring mount for partition: boot Mar 13 20:15:15 fabiocasa volumio[882]: info: Ignoring mount for partition: volumio Mar 13 20:15:15 fabiocasa volumio[882]: info: Ignoring mount for partition: volumio_data Mar 13 20:15:15 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:15:15 fabiocasa volumio[882]: info: Loading plugin "volumio_command_line_client"... Mar 13 20:15:15 fabiocasa volumio[882]: info: Loading plugin "upnp"... Mar 13 20:15:15 fabiocasa volumio[882]: info: [1741893315884] Starting Upmpd Daemon Mar 13 20:15:15 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:15:15 fabiocasa volumio[882]: info: Loading plugin "my_music"... Mar 13 20:15:15 fabiocasa volumio[882]: info: Loading plugin "mpd"... Mar 13 20:15:16 fabiocasa volumio[882]: info: Loading plugin "upnp_browser"... Mar 13 20:15:16 fabiocasa volumio[882]: info: Loading plugin "alarm-clock"... Mar 13 20:15:16 fabiocasa volumio-remote-updater[576]: [2025-03-13 20:15:16] [connect] Successful connection Mar 13 20:15:16 fabiocasa volumio[882]: info: Loading plugin "airplay_emulation"... Mar 13 20:15:16 fabiocasa volumio[882]: info: Starting Shairport Sync Mar 13 20:15:16 fabiocasa volumio[882]: info: Loading plugin "last_100"... Mar 13 20:15:16 fabiocasa volumio[882]: info: Loading plugin "webradio"... Mar 13 20:15:16 fabiocasa volumio[882]: info: Loading plugin "i2s_dacs"... Mar 13 20:15:16 fabiocasa volumio[882]: info: Loading plugin "volumiodiscovery"... Mar 13 20:15:16 fabiocasa volumio[882]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:16 fabiocasa volumio[882]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:16 fabiocasa volumio[882]: *** WARNING *** For more information see Mar 13 20:15:16 fabiocasa volumio[882]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:16 fabiocasa node[882]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:16 fabiocasa volumio[882]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:16 fabiocasa volumio[882]: *** WARNING *** For more information see Mar 13 20:15:16 fabiocasa node[882]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:16 fabiocasa node[882]: *** WARNING *** For more information see Mar 13 20:15:16 fabiocasa node[882]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:16 fabiocasa node[882]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:16 fabiocasa node[882]: *** WARNING *** For more information see Mar 13 20:15:16 fabiocasa volumio[882]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 13 20:15:16 fabiocasa volumio[882]: info: Discovery: Started advertising with name: FabioCasa Mar 13 20:15:16 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:15:16 fabiocasa volumio[882]: info: Loading plugin "spop"... Mar 13 20:15:17 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:17 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 13 20:15:17 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:17 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:17 fabiocasa go-librespot[947]: Librespot-go daemon starting... Mar 13 20:15:17 fabiocasa go-librespot[947]: time="2025-03-13T20:15:17+01:00" level=info msg="generated new device id: 5996645899e52db4554213555f9b1d59c2c13b67" Mar 13 20:15:17 fabiocasa go-librespot[947]: time="2025-03-13T20:15:17+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:17 fabiocasa go-librespot[947]: time="2025-03-13T20:15:17+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:17 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:17 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:17 fabiocasa volumio[882]: info: Loading plugin "squeezelite_mc"... Mar 13 20:15:18 fabiocasa sudo[933]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:18 fabiocasa volumio[882]: info: Loading plugin "ytmusic"... Mar 13 20:15:19 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 13 20:15:19 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 13 20:15:19 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 13 20:15:20 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 13 20:15:20 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:20 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 13 20:15:20 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:20 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:20 fabiocasa go-librespot[957]: Librespot-go daemon starting... Mar 13 20:15:20 fabiocasa go-librespot[957]: time="2025-03-13T20:15:20+01:00" level=info msg="generated new device id: 9490220eee65d25d083555c49c1cb7e9c092f1af" Mar 13 20:15:20 fabiocasa go-librespot[957]: time="2025-03-13T20:15:20+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:20 fabiocasa go-librespot[957]: time="2025-03-13T20:15:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:20 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:20 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:21 fabiocasa volumio[882]: info: Loading plugin "outputs"... Mar 13 20:15:21 fabiocasa volumio[882]: info: Loading plugin "albumart"... Mar 13 20:15:21 fabiocasa volumio[882]: info: Plugin example_plugin is not enabled Mar 13 20:15:21 fabiocasa volumio[882]: info: Loading plugin "inputs"... Mar 13 20:15:21 fabiocasa volumio[882]: info: Loading plugin "updater_comm"... Mar 13 20:15:21 fabiocasa volumio[882]: info: Plugin mpdemulation is not enabled Mar 13 20:15:21 fabiocasa volumio[882]: info: Loading plugin "rest_api"... Mar 13 20:15:21 fabiocasa volumio[882]: info: Loading plugin "websocket"... Mar 13 20:15:21 fabiocasa volumio[882]: info: Starting Socket.io Server version 2.3.0 Mar 13 20:15:21 fabiocasa volumio[882]: info: Loading plugin "radio_paradise"... Mar 13 20:15:21 fabiocasa volumio[882]: Forking 3 albumart workers Mar 13 20:15:21 fabiocasa volumio[882]: info: Applying required configuration parameters for plugin radio_paradise Mar 13 20:15:21 fabiocasa volumio[882]: info: [1741893321821] [RadioParadise] API delay: 5 Mar 13 20:15:21 fabiocasa volumio[882]: info: Loading i18n strings for locale it Mar 13 20:15:21 fabiocasa volumio[882]: Updating browse sources language Mar 13 20:15:21 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:21 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 13 20:15:21 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 13 20:15:21 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 13 20:15:21 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 13 20:15:21 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 13 20:15:21 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::initPlayerControls Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:15:22 fabiocasa volumio[882]: Express server listening on port 3000 Mar 13 20:15:22 fabiocasa volumio[882]: [Metrics] WebUI: 8s 686.87ms Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreStateMachine::resetVolumioState Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreStateMachine::getcurrentVolume Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:15:22 fabiocasa volumio[882]: info: Volumio Network Manager: Network status updated: 0 Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:22 fabiocasa volumio[882]: info: Reloading queue from file Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreStateMachine::setRepeat null single undefined Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreStateMachine::pushState Mar 13 20:15:22 fabiocasa volumio[882]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreStateMachine::setRandom true Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreStateMachine::pushState Mar 13 20:15:22 fabiocasa volumio[882]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:22 fabiocasa volumio[882]: info: Setting Device type: Raspberry PI Mar 13 20:15:22 fabiocasa volumio[882]: info: Completed loading Core Plugins Mar 13 20:15:22 fabiocasa volumio[882]: info: Preparing to generate the ALSA configuration file Mar 13 20:15:22 fabiocasa volumio[882]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreStateMachine::pushState Mar 13 20:15:22 fabiocasa volumio[882]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreStateMachine::updateTrackBlock Mar 13 20:15:22 fabiocasa volumio[882]: info: CorePlayQueue::getTrackBlock Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:15:22 fabiocasa volumio[882]: Starting albumart workers Mar 13 20:15:22 fabiocasa volumio[882]: info: Asound.conf file unchanged, so no further update is needed Mar 13 20:15:22 fabiocasa volumio[882]: info: Output device has changed, restarting MPD Mar 13 20:15:22 fabiocasa volumio[882]: Starting albumart workers Mar 13 20:15:22 fabiocasa volumio[882]: Starting albumart workers Mar 13 20:15:22 fabiocasa sudo[1004]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 13 20:15:22 fabiocasa sudo[1004]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:22 fabiocasa volumio[882]: info: Output device has changed, restarting Shairport Sync Mar 13 20:15:22 fabiocasa sudo[1004]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:22 fabiocasa sudo[1008]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 13 20:15:22 fabiocasa sudo[1008]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:22 fabiocasa volumio[882]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:15:22 fabiocasa volumio[882]: info: ___________ START PLUGINS ___________ Mar 13 20:15:22 fabiocasa volumio[882]: info: ControllerMpd::onStart: Initializing MPD Mar 13 20:15:22 fabiocasa volumio[882]: info: Creating MPD Configuration file Mar 13 20:15:22 fabiocasa systemd[1]: Stopping Music Player Daemon... Mar 13 20:15:22 fabiocasa systemd[1]: mpd.service: Succeeded. Mar 13 20:15:22 fabiocasa systemd[1]: Stopped Music Player Daemon. Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:22 fabiocasa sudo[1014]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 13 20:15:22 fabiocasa sudo[1014]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:22 fabiocasa volumio[882]: info: [1741893322906] CoreMusicLibrary::Adding element Server multimediali Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:22 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:22 fabiocasa sudo[1014]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:22 fabiocasa systemd[1]: Starting Music Player Daemon... Mar 13 20:15:22 fabiocasa sudo[1017]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 13 20:15:22 fabiocasa sudo[1017]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:22 fabiocasa systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Mar 13 20:15:22 fabiocasa systemd[1]: mpd.service: Succeeded. Mar 13 20:15:22 fabiocasa systemd[1]: Stopped Music Player Daemon. Mar 13 20:15:23 fabiocasa systemd[1]: Starting Music Player Daemon... Mar 13 20:15:23 fabiocasa volumio[882]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:23 fabiocasa sudo[1030]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 13 20:15:23 fabiocasa sudo[1030]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:23 fabiocasa sudo[1030]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:23 fabiocasa volumio[882]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:23 fabiocasa volumio[882]: info: [1741893323179] CoreMusicLibrary::Adding element Last_100 Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:23 fabiocasa volumio[882]: info: [1741893323184] CoreMusicLibrary::Adding element Webradio Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:15:23 fabiocasa volumio[882]: info: Initializing BBC Radios Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:23 fabiocasa volumio[882]: info: Creating Spotify config file Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:23 fabiocasa volumio[882]: info: [squeezelite_mc] Starting proxy server... Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:23 fabiocasa volumio[882]: info: [1741893323551] CoreMusicLibrary::Adding element YouTube Music Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:23 fabiocasa volumio[882]: Cannot find translation for source YouTube Music Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:23 fabiocasa volumio[882]: info: [1741893323563] CoreMusicLibrary::Adding element Radio Paradise Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:23 fabiocasa volumio[882]: Cannot find translation for source YouTube Music Mar 13 20:15:23 fabiocasa volumio[882]: Cannot find translation for source Radio Paradise Mar 13 20:15:23 fabiocasa volumio[882]: info: Volumio Calling Home Mar 13 20:15:23 fabiocasa volumio[882]: info: [squeezelite_mc] Proxy server started on port 35797 Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:15:23 fabiocasa volumio[882]: Unhandled rejection Error: No sockets available, cannot start. Mar 13 20:15:23 fabiocasa volumio[882]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Mar 13 20:15:23 fabiocasa volumio[882]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Mar 13 20:15:23 fabiocasa volumio[882]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Mar 13 20:15:23 fabiocasa volumio[882]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Mar 13 20:15:23 fabiocasa volumio[882]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Mar 13 20:15:23 fabiocasa volumio[882]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Mar 13 20:15:23 fabiocasa volumio[882]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Mar 13 20:15:23 fabiocasa volumio[882]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Mar 13 20:15:23 fabiocasa volumio[882]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Mar 13 20:15:23 fabiocasa volumio[882]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Mar 13 20:15:23 fabiocasa volumio[882]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Mar 13 20:15:23 fabiocasa volumio[882]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Mar 13 20:15:23 fabiocasa volumio[882]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Mar 13 20:15:23 fabiocasa volumio[882]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Mar 13 20:15:23 fabiocasa volumio[882]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Mar 13 20:15:23 fabiocasa volumio[882]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 13 20:15:23 fabiocasa volumio[882]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Mar 13 20:15:23 fabiocasa volumio[882]: info: MPD Permissions set Mar 13 20:15:23 fabiocasa volumio[882]: info: MPD Permissions set Mar 13 20:15:23 fabiocasa volumio[882]: info: Spotify config file written Mar 13 20:15:23 fabiocasa sudo[1077]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 13 20:15:23 fabiocasa sudo[1077]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:23 fabiocasa ntpd[779]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Mar 13 20:15:23 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:23 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 13 20:15:23 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:23 fabiocasa volumio[882]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 13 20:15:23 fabiocasa volumio[882]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreStateMachine::pushState Mar 13 20:15:23 fabiocasa volumio[882]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:23 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:23 fabiocasa go-librespot[1079]: Librespot-go daemon starting... Mar 13 20:15:23 fabiocasa systemd[1]: Stopping go-librespot Daemon... Mar 13 20:15:23 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Mar 13 20:15:23 fabiocasa systemd[1]: go-librespot-daemon.service: Succeeded. Mar 13 20:15:23 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:23 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:24 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:24 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:24 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:24 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:24 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:24 fabiocasa sudo[1077]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:24 fabiocasa go-librespot[1085]: Librespot-go daemon starting... Mar 13 20:15:24 fabiocasa go-librespot[1085]: time="2025-03-13T20:15:24+01:00" level=info msg="generated new device id: bbc928c653b28f711f7fa4ab05e15fd4aee94830" Mar 13 20:15:24 fabiocasa go-librespot[1085]: time="2025-03-13T20:15:24+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:24 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:24 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:24 fabiocasa go-librespot[1085]: time="2025-03-13T20:15:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:24 fabiocasa volumio[882]: info: No need to fix Spotify hosts Mar 13 20:15:24 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:24 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:24 fabiocasa volumio[882]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:15:24 fabiocasa volumio[882]: info: CoreStateMachine::pushState Mar 13 20:15:24 fabiocasa volumio[882]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:24 fabiocasa volumio[882]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:24 fabiocasa volumio[882]: info: [squeezelite_mc] Server discovery started Mar 13 20:15:24 fabiocasa volumio[882]: info: [squeezelite_mc] Player finder started Mar 13 20:15:24 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:24 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:24 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:24 fabiocasa volumio[882]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:15:24 fabiocasa volumio[882]: info: [squeezelite_mc] Executing aplay -D hw:2 --nonblock -f MPEG /dev/zero 2>&1 || true Mar 13 20:15:24 fabiocasa volumio[882]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 13 20:15:24 fabiocasa volumio[882]: Error: send ENETUNREACH 255.255.255.255:3483 Mar 13 20:15:24 fabiocasa volumio[882]: at doSend (dgram.js:692:16) Mar 13 20:15:24 fabiocasa volumio[882]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Mar 13 20:15:24 fabiocasa volumio[882]: at afterDns (dgram.js:638:5) Mar 13 20:15:24 fabiocasa volumio[882]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Mar 13 20:15:24 fabiocasa volumio[882]: errno: -101, Mar 13 20:15:24 fabiocasa volumio[882]: code: 'ENETUNREACH', Mar 13 20:15:24 fabiocasa volumio[882]: syscall: 'send', Mar 13 20:15:24 fabiocasa volumio[882]: address: '255.255.255.255', Mar 13 20:15:24 fabiocasa volumio[882]: port: 3483 Mar 13 20:15:24 fabiocasa volumio[882]: } Mar 13 20:15:24 fabiocasa volumio[882]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 13 20:15:24 fabiocasa kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 13 20:15:24 fabiocasa sudo[1109]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-13 20:14 Mar 13 20:15:24 fabiocasa sudo[1109]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:24 fabiocasa mpd[1035]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 13 20:15:24 fabiocasa mpd[1035]: output: No 'audio_output' defined in config file Mar 13 20:15:24 fabiocasa mpd[1035]: output: Successfully detected a sndio audio device Mar 13 20:15:24 fabiocasa mpd[1035]: zeroconf: No global port, disabling zeroconf Mar 13 20:15:24 fabiocasa systemd[1]: Started Music Player Daemon. Mar 13 20:15:24 fabiocasa sudo[1017]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:24 fabiocasa sudo[1008]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:24 fabiocasa sudo[1109]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:25 fabiocasa systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:25 fabiocasa systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 13 20:15:25 fabiocasa systemd[1]: Started dynamicswap service. Mar 13 20:15:25 fabiocasa systemd[1]: dynamicswap.service: Succeeded. Mar 13 20:15:25 fabiocasa systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Mar 13 20:15:25 fabiocasa systemd[1]: volumio.service: Scheduled restart job, restart counter is at 34. Mar 13 20:15:25 fabiocasa systemd[1]: Stopped Volumio Backend Module. Mar 13 20:15:25 fabiocasa systemd[1]: Started Volumio Backend Module. Mar 13 20:15:25 fabiocasa systemd[1]: Started dynamicswap service. Mar 13 20:15:25 fabiocasa systemd[1]: dynamicswap.service: Succeeded. Mar 13 20:15:25 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 13 20:15:26 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 13 20:15:26 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 13 20:15:26 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 13 20:15:26 fabiocasa volumio[1125]: info: ------------------------------------------- Mar 13 20:15:26 fabiocasa volumio[1125]: info: ----- Volumio3 ---- Mar 13 20:15:26 fabiocasa volumio[1125]: info: ------------------------------------------- Mar 13 20:15:26 fabiocasa volumio[1125]: info: ----- System startup ---- Mar 13 20:15:26 fabiocasa volumio[1125]: info: ------------------------------------------- Mar 13 20:15:27 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:27 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 13 20:15:27 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:27 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:27 fabiocasa go-librespot[1185]: Librespot-go daemon starting... Mar 13 20:15:27 fabiocasa go-librespot[1185]: time="2025-03-13T20:15:27+01:00" level=info msg="generated new device id: ea02d0e8736e3420fa65ae192ab1724c044e1a60" Mar 13 20:15:27 fabiocasa go-librespot[1185]: time="2025-03-13T20:15:27+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:27 fabiocasa go-librespot[1185]: time="2025-03-13T20:15:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:27 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:27 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:27 fabiocasa volumio[1125]: info: MYVOLUMIO Environment detected Mar 13 20:15:27 fabiocasa volumio[1125]: info: Plugin folders cleanup Mar 13 20:15:27 fabiocasa volumio[1125]: info: Scanning into folder /volumio/app/plugins/ Mar 13 20:15:27 fabiocasa volumio[1125]: info: Scanning category audio_interface Mar 13 20:15:27 fabiocasa volumio[1125]: info: Scanning category miscellanea Mar 13 20:15:27 fabiocasa volumio[1125]: info: Scanning category music_service Mar 13 20:15:27 fabiocasa volumio[1125]: info: Scanning category plugins.json Mar 13 20:15:27 fabiocasa volumio[1125]: info: Scanning category system_controller Mar 13 20:15:27 fabiocasa volumio[1125]: info: Scanning category user_interface Mar 13 20:15:27 fabiocasa volumio[1125]: info: Scanning into folder /data/plugins/ Mar 13 20:15:27 fabiocasa volumio[1125]: info: Scanning category music_service Mar 13 20:15:27 fabiocasa volumio[1125]: info: Plugin folders cleanup completed Mar 13 20:15:27 fabiocasa volumio[1125]: info: ------------------------------------------- Mar 13 20:15:27 fabiocasa volumio[1125]: info: ----- Core plugins startup ---- Mar 13 20:15:27 fabiocasa volumio[1125]: info: ------------------------------------------- Mar 13 20:15:27 fabiocasa volumio[1125]: info: Loading plugins from folder /volumio/app/plugins/ Mar 13 20:15:27 fabiocasa volumio[1125]: info: Adding plugin upnp to MyMusic Plugins Mar 13 20:15:27 fabiocasa volumio[1125]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 13 20:15:27 fabiocasa volumio[1125]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 13 20:15:27 fabiocasa volumio[1125]: info: Loading plugins from folder /data/plugins/ Mar 13 20:15:27 fabiocasa volumio[1125]: info: Loading plugin "system"... Mar 13 20:15:27 fabiocasa volumio[1125]: info: Loading plugin "appearance"... Mar 13 20:15:28 fabiocasa wpa_supplicant[877]: wlan0: Failed to initiate sched scan Mar 13 20:15:28 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 13 20:15:28 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 13 20:15:28 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 13 20:15:28 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 13 20:15:28 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 13 20:15:28 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 13 20:15:28 fabiocasa volumio[1125]: info: Loading plugin "network"... Mar 13 20:15:28 fabiocasa volumio[1125]: info: Refreshing Cached IP Addresses Mar 13 20:15:28 fabiocasa sudo[1200]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 13 20:15:28 fabiocasa sudo[1200]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:28 fabiocasa sudo[1200]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:28 fabiocasa sudo[1202]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 13 20:15:28 fabiocasa sudo[1202]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:28 fabiocasa sudo[1202]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:28 fabiocasa volumio[1125]: info: Loading plugin "services"... Mar 13 20:15:28 fabiocasa volumio[1125]: info: Loading plugin "alsa_controller"... Mar 13 20:15:28 fabiocasa sudo[1215]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 13 20:15:28 fabiocasa sudo[1215]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:28 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:15:28 fabiocasa volumio[1125]: info: Loading plugin "wizard"... Mar 13 20:15:28 fabiocasa volumio[1125]: info: Loading plugin "networkfs"... Mar 13 20:15:28 fabiocasa volumio[1125]: info: Starting Udev Watcher for removable devices Mar 13 20:15:28 fabiocasa volumio[1125]: info: Ignoring mount for partition: boot Mar 13 20:15:28 fabiocasa volumio[1125]: info: Ignoring mount for partition: volumio Mar 13 20:15:28 fabiocasa volumio[1125]: info: Ignoring mount for partition: volumio_data Mar 13 20:15:28 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:15:28 fabiocasa volumio[1125]: info: Loading plugin "volumio_command_line_client"... Mar 13 20:15:28 fabiocasa volumio[1125]: info: Loading plugin "upnp"... Mar 13 20:15:28 fabiocasa volumio[1125]: info: [1741893328928] Starting Upmpd Daemon Mar 13 20:15:28 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:15:28 fabiocasa volumio[1125]: info: Loading plugin "my_music"... Mar 13 20:15:28 fabiocasa volumio[1125]: info: Loading plugin "mpd"... Mar 13 20:15:29 fabiocasa volumio[1125]: info: Loading plugin "upnp_browser"... Mar 13 20:15:29 fabiocasa volumio[1125]: info: Loading plugin "alarm-clock"... Mar 13 20:15:29 fabiocasa volumio[1125]: info: Loading plugin "airplay_emulation"... Mar 13 20:15:29 fabiocasa volumio[1125]: info: Starting Shairport Sync Mar 13 20:15:29 fabiocasa volumio[1125]: info: Loading plugin "last_100"... Mar 13 20:15:29 fabiocasa volumio[1125]: info: Loading plugin "webradio"... Mar 13 20:15:29 fabiocasa volumio[1125]: info: Loading plugin "i2s_dacs"... Mar 13 20:15:29 fabiocasa volumio[1125]: info: Loading plugin "volumiodiscovery"... Mar 13 20:15:29 fabiocasa volumio[1125]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:29 fabiocasa node[1125]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:29 fabiocasa volumio[1125]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:29 fabiocasa node[1125]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:29 fabiocasa volumio[1125]: *** WARNING *** For more information see Mar 13 20:15:29 fabiocasa node[1125]: *** WARNING *** For more information see Mar 13 20:15:29 fabiocasa volumio[1125]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:29 fabiocasa node[1125]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:29 fabiocasa volumio[1125]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:29 fabiocasa node[1125]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:29 fabiocasa volumio[1125]: *** WARNING *** For more information see Mar 13 20:15:29 fabiocasa node[1125]: *** WARNING *** For more information see Mar 13 20:15:29 fabiocasa volumio[1125]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 13 20:15:29 fabiocasa volumio[1125]: info: Discovery: Started advertising with name: FabioCasa Mar 13 20:15:29 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:15:29 fabiocasa volumio[1125]: info: Loading plugin "spop"... Mar 13 20:15:30 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:30 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 13 20:15:30 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:30 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:30 fabiocasa go-librespot[1232]: Librespot-go daemon starting... Mar 13 20:15:30 fabiocasa go-librespot[1232]: time="2025-03-13T20:15:30+01:00" level=info msg="generated new device id: af3424f40f63c1023978e52aaa374bb8e40a96f3" Mar 13 20:15:30 fabiocasa go-librespot[1232]: time="2025-03-13T20:15:30+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:30 fabiocasa go-librespot[1232]: time="2025-03-13T20:15:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:30 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:30 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:30 fabiocasa volumio[1125]: info: Loading plugin "squeezelite_mc"... Mar 13 20:15:31 fabiocasa sudo[1215]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:31 fabiocasa volumio-remote-updater[576]: [2025-03-13 20:15:31] [connect] Successful connection Mar 13 20:15:31 fabiocasa volumio[1125]: info: Loading plugin "ytmusic"... Mar 13 20:15:32 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 13 20:15:32 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 13 20:15:32 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 13 20:15:33 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 13 20:15:33 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:33 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 13 20:15:33 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:33 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:33 fabiocasa go-librespot[1239]: Librespot-go daemon starting... Mar 13 20:15:33 fabiocasa go-librespot[1239]: time="2025-03-13T20:15:33+01:00" level=info msg="generated new device id: 3a46a300718390ca84ef393108d2bdf33975fb6e" Mar 13 20:15:33 fabiocasa go-librespot[1239]: time="2025-03-13T20:15:33+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:33 fabiocasa go-librespot[1239]: time="2025-03-13T20:15:33+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:33 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:33 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:34 fabiocasa volumio[1125]: info: Loading plugin "outputs"... Mar 13 20:15:34 fabiocasa volumio[1125]: info: Loading plugin "albumart"... Mar 13 20:15:34 fabiocasa volumio[1125]: info: Plugin example_plugin is not enabled Mar 13 20:15:34 fabiocasa volumio[1125]: info: Loading plugin "inputs"... Mar 13 20:15:34 fabiocasa volumio[1125]: info: Loading plugin "updater_comm"... Mar 13 20:15:34 fabiocasa volumio[1125]: info: Plugin mpdemulation is not enabled Mar 13 20:15:34 fabiocasa volumio[1125]: info: Loading plugin "rest_api"... Mar 13 20:15:34 fabiocasa volumio[1125]: info: Loading plugin "websocket"... Mar 13 20:15:34 fabiocasa volumio[1125]: info: Starting Socket.io Server version 2.3.0 Mar 13 20:15:34 fabiocasa volumio[1125]: info: Loading plugin "radio_paradise"... Mar 13 20:15:34 fabiocasa volumio[1125]: Forking 3 albumart workers Mar 13 20:15:34 fabiocasa volumio[1125]: info: Applying required configuration parameters for plugin radio_paradise Mar 13 20:15:34 fabiocasa volumio[1125]: info: [1741893334841] [RadioParadise] API delay: 5 Mar 13 20:15:34 fabiocasa volumio[1125]: info: Loading i18n strings for locale it Mar 13 20:15:34 fabiocasa volumio[1125]: Updating browse sources language Mar 13 20:15:34 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:34 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 13 20:15:34 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 13 20:15:34 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 13 20:15:34 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 13 20:15:34 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 13 20:15:34 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::initPlayerControls Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:15:35 fabiocasa volumio[1125]: Express server listening on port 3000 Mar 13 20:15:35 fabiocasa volumio[1125]: [Metrics] WebUI: 8s 616.37ms Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreStateMachine::resetVolumioState Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreStateMachine::getcurrentVolume Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:15:35 fabiocasa volumio[1125]: info: Volumio Network Manager: Network status updated: 0 Mar 13 20:15:35 fabiocasa volumio-remote-updater[576]: [2025-03-13 20:15:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1741893331 101 Mar 13 20:15:35 fabiocasa volumio[1125]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:35 fabiocasa volumio[1125]: info: Reloading queue from file Mar 13 20:15:35 fabiocasa volumio[1125]: info: Setting Device type: Raspberry PI Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreStateMachine::setRepeat null single undefined Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreStateMachine::pushState Mar 13 20:15:35 fabiocasa volumio[1125]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreStateMachine::setRandom true Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreStateMachine::pushState Mar 13 20:15:35 fabiocasa volumio[1125]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:35 fabiocasa volumio[1125]: info: Completed loading Core Plugins Mar 13 20:15:35 fabiocasa volumio[1125]: info: Preparing to generate the ALSA configuration file Mar 13 20:15:35 fabiocasa volumio[1125]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreStateMachine::pushState Mar 13 20:15:35 fabiocasa volumio[1125]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreStateMachine::updateTrackBlock Mar 13 20:15:35 fabiocasa volumio[1125]: info: CorePlayQueue::getTrackBlock Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:15:35 fabiocasa volumio[1125]: info: Asound.conf file unchanged, so no further update is needed Mar 13 20:15:35 fabiocasa volumio[1125]: info: Output device has changed, restarting MPD Mar 13 20:15:35 fabiocasa volumio[1125]: Starting albumart workers Mar 13 20:15:35 fabiocasa volumio[1125]: Starting albumart workers Mar 13 20:15:35 fabiocasa volumio[1125]: Starting albumart workers Mar 13 20:15:35 fabiocasa sudo[1285]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 13 20:15:35 fabiocasa sudo[1285]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:35 fabiocasa sudo[1285]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:35 fabiocasa volumio[1125]: info: Output device has changed, restarting Shairport Sync Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:35 fabiocasa sudo[1288]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 13 20:15:35 fabiocasa sudo[1288]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:35 fabiocasa systemd[1]: Stopping Music Player Daemon... Mar 13 20:15:35 fabiocasa systemd[1]: mpd.service: Succeeded. Mar 13 20:15:35 fabiocasa systemd[1]: Stopped Music Player Daemon. Mar 13 20:15:35 fabiocasa volumio[1125]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:15:35 fabiocasa volumio[1125]: info: ___________ START PLUGINS ___________ Mar 13 20:15:35 fabiocasa volumio[1125]: info: ControllerMpd::onStart: Initializing MPD Mar 13 20:15:35 fabiocasa volumio[1125]: info: Creating MPD Configuration file Mar 13 20:15:35 fabiocasa systemd[1]: Starting Music Player Daemon... Mar 13 20:15:35 fabiocasa sudo[1297]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 13 20:15:35 fabiocasa sudo[1297]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:35 fabiocasa volumio[1125]: info: [1741893335945] CoreMusicLibrary::Adding element Server multimediali Mar 13 20:15:35 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:35 fabiocasa sudo[1297]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:36 fabiocasa sudo[1302]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 13 20:15:36 fabiocasa sudo[1302]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:36 fabiocasa sudo[1294]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 13 20:15:36 fabiocasa sudo[1294]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:36 fabiocasa sudo[1294]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:36 fabiocasa systemd[1]: mpd.service: Succeeded. Mar 13 20:15:36 fabiocasa systemd[1]: Stopped Music Player Daemon. Mar 13 20:15:36 fabiocasa volumio[1125]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:36 fabiocasa systemd[1]: Starting Music Player Daemon... Mar 13 20:15:36 fabiocasa volumio[1125]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:36 fabiocasa volumio[1125]: info: [1741893336183] CoreMusicLibrary::Adding element Last_100 Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:36 fabiocasa volumio[1125]: info: [1741893336187] CoreMusicLibrary::Adding element Webradio Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:15:36 fabiocasa volumio[1125]: info: Initializing BBC Radios Mar 13 20:15:36 fabiocasa sudo[1308]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 13 20:15:36 fabiocasa sudo[1308]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:36 fabiocasa sudo[1308]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:36 fabiocasa volumio[1125]: info: Creating Spotify config file Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:36 fabiocasa volumio[1125]: info: [squeezelite_mc] Starting proxy server... Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:36 fabiocasa volumio[1125]: info: [1741893336534] CoreMusicLibrary::Adding element YouTube Music Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:36 fabiocasa volumio[1125]: Cannot find translation for source YouTube Music Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:36 fabiocasa volumio[1125]: info: [1741893336546] CoreMusicLibrary::Adding element Radio Paradise Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:36 fabiocasa volumio[1125]: Cannot find translation for source YouTube Music Mar 13 20:15:36 fabiocasa volumio[1125]: Cannot find translation for source Radio Paradise Mar 13 20:15:36 fabiocasa volumio[1125]: info: Volumio Calling Home Mar 13 20:15:36 fabiocasa volumio[1125]: info: [squeezelite_mc] Proxy server started on port 36365 Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:15:36 fabiocasa volumio[1125]: Unhandled rejection Error: No sockets available, cannot start. Mar 13 20:15:36 fabiocasa volumio[1125]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Mar 13 20:15:36 fabiocasa volumio[1125]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Mar 13 20:15:36 fabiocasa volumio[1125]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Mar 13 20:15:36 fabiocasa volumio[1125]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Mar 13 20:15:36 fabiocasa volumio[1125]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Mar 13 20:15:36 fabiocasa volumio[1125]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Mar 13 20:15:36 fabiocasa volumio[1125]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Mar 13 20:15:36 fabiocasa volumio[1125]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Mar 13 20:15:36 fabiocasa volumio[1125]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Mar 13 20:15:36 fabiocasa volumio[1125]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Mar 13 20:15:36 fabiocasa volumio[1125]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Mar 13 20:15:36 fabiocasa volumio[1125]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Mar 13 20:15:36 fabiocasa volumio[1125]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Mar 13 20:15:36 fabiocasa volumio[1125]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Mar 13 20:15:36 fabiocasa volumio[1125]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Mar 13 20:15:36 fabiocasa volumio[1125]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 13 20:15:36 fabiocasa volumio[1125]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Mar 13 20:15:36 fabiocasa volumio[1125]: info: MPD Permissions set Mar 13 20:15:36 fabiocasa volumio[1125]: info: MPD Permissions set Mar 13 20:15:36 fabiocasa volumio[1125]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreStateMachine::pushState Mar 13 20:15:36 fabiocasa volumio[1125]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:36 fabiocasa volumio[1125]: info: [squeezelite_mc] Server discovery started Mar 13 20:15:36 fabiocasa volumio[1125]: info: [squeezelite_mc] Player finder started Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:36 fabiocasa volumio[1125]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:15:36 fabiocasa volumio[1125]: info: [squeezelite_mc] Executing aplay -D hw:2 --nonblock -f MPEG /dev/zero 2>&1 || true Mar 13 20:15:36 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:36 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 13 20:15:36 fabiocasa volumio[1125]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 13 20:15:36 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:36 fabiocasa volumio[1125]: Error: send ENETUNREACH 255.255.255.255:3483 Mar 13 20:15:36 fabiocasa volumio[1125]: at doSend (dgram.js:692:16) Mar 13 20:15:36 fabiocasa volumio[1125]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Mar 13 20:15:36 fabiocasa volumio[1125]: at afterDns (dgram.js:638:5) Mar 13 20:15:36 fabiocasa volumio[1125]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Mar 13 20:15:36 fabiocasa volumio[1125]: errno: -101, Mar 13 20:15:36 fabiocasa volumio[1125]: code: 'ENETUNREACH', Mar 13 20:15:36 fabiocasa volumio[1125]: syscall: 'send', Mar 13 20:15:36 fabiocasa volumio[1125]: address: '255.255.255.255', Mar 13 20:15:36 fabiocasa volumio[1125]: port: 3483 Mar 13 20:15:36 fabiocasa volumio[1125]: } Mar 13 20:15:36 fabiocasa volumio[1125]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 13 20:15:37 fabiocasa kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 13 20:15:37 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:37 fabiocasa go-librespot[1358]: Librespot-go daemon starting... Mar 13 20:15:37 fabiocasa go-librespot[1358]: time="2025-03-13T20:15:37+01:00" level=info msg="generated new device id: 9e89085b7509368f343397eeaade7b507e948a2a" Mar 13 20:15:37 fabiocasa go-librespot[1358]: time="2025-03-13T20:15:37+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:37 fabiocasa go-librespot[1358]: time="2025-03-13T20:15:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:37 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:37 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:37 fabiocasa sudo[1375]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-13 20:14 Mar 13 20:15:37 fabiocasa sudo[1375]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:37 fabiocasa sudo[1375]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:37 fabiocasa volumio-remote-updater[576]: [2025-03-13 20:15:37] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 13 20:15:37 fabiocasa volumio-remote-updater[576]: [2025-03-13 20:15:37] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 13 20:15:37 fabiocasa systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:37 fabiocasa sudo[1302]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:37 fabiocasa sudo[1288]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:37 fabiocasa systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 13 20:15:37 fabiocasa mpd[1320]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 13 20:15:37 fabiocasa mpd[1320]: output: No 'audio_output' defined in config file Mar 13 20:15:37 fabiocasa mpd[1320]: output: Successfully detected a sndio audio device Mar 13 20:15:37 fabiocasa mpd[1320]: zeroconf: No global port, disabling zeroconf Mar 13 20:15:37 fabiocasa systemd[1]: Started dynamicswap service. Mar 13 20:15:37 fabiocasa systemd[1]: Started Music Player Daemon. Mar 13 20:15:38 fabiocasa systemd[1]: dynamicswap.service: Succeeded. Mar 13 20:15:38 fabiocasa systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Mar 13 20:15:38 fabiocasa systemd[1]: volumio.service: Scheduled restart job, restart counter is at 35. Mar 13 20:15:38 fabiocasa systemd[1]: Stopped Volumio Backend Module. Mar 13 20:15:38 fabiocasa systemd[1]: Started Volumio Backend Module. Mar 13 20:15:38 fabiocasa systemd[1]: Started dynamicswap service. Mar 13 20:15:38 fabiocasa systemd[1]: dynamicswap.service: Succeeded. Mar 13 20:15:38 fabiocasa ntpd[779]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Mar 13 20:15:39 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 13 20:15:39 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 13 20:15:39 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 13 20:15:39 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 13 20:15:39 fabiocasa volumio[1390]: info: ------------------------------------------- Mar 13 20:15:39 fabiocasa volumio[1390]: info: ----- Volumio3 ---- Mar 13 20:15:39 fabiocasa volumio[1390]: info: ------------------------------------------- Mar 13 20:15:39 fabiocasa volumio[1390]: info: ----- System startup ---- Mar 13 20:15:39 fabiocasa volumio[1390]: info: ------------------------------------------- Mar 13 20:15:40 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:40 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 13 20:15:40 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:40 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:40 fabiocasa go-librespot[1414]: Librespot-go daemon starting... Mar 13 20:15:40 fabiocasa go-librespot[1414]: time="2025-03-13T20:15:40+01:00" level=info msg="generated new device id: 4b63ca9a3f4d8cbfcb0ddd52643d24a889516c2b" Mar 13 20:15:40 fabiocasa go-librespot[1414]: time="2025-03-13T20:15:40+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:40 fabiocasa go-librespot[1414]: time="2025-03-13T20:15:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:40 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:40 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:40 fabiocasa volumio[1390]: info: MYVOLUMIO Environment detected Mar 13 20:15:40 fabiocasa volumio[1390]: info: Plugin folders cleanup Mar 13 20:15:40 fabiocasa volumio[1390]: info: Scanning into folder /volumio/app/plugins/ Mar 13 20:15:40 fabiocasa volumio[1390]: info: Scanning category audio_interface Mar 13 20:15:40 fabiocasa volumio[1390]: info: Scanning category miscellanea Mar 13 20:15:40 fabiocasa volumio[1390]: info: Scanning category music_service Mar 13 20:15:40 fabiocasa volumio[1390]: info: Scanning category plugins.json Mar 13 20:15:40 fabiocasa volumio[1390]: info: Scanning category system_controller Mar 13 20:15:40 fabiocasa volumio[1390]: info: Scanning category user_interface Mar 13 20:15:40 fabiocasa volumio[1390]: info: Scanning into folder /data/plugins/ Mar 13 20:15:40 fabiocasa volumio[1390]: info: Scanning category music_service Mar 13 20:15:40 fabiocasa volumio[1390]: info: Plugin folders cleanup completed Mar 13 20:15:40 fabiocasa volumio[1390]: info: ------------------------------------------- Mar 13 20:15:40 fabiocasa volumio[1390]: info: ----- Core plugins startup ---- Mar 13 20:15:40 fabiocasa volumio[1390]: info: ------------------------------------------- Mar 13 20:15:40 fabiocasa volumio[1390]: info: Loading plugins from folder /volumio/app/plugins/ Mar 13 20:15:40 fabiocasa volumio[1390]: info: Adding plugin upnp to MyMusic Plugins Mar 13 20:15:40 fabiocasa volumio[1390]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 13 20:15:40 fabiocasa volumio[1390]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 13 20:15:40 fabiocasa volumio[1390]: info: Loading plugins from folder /data/plugins/ Mar 13 20:15:40 fabiocasa volumio[1390]: info: Loading plugin "system"... Mar 13 20:15:40 fabiocasa volumio[1390]: info: Loading plugin "appearance"... Mar 13 20:15:41 fabiocasa wpa_supplicant[877]: wlan0: Failed to initiate sched scan Mar 13 20:15:41 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 13 20:15:41 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 13 20:15:41 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 13 20:15:41 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 13 20:15:41 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 13 20:15:41 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 13 20:15:41 fabiocasa volumio[1390]: info: Loading plugin "network"... Mar 13 20:15:41 fabiocasa volumio[1390]: info: Refreshing Cached IP Addresses Mar 13 20:15:41 fabiocasa sudo[1427]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 13 20:15:41 fabiocasa sudo[1427]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:41 fabiocasa sudo[1427]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:41 fabiocasa sudo[1429]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 13 20:15:41 fabiocasa sudo[1429]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:41 fabiocasa sudo[1429]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:41 fabiocasa volumio[1390]: info: Loading plugin "services"... Mar 13 20:15:41 fabiocasa volumio[1390]: info: Loading plugin "alsa_controller"... Mar 13 20:15:41 fabiocasa sudo[1438]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 13 20:15:41 fabiocasa sudo[1438]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:41 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:15:41 fabiocasa volumio[1390]: info: Loading plugin "wizard"... Mar 13 20:15:41 fabiocasa volumio[1390]: info: Loading plugin "networkfs"... Mar 13 20:15:41 fabiocasa volumio[1390]: info: Starting Udev Watcher for removable devices Mar 13 20:15:41 fabiocasa volumio[1390]: info: Ignoring mount for partition: boot Mar 13 20:15:41 fabiocasa volumio[1390]: info: Ignoring mount for partition: volumio Mar 13 20:15:41 fabiocasa volumio[1390]: info: Ignoring mount for partition: volumio_data Mar 13 20:15:41 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:15:41 fabiocasa volumio[1390]: info: Loading plugin "volumio_command_line_client"... Mar 13 20:15:41 fabiocasa volumio[1390]: info: Loading plugin "upnp"... Mar 13 20:15:41 fabiocasa volumio[1390]: info: [1741893341890] Starting Upmpd Daemon Mar 13 20:15:41 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:15:41 fabiocasa volumio[1390]: info: Loading plugin "my_music"... Mar 13 20:15:41 fabiocasa volumio[1390]: info: Loading plugin "mpd"... Mar 13 20:15:42 fabiocasa volumio[1390]: info: Loading plugin "upnp_browser"... Mar 13 20:15:42 fabiocasa volumio[1390]: info: Loading plugin "alarm-clock"... Mar 13 20:15:42 fabiocasa volumio[1390]: info: Loading plugin "airplay_emulation"... Mar 13 20:15:42 fabiocasa volumio[1390]: info: Starting Shairport Sync Mar 13 20:15:42 fabiocasa volumio[1390]: info: Loading plugin "last_100"... Mar 13 20:15:42 fabiocasa volumio[1390]: info: Loading plugin "webradio"... Mar 13 20:15:42 fabiocasa volumio[1390]: info: Loading plugin "i2s_dacs"... Mar 13 20:15:42 fabiocasa volumio[1390]: info: Loading plugin "volumiodiscovery"... Mar 13 20:15:42 fabiocasa volumio[1390]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:42 fabiocasa volumio[1390]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:42 fabiocasa volumio[1390]: *** WARNING *** For more information see Mar 13 20:15:42 fabiocasa node[1390]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:42 fabiocasa volumio[1390]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:42 fabiocasa volumio[1390]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:42 fabiocasa volumio[1390]: *** WARNING *** For more information see Mar 13 20:15:42 fabiocasa node[1390]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:42 fabiocasa node[1390]: *** WARNING *** For more information see Mar 13 20:15:42 fabiocasa node[1390]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:42 fabiocasa node[1390]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:42 fabiocasa node[1390]: *** WARNING *** For more information see Mar 13 20:15:42 fabiocasa volumio[1390]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 13 20:15:42 fabiocasa volumio[1390]: info: Discovery: Started advertising with name: FabioCasa Mar 13 20:15:42 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:15:42 fabiocasa volumio[1390]: info: Loading plugin "spop"... Mar 13 20:15:42 fabiocasa volumio-remote-updater[576]: [2025-03-13 20:15:42] [connect] Successful connection Mar 13 20:15:43 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:43 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 13 20:15:43 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:43 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:43 fabiocasa go-librespot[1456]: Librespot-go daemon starting... Mar 13 20:15:43 fabiocasa go-librespot[1456]: time="2025-03-13T20:15:43+01:00" level=info msg="generated new device id: d3b093c088483f6369e53081ec412ca0c9be82ee" Mar 13 20:15:43 fabiocasa go-librespot[1456]: time="2025-03-13T20:15:43+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:43 fabiocasa go-librespot[1456]: time="2025-03-13T20:15:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:43 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:43 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:43 fabiocasa volumio[1390]: info: Loading plugin "squeezelite_mc"... Mar 13 20:15:44 fabiocasa sudo[1438]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:44 fabiocasa volumio[1390]: info: Loading plugin "ytmusic"... Mar 13 20:15:44 fabiocasa ntpd[779]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Mar 13 20:15:45 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 13 20:15:45 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 13 20:15:46 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 13 20:15:46 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 13 20:15:46 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:46 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 13 20:15:46 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:46 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:46 fabiocasa go-librespot[1463]: Librespot-go daemon starting... Mar 13 20:15:46 fabiocasa go-librespot[1463]: time="2025-03-13T20:15:46+01:00" level=info msg="generated new device id: 6a95b4ff64c5ae1019ada49cc2d6a2ff54402458" Mar 13 20:15:46 fabiocasa go-librespot[1463]: time="2025-03-13T20:15:46+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:46 fabiocasa go-librespot[1463]: time="2025-03-13T20:15:46+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:46 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:46 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:47 fabiocasa volumio[1390]: info: Loading plugin "outputs"... Mar 13 20:15:47 fabiocasa volumio[1390]: info: Loading plugin "albumart"... Mar 13 20:15:47 fabiocasa volumio[1390]: info: Plugin example_plugin is not enabled Mar 13 20:15:47 fabiocasa volumio[1390]: info: Loading plugin "inputs"... Mar 13 20:15:47 fabiocasa volumio[1390]: info: Loading plugin "updater_comm"... Mar 13 20:15:47 fabiocasa volumio[1390]: info: Plugin mpdemulation is not enabled Mar 13 20:15:47 fabiocasa volumio[1390]: info: Loading plugin "rest_api"... Mar 13 20:15:47 fabiocasa volumio[1390]: info: Loading plugin "websocket"... Mar 13 20:15:47 fabiocasa volumio[1390]: info: Starting Socket.io Server version 2.3.0 Mar 13 20:15:47 fabiocasa volumio[1390]: info: Loading plugin "radio_paradise"... Mar 13 20:15:47 fabiocasa volumio[1390]: Forking 3 albumart workers Mar 13 20:15:47 fabiocasa volumio[1390]: info: Applying required configuration parameters for plugin radio_paradise Mar 13 20:15:47 fabiocasa volumio[1390]: info: [1741893347741] [RadioParadise] API delay: 5 Mar 13 20:15:47 fabiocasa volumio[1390]: info: Loading i18n strings for locale it Mar 13 20:15:47 fabiocasa volumio[1390]: Updating browse sources language Mar 13 20:15:47 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:47 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:15:47 fabiocasa volumio[1390]: info: CoreCommandRouter::initPlayerControls Mar 13 20:15:47 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:47 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:47 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:47 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:47 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:47 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:47 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:47 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:47 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:15:47 fabiocasa volumio[1390]: Express server listening on port 3000 Mar 13 20:15:47 fabiocasa volumio[1390]: [Metrics] WebUI: 8s 533.18ms Mar 13 20:15:48 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 13 20:15:48 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 13 20:15:48 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 13 20:15:48 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 13 20:15:48 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 13 20:15:48 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreStateMachine::resetVolumioState Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreStateMachine::getcurrentVolume Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:15:48 fabiocasa volumio[1390]: info: Volumio Network Manager: Network status updated: 0 Mar 13 20:15:48 fabiocasa volumio[1390]: info: Reloading queue from file Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreStateMachine::setRepeat null single undefined Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreStateMachine::pushState Mar 13 20:15:48 fabiocasa volumio[1390]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreStateMachine::setRandom true Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreStateMachine::pushState Mar 13 20:15:48 fabiocasa volumio[1390]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:48 fabiocasa volumio[1390]: info: Setting Device type: Raspberry PI Mar 13 20:15:48 fabiocasa volumio[1390]: info: Completed loading Core Plugins Mar 13 20:15:48 fabiocasa volumio[1390]: info: Preparing to generate the ALSA configuration file Mar 13 20:15:48 fabiocasa volumio[1390]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreStateMachine::pushState Mar 13 20:15:48 fabiocasa volumio[1390]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreStateMachine::updateTrackBlock Mar 13 20:15:48 fabiocasa volumio[1390]: info: CorePlayQueue::getTrackBlock Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:15:48 fabiocasa volumio[1390]: info: Asound.conf file unchanged, so no further update is needed Mar 13 20:15:48 fabiocasa volumio[1390]: info: Output device has changed, restarting MPD Mar 13 20:15:48 fabiocasa sudo[1509]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 13 20:15:48 fabiocasa sudo[1509]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:48 fabiocasa sudo[1509]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:48 fabiocasa volumio[1390]: info: Output device has changed, restarting Shairport Sync Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:48 fabiocasa volumio[1390]: Starting albumart workers Mar 13 20:15:48 fabiocasa sudo[1512]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 13 20:15:48 fabiocasa sudo[1512]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:48 fabiocasa systemd[1]: Stopping Music Player Daemon... Mar 13 20:15:48 fabiocasa volumio[1390]: Starting albumart workers Mar 13 20:15:48 fabiocasa systemd[1]: mpd.service: Succeeded. Mar 13 20:15:48 fabiocasa systemd[1]: Stopped Music Player Daemon. Mar 13 20:15:48 fabiocasa volumio[1390]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:15:48 fabiocasa volumio[1390]: info: ___________ START PLUGINS ___________ Mar 13 20:15:48 fabiocasa volumio[1390]: Starting albumart workers Mar 13 20:15:48 fabiocasa volumio[1390]: info: ControllerMpd::onStart: Initializing MPD Mar 13 20:15:48 fabiocasa volumio[1390]: info: Creating MPD Configuration file Mar 13 20:15:48 fabiocasa systemd[1]: Starting Music Player Daemon... Mar 13 20:15:48 fabiocasa sudo[1519]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 13 20:15:48 fabiocasa sudo[1519]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:48 fabiocasa sudo[1521]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:48 fabiocasa volumio[1390]: info: [1741893348836] CoreMusicLibrary::Adding element Server multimediali Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:48 fabiocasa sudo[1519]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:48 fabiocasa sudo[1521]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:48 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:48 fabiocasa sudo[1517]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 13 20:15:48 fabiocasa sudo[1517]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:48 fabiocasa sudo[1517]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:48 fabiocasa systemd[1]: mpd.service: Succeeded. Mar 13 20:15:48 fabiocasa systemd[1]: Stopped Music Player Daemon. Mar 13 20:15:48 fabiocasa systemd[1]: Starting Music Player Daemon... Mar 13 20:15:49 fabiocasa volumio[1390]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:15:49 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:49 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:49 fabiocasa sudo[1528]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 13 20:15:49 fabiocasa sudo[1528]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:49 fabiocasa sudo[1528]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:49 fabiocasa volumio[1390]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:15:49 fabiocasa volumio[1390]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:49 fabiocasa volumio[1390]: info: [1741893349192] CoreMusicLibrary::Adding element Last_100 Mar 13 20:15:49 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:49 fabiocasa volumio[1390]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:49 fabiocasa volumio[1390]: info: [1741893349204] CoreMusicLibrary::Adding element Webradio Mar 13 20:15:49 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:49 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:15:49 fabiocasa volumio[1390]: info: Initializing BBC Radios Mar 13 20:15:49 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:15:49 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:49 fabiocasa volumio[1390]: info: Creating Spotify config file Mar 13 20:15:49 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:49 fabiocasa volumio[1390]: info: [squeezelite_mc] Starting proxy server... Mar 13 20:15:49 fabiocasa volumio[1390]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:49 fabiocasa volumio[1390]: info: [1741893349673] CoreMusicLibrary::Adding element YouTube Music Mar 13 20:15:49 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:49 fabiocasa volumio[1390]: Cannot find translation for source YouTube Music Mar 13 20:15:49 fabiocasa volumio[1390]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:15:49 fabiocasa volumio[1390]: info: [1741893349682] CoreMusicLibrary::Adding element Radio Paradise Mar 13 20:15:49 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:15:49 fabiocasa volumio[1390]: Cannot find translation for source YouTube Music Mar 13 20:15:49 fabiocasa volumio[1390]: Cannot find translation for source Radio Paradise Mar 13 20:15:49 fabiocasa volumio[1390]: info: Volumio Calling Home Mar 13 20:15:49 fabiocasa volumio[1390]: info: [squeezelite_mc] Proxy server started on port 33249 Mar 13 20:15:49 fabiocasa volumio[1390]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:15:49 fabiocasa volumio[1390]: Unhandled rejection Error: No sockets available, cannot start. Mar 13 20:15:49 fabiocasa volumio[1390]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Mar 13 20:15:49 fabiocasa volumio[1390]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Mar 13 20:15:49 fabiocasa volumio[1390]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Mar 13 20:15:49 fabiocasa volumio[1390]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Mar 13 20:15:49 fabiocasa volumio[1390]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Mar 13 20:15:49 fabiocasa volumio[1390]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Mar 13 20:15:49 fabiocasa volumio[1390]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Mar 13 20:15:49 fabiocasa volumio[1390]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Mar 13 20:15:49 fabiocasa volumio[1390]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Mar 13 20:15:49 fabiocasa volumio[1390]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Mar 13 20:15:49 fabiocasa volumio[1390]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Mar 13 20:15:49 fabiocasa volumio[1390]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Mar 13 20:15:49 fabiocasa volumio[1390]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Mar 13 20:15:49 fabiocasa volumio[1390]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Mar 13 20:15:49 fabiocasa volumio[1390]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Mar 13 20:15:49 fabiocasa volumio[1390]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 13 20:15:49 fabiocasa volumio[1390]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Mar 13 20:15:49 fabiocasa volumio[1390]: info: MPD Permissions set Mar 13 20:15:49 fabiocasa volumio[1390]: info: MPD Permissions set Mar 13 20:15:49 fabiocasa volumio[1390]: info: Spotify config file written Mar 13 20:15:49 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:49 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 13 20:15:49 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:49 fabiocasa sudo[1578]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 13 20:15:49 fabiocasa sudo[1578]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:50 fabiocasa volumio[1390]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 13 20:15:50 fabiocasa volumio[1390]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreStateMachine::pushState Mar 13 20:15:50 fabiocasa volumio[1390]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:50 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:50 fabiocasa go-librespot[1579]: Librespot-go daemon starting... Mar 13 20:15:50 fabiocasa systemd[1]: Stopping go-librespot Daemon... Mar 13 20:15:50 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Mar 13 20:15:50 fabiocasa systemd[1]: go-librespot-daemon.service: Succeeded. Mar 13 20:15:50 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:50 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:50 fabiocasa sudo[1578]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:50 fabiocasa go-librespot[1591]: Librespot-go daemon starting... Mar 13 20:15:50 fabiocasa go-librespot[1591]: time="2025-03-13T20:15:50+01:00" level=info msg="generated new device id: ed73e88b872cc8d205ce47701262c9f82cb785cb" Mar 13 20:15:50 fabiocasa go-librespot[1591]: time="2025-03-13T20:15:50+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:50 fabiocasa go-librespot[1591]: time="2025-03-13T20:15:50+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:50 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:50 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:50 fabiocasa volumio[1390]: info: No need to fix Spotify hosts Mar 13 20:15:50 fabiocasa volumio[1390]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreStateMachine::pushState Mar 13 20:15:50 fabiocasa volumio[1390]: info: CorePlayQueue::getTrack 0 Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreCommandRouter::volumioPushState Mar 13 20:15:50 fabiocasa volumio[1390]: info: [squeezelite_mc] Server discovery started Mar 13 20:15:50 fabiocasa volumio[1390]: info: [squeezelite_mc] Player finder started Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:15:50 fabiocasa volumio[1390]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:15:50 fabiocasa volumio[1390]: info: [squeezelite_mc] Executing aplay -D hw:2 --nonblock -f MPEG /dev/zero 2>&1 || true Mar 13 20:15:50 fabiocasa volumio[1390]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 13 20:15:50 fabiocasa volumio[1390]: Error: send ENETUNREACH 255.255.255.255:3483 Mar 13 20:15:50 fabiocasa volumio[1390]: at doSend (dgram.js:692:16) Mar 13 20:15:50 fabiocasa volumio[1390]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Mar 13 20:15:50 fabiocasa volumio[1390]: at afterDns (dgram.js:638:5) Mar 13 20:15:50 fabiocasa volumio[1390]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Mar 13 20:15:50 fabiocasa volumio[1390]: errno: -101, Mar 13 20:15:50 fabiocasa volumio[1390]: code: 'ENETUNREACH', Mar 13 20:15:50 fabiocasa volumio[1390]: syscall: 'send', Mar 13 20:15:50 fabiocasa volumio[1390]: address: '255.255.255.255', Mar 13 20:15:50 fabiocasa volumio[1390]: port: 3483 Mar 13 20:15:50 fabiocasa volumio[1390]: } Mar 13 20:15:50 fabiocasa volumio[1390]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 13 20:15:50 fabiocasa kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 13 20:15:50 fabiocasa mpd[1535]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 13 20:15:50 fabiocasa mpd[1535]: output: No 'audio_output' defined in config file Mar 13 20:15:50 fabiocasa mpd[1535]: output: Successfully detected a sndio audio device Mar 13 20:15:50 fabiocasa mpd[1535]: zeroconf: No global port, disabling zeroconf Mar 13 20:15:50 fabiocasa systemd[1]: Started Music Player Daemon. Mar 13 20:15:50 fabiocasa sudo[1512]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:50 fabiocasa sudo[1521]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:50 fabiocasa sudo[1628]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-13 20:14 Mar 13 20:15:50 fabiocasa sudo[1628]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:51 fabiocasa sudo[1628]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:51 fabiocasa systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:51 fabiocasa systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 13 20:15:51 fabiocasa systemd[1]: Started dynamicswap service. Mar 13 20:15:51 fabiocasa systemd[1]: dynamicswap.service: Succeeded. Mar 13 20:15:51 fabiocasa systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Mar 13 20:15:51 fabiocasa systemd[1]: volumio.service: Scheduled restart job, restart counter is at 36. Mar 13 20:15:51 fabiocasa systemd[1]: Stopped Volumio Backend Module. Mar 13 20:15:51 fabiocasa systemd[1]: Started Volumio Backend Module. Mar 13 20:15:51 fabiocasa systemd[1]: Started dynamicswap service. Mar 13 20:15:51 fabiocasa systemd[1]: dynamicswap.service: Succeeded. Mar 13 20:15:52 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 13 20:15:52 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 13 20:15:52 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 13 20:15:52 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 13 20:15:53 fabiocasa volumio[1641]: info: ------------------------------------------- Mar 13 20:15:53 fabiocasa volumio[1641]: info: ----- Volumio3 ---- Mar 13 20:15:53 fabiocasa volumio[1641]: info: ------------------------------------------- Mar 13 20:15:53 fabiocasa volumio[1641]: info: ----- System startup ---- Mar 13 20:15:53 fabiocasa volumio[1641]: info: ------------------------------------------- Mar 13 20:15:53 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:53 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 13 20:15:53 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:53 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:53 fabiocasa go-librespot[1662]: Librespot-go daemon starting... Mar 13 20:15:53 fabiocasa go-librespot[1662]: time="2025-03-13T20:15:53+01:00" level=info msg="generated new device id: e150e08508277be5b4b1356d5e8c0366f42a074b" Mar 13 20:15:53 fabiocasa go-librespot[1662]: time="2025-03-13T20:15:53+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:53 fabiocasa go-librespot[1662]: time="2025-03-13T20:15:53+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:53 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:53 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:53 fabiocasa volumio[1641]: info: MYVOLUMIO Environment detected Mar 13 20:15:53 fabiocasa volumio[1641]: info: Plugin folders cleanup Mar 13 20:15:53 fabiocasa volumio[1641]: info: Scanning into folder /volumio/app/plugins/ Mar 13 20:15:53 fabiocasa volumio[1641]: info: Scanning category audio_interface Mar 13 20:15:53 fabiocasa volumio[1641]: info: Scanning category miscellanea Mar 13 20:15:53 fabiocasa volumio[1641]: info: Scanning category music_service Mar 13 20:15:53 fabiocasa volumio[1641]: info: Scanning category plugins.json Mar 13 20:15:53 fabiocasa volumio[1641]: info: Scanning category system_controller Mar 13 20:15:53 fabiocasa volumio[1641]: info: Scanning category user_interface Mar 13 20:15:53 fabiocasa volumio[1641]: info: Scanning into folder /data/plugins/ Mar 13 20:15:53 fabiocasa volumio[1641]: info: Scanning category music_service Mar 13 20:15:53 fabiocasa volumio[1641]: info: Plugin folders cleanup completed Mar 13 20:15:53 fabiocasa volumio[1641]: info: ------------------------------------------- Mar 13 20:15:53 fabiocasa volumio[1641]: info: ----- Core plugins startup ---- Mar 13 20:15:53 fabiocasa volumio[1641]: info: ------------------------------------------- Mar 13 20:15:53 fabiocasa volumio[1641]: info: Loading plugins from folder /volumio/app/plugins/ Mar 13 20:15:53 fabiocasa volumio[1641]: info: Adding plugin upnp to MyMusic Plugins Mar 13 20:15:53 fabiocasa volumio[1641]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 13 20:15:53 fabiocasa volumio[1641]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 13 20:15:53 fabiocasa volumio[1641]: info: Loading plugins from folder /data/plugins/ Mar 13 20:15:53 fabiocasa volumio[1641]: info: Loading plugin "system"... Mar 13 20:15:53 fabiocasa volumio[1641]: info: Loading plugin "appearance"... Mar 13 20:15:54 fabiocasa wpa_supplicant[877]: wlan0: Failed to initiate sched scan Mar 13 20:15:54 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 13 20:15:54 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 13 20:15:54 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 13 20:15:54 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 13 20:15:54 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 13 20:15:54 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 13 20:15:54 fabiocasa volumio[1641]: info: Loading plugin "network"... Mar 13 20:15:54 fabiocasa volumio[1641]: info: Refreshing Cached IP Addresses Mar 13 20:15:54 fabiocasa sudo[1675]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 13 20:15:54 fabiocasa sudo[1675]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:54 fabiocasa sudo[1675]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:54 fabiocasa sudo[1677]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 13 20:15:54 fabiocasa sudo[1677]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:54 fabiocasa sudo[1677]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:54 fabiocasa volumio[1641]: info: Loading plugin "services"... Mar 13 20:15:54 fabiocasa volumio[1641]: info: Loading plugin "alsa_controller"... Mar 13 20:15:54 fabiocasa sudo[1686]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 13 20:15:54 fabiocasa sudo[1686]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:15:55 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:15:55 fabiocasa volumio[1641]: info: Loading plugin "wizard"... Mar 13 20:15:55 fabiocasa volumio[1641]: info: Loading plugin "networkfs"... Mar 13 20:15:55 fabiocasa volumio[1641]: info: Starting Udev Watcher for removable devices Mar 13 20:15:55 fabiocasa volumio[1641]: info: Ignoring mount for partition: boot Mar 13 20:15:55 fabiocasa volumio[1641]: info: Ignoring mount for partition: volumio Mar 13 20:15:55 fabiocasa volumio[1641]: info: Ignoring mount for partition: volumio_data Mar 13 20:15:55 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:15:55 fabiocasa volumio[1641]: info: Loading plugin "volumio_command_line_client"... Mar 13 20:15:55 fabiocasa volumio[1641]: info: Loading plugin "upnp"... Mar 13 20:15:55 fabiocasa volumio[1641]: info: [1741893355111] Starting Upmpd Daemon Mar 13 20:15:55 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:15:55 fabiocasa volumio[1641]: info: Loading plugin "my_music"... Mar 13 20:15:55 fabiocasa volumio[1641]: info: Loading plugin "mpd"... Mar 13 20:15:55 fabiocasa volumio-remote-updater[576]: [2025-03-13 20:15:55] [connect] Successful connection Mar 13 20:15:55 fabiocasa volumio[1641]: info: Loading plugin "upnp_browser"... Mar 13 20:15:55 fabiocasa volumio[1641]: info: Loading plugin "alarm-clock"... Mar 13 20:15:55 fabiocasa volumio[1641]: info: Loading plugin "airplay_emulation"... Mar 13 20:15:55 fabiocasa volumio[1641]: info: Starting Shairport Sync Mar 13 20:15:55 fabiocasa volumio[1641]: info: Loading plugin "last_100"... Mar 13 20:15:55 fabiocasa volumio[1641]: info: Loading plugin "webradio"... Mar 13 20:15:55 fabiocasa ntpd[779]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Mar 13 20:15:55 fabiocasa volumio[1641]: info: Loading plugin "i2s_dacs"... Mar 13 20:15:55 fabiocasa volumio[1641]: info: Loading plugin "volumiodiscovery"... Mar 13 20:15:56 fabiocasa volumio[1641]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:56 fabiocasa volumio[1641]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:56 fabiocasa volumio[1641]: *** WARNING *** For more information see Mar 13 20:15:56 fabiocasa node[1641]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:56 fabiocasa volumio[1641]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:56 fabiocasa volumio[1641]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:56 fabiocasa volumio[1641]: *** WARNING *** For more information see Mar 13 20:15:56 fabiocasa node[1641]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:56 fabiocasa node[1641]: *** WARNING *** For more information see Mar 13 20:15:56 fabiocasa node[1641]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 13 20:15:56 fabiocasa node[1641]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:15:56 fabiocasa node[1641]: *** WARNING *** For more information see Mar 13 20:15:56 fabiocasa volumio[1641]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 13 20:15:56 fabiocasa volumio[1641]: info: Discovery: Started advertising with name: FabioCasa Mar 13 20:15:56 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:15:56 fabiocasa volumio[1641]: info: Loading plugin "spop"... Mar 13 20:15:56 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:56 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 13 20:15:56 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:56 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:56 fabiocasa go-librespot[1704]: Librespot-go daemon starting... Mar 13 20:15:56 fabiocasa go-librespot[1704]: time="2025-03-13T20:15:56+01:00" level=info msg="generated new device id: 38bae8f7276bf6d9278077f8c724d1181597ae12" Mar 13 20:15:56 fabiocasa go-librespot[1704]: time="2025-03-13T20:15:56+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:56 fabiocasa go-librespot[1704]: time="2025-03-13T20:15:56+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:56 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:56 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:15:57 fabiocasa volumio[1641]: info: Loading plugin "squeezelite_mc"... Mar 13 20:15:57 fabiocasa sudo[1686]: pam_unix(sudo:session): session closed for user root Mar 13 20:15:57 fabiocasa volumio[1641]: info: Loading plugin "ytmusic"... Mar 13 20:15:58 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 13 20:15:59 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 13 20:15:59 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 13 20:15:59 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 13 20:15:59 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:15:59 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 13 20:15:59 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:15:59 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:15:59 fabiocasa go-librespot[1711]: Librespot-go daemon starting... Mar 13 20:15:59 fabiocasa go-librespot[1711]: time="2025-03-13T20:15:59+01:00" level=info msg="generated new device id: 29e50372946202d9351d67476b195ffe87e721cc" Mar 13 20:15:59 fabiocasa go-librespot[1711]: time="2025-03-13T20:15:59+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:15:59 fabiocasa go-librespot[1711]: time="2025-03-13T20:15:59+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:15:59 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:15:59 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:16:00 fabiocasa volumio[1641]: info: Loading plugin "outputs"... Mar 13 20:16:00 fabiocasa volumio[1641]: info: Loading plugin "albumart"... Mar 13 20:16:00 fabiocasa volumio[1641]: info: Plugin example_plugin is not enabled Mar 13 20:16:00 fabiocasa volumio[1641]: info: Loading plugin "inputs"... Mar 13 20:16:00 fabiocasa volumio[1641]: info: Loading plugin "updater_comm"... Mar 13 20:16:00 fabiocasa volumio[1641]: info: Plugin mpdemulation is not enabled Mar 13 20:16:00 fabiocasa volumio[1641]: info: Loading plugin "rest_api"... Mar 13 20:16:00 fabiocasa volumio[1641]: info: Loading plugin "websocket"... Mar 13 20:16:00 fabiocasa volumio[1641]: info: Starting Socket.io Server version 2.3.0 Mar 13 20:16:00 fabiocasa volumio[1641]: info: Loading plugin "radio_paradise"... Mar 13 20:16:00 fabiocasa volumio[1641]: Forking 3 albumart workers Mar 13 20:16:00 fabiocasa volumio[1641]: info: Applying required configuration parameters for plugin radio_paradise Mar 13 20:16:00 fabiocasa volumio[1641]: info: [1741893360936] [RadioParadise] API delay: 5 Mar 13 20:16:00 fabiocasa volumio[1641]: info: Loading i18n strings for locale it Mar 13 20:16:00 fabiocasa volumio[1641]: Updating browse sources language Mar 13 20:16:00 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::initPlayerControls Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:16:01 fabiocasa volumio[1641]: Express server listening on port 3000 Mar 13 20:16:01 fabiocasa volumio[1641]: [Metrics] WebUI: 8s 516.01ms Mar 13 20:16:01 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 13 20:16:01 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 13 20:16:01 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 13 20:16:01 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 13 20:16:01 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 13 20:16:01 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreStateMachine::resetVolumioState Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreStateMachine::getcurrentVolume Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:16:01 fabiocasa volumio[1641]: info: Volumio Network Manager: Network status updated: 0 Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:01 fabiocasa volumio[1641]: info: Reloading queue from file Mar 13 20:16:01 fabiocasa volumio[1641]: info: Setting Device type: Raspberry PI Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreStateMachine::setRepeat null single undefined Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreStateMachine::pushState Mar 13 20:16:01 fabiocasa volumio[1641]: info: CorePlayQueue::getTrack 0 Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::volumioPushState Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreStateMachine::setRandom true Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreStateMachine::pushState Mar 13 20:16:01 fabiocasa volumio[1641]: info: CorePlayQueue::getTrack 0 Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::volumioPushState Mar 13 20:16:01 fabiocasa volumio[1641]: info: Completed loading Core Plugins Mar 13 20:16:01 fabiocasa volumio[1641]: info: Preparing to generate the ALSA configuration file Mar 13 20:16:01 fabiocasa volumio[1641]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreStateMachine::pushState Mar 13 20:16:01 fabiocasa volumio[1641]: info: CorePlayQueue::getTrack 0 Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::volumioPushState Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreStateMachine::updateTrackBlock Mar 13 20:16:01 fabiocasa volumio[1641]: info: CorePlayQueue::getTrackBlock Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:16:01 fabiocasa volumio[1641]: info: Asound.conf file unchanged, so no further update is needed Mar 13 20:16:01 fabiocasa volumio[1641]: info: Output device has changed, restarting MPD Mar 13 20:16:01 fabiocasa volumio[1641]: Starting albumart workers Mar 13 20:16:01 fabiocasa volumio[1641]: Starting albumart workers Mar 13 20:16:01 fabiocasa volumio[1641]: Starting albumart workers Mar 13 20:16:01 fabiocasa sudo[1761]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 13 20:16:01 fabiocasa sudo[1761]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:01 fabiocasa volumio[1641]: info: Output device has changed, restarting Shairport Sync Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:01 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:01 fabiocasa sudo[1761]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:01 fabiocasa sudo[1764]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 13 20:16:01 fabiocasa sudo[1764]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:01 fabiocasa systemd[1]: Stopping Music Player Daemon... Mar 13 20:16:01 fabiocasa volumio[1641]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:16:01 fabiocasa volumio[1641]: info: ___________ START PLUGINS ___________ Mar 13 20:16:01 fabiocasa systemd[1]: mpd.service: Succeeded. Mar 13 20:16:01 fabiocasa systemd[1]: Stopped Music Player Daemon. Mar 13 20:16:01 fabiocasa volumio[1641]: info: ControllerMpd::onStart: Initializing MPD Mar 13 20:16:01 fabiocasa volumio[1641]: info: Creating MPD Configuration file Mar 13 20:16:02 fabiocasa systemd[1]: Starting Music Player Daemon... Mar 13 20:16:02 fabiocasa sudo[1771]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 13 20:16:02 fabiocasa sudo[1771]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:16:02 fabiocasa volumio[1641]: info: [1741893362062] CoreMusicLibrary::Adding element Server multimediali Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:02 fabiocasa sudo[1771]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:02 fabiocasa sudo[1773]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 13 20:16:02 fabiocasa sudo[1773]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:02 fabiocasa systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Mar 13 20:16:02 fabiocasa systemd[1]: mpd.service: Succeeded. Mar 13 20:16:02 fabiocasa systemd[1]: Stopped Music Player Daemon. Mar 13 20:16:02 fabiocasa volumio[1641]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:02 fabiocasa systemd[1]: Starting Music Player Daemon... Mar 13 20:16:02 fabiocasa volumio[1641]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:16:02 fabiocasa volumio[1641]: info: [1741893362320] CoreMusicLibrary::Adding element Last_100 Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:16:02 fabiocasa volumio[1641]: info: [1741893362325] CoreMusicLibrary::Adding element Webradio Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:16:02 fabiocasa sudo[1777]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 13 20:16:02 fabiocasa sudo[1777]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:02 fabiocasa sudo[1777]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:02 fabiocasa volumio[1641]: info: Initializing BBC Radios Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:02 fabiocasa volumio[1641]: info: Creating Spotify config file Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:02 fabiocasa volumio[1641]: info: [squeezelite_mc] Starting proxy server... Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:16:02 fabiocasa volumio[1641]: info: [1741893362807] CoreMusicLibrary::Adding element YouTube Music Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:02 fabiocasa volumio[1641]: Cannot find translation for source YouTube Music Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:16:02 fabiocasa volumio[1641]: info: [1741893362815] CoreMusicLibrary::Adding element Radio Paradise Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:02 fabiocasa volumio[1641]: Cannot find translation for source YouTube Music Mar 13 20:16:02 fabiocasa volumio[1641]: Cannot find translation for source Radio Paradise Mar 13 20:16:02 fabiocasa volumio[1641]: info: Volumio Calling Home Mar 13 20:16:02 fabiocasa volumio[1641]: info: [squeezelite_mc] Proxy server started on port 38511 Mar 13 20:16:02 fabiocasa volumio[1641]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:16:02 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:16:02 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 13 20:16:02 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:16:02 fabiocasa volumio[1641]: Unhandled rejection Error: No sockets available, cannot start. Mar 13 20:16:02 fabiocasa volumio[1641]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Mar 13 20:16:02 fabiocasa volumio[1641]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Mar 13 20:16:02 fabiocasa volumio[1641]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Mar 13 20:16:02 fabiocasa volumio[1641]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Mar 13 20:16:02 fabiocasa volumio[1641]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Mar 13 20:16:02 fabiocasa volumio[1641]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Mar 13 20:16:02 fabiocasa volumio[1641]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Mar 13 20:16:02 fabiocasa volumio[1641]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Mar 13 20:16:02 fabiocasa volumio[1641]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Mar 13 20:16:02 fabiocasa volumio[1641]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Mar 13 20:16:02 fabiocasa volumio[1641]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Mar 13 20:16:02 fabiocasa volumio[1641]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Mar 13 20:16:02 fabiocasa volumio[1641]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Mar 13 20:16:02 fabiocasa volumio[1641]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Mar 13 20:16:02 fabiocasa volumio[1641]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Mar 13 20:16:02 fabiocasa volumio[1641]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 13 20:16:03 fabiocasa volumio[1641]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Mar 13 20:16:03 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:16:03 fabiocasa go-librespot[1825]: Librespot-go daemon starting... Mar 13 20:16:03 fabiocasa volumio[1641]: info: MPD Permissions set Mar 13 20:16:03 fabiocasa volumio[1641]: info: MPD Permissions set Mar 13 20:16:03 fabiocasa go-librespot[1825]: time="2025-03-13T20:16:03+01:00" level=info msg="generated new device id: 4cb1f91a8d804216784388a00294d3a132ffbe83" Mar 13 20:16:03 fabiocasa go-librespot[1825]: time="2025-03-13T20:16:03+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:16:03 fabiocasa go-librespot[1825]: time="2025-03-13T20:16:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:16:03 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:16:03 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:16:03 fabiocasa volumio[1641]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:16:03 fabiocasa volumio[1641]: info: CoreStateMachine::pushState Mar 13 20:16:03 fabiocasa volumio[1641]: info: CorePlayQueue::getTrack 0 Mar 13 20:16:03 fabiocasa volumio[1641]: info: CoreCommandRouter::volumioPushState Mar 13 20:16:03 fabiocasa volumio[1641]: info: [squeezelite_mc] Server discovery started Mar 13 20:16:03 fabiocasa volumio[1641]: info: [squeezelite_mc] Player finder started Mar 13 20:16:03 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:03 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:03 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:03 fabiocasa volumio[1641]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:16:03 fabiocasa volumio[1641]: info: [squeezelite_mc] Executing aplay -D hw:2 --nonblock -f MPEG /dev/zero 2>&1 || true Mar 13 20:16:03 fabiocasa volumio[1641]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 13 20:16:03 fabiocasa volumio[1641]: Error: send ENETUNREACH 255.255.255.255:3483 Mar 13 20:16:03 fabiocasa volumio[1641]: at doSend (dgram.js:692:16) Mar 13 20:16:03 fabiocasa volumio[1641]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Mar 13 20:16:03 fabiocasa volumio[1641]: at afterDns (dgram.js:638:5) Mar 13 20:16:03 fabiocasa volumio[1641]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Mar 13 20:16:03 fabiocasa volumio[1641]: errno: -101, Mar 13 20:16:03 fabiocasa volumio[1641]: code: 'ENETUNREACH', Mar 13 20:16:03 fabiocasa volumio[1641]: syscall: 'send', Mar 13 20:16:03 fabiocasa volumio[1641]: address: '255.255.255.255', Mar 13 20:16:03 fabiocasa volumio[1641]: port: 3483 Mar 13 20:16:03 fabiocasa volumio[1641]: } Mar 13 20:16:03 fabiocasa volumio[1641]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 13 20:16:03 fabiocasa kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 13 20:16:03 fabiocasa sudo[1846]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-13 20:15 Mar 13 20:16:03 fabiocasa sudo[1846]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:03 fabiocasa sudo[1846]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:03 fabiocasa mpd[1786]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 13 20:16:03 fabiocasa mpd[1786]: output: No 'audio_output' defined in config file Mar 13 20:16:03 fabiocasa mpd[1786]: output: Successfully detected a sndio audio device Mar 13 20:16:03 fabiocasa mpd[1786]: zeroconf: No global port, disabling zeroconf Mar 13 20:16:03 fabiocasa systemd[1]: Started Music Player Daemon. Mar 13 20:16:03 fabiocasa sudo[1764]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:03 fabiocasa sudo[1773]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:04 fabiocasa systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:16:04 fabiocasa systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 13 20:16:04 fabiocasa systemd[1]: Started dynamicswap service. Mar 13 20:16:04 fabiocasa systemd[1]: dynamicswap.service: Succeeded. Mar 13 20:16:04 fabiocasa systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Mar 13 20:16:04 fabiocasa systemd[1]: volumio.service: Scheduled restart job, restart counter is at 37. Mar 13 20:16:04 fabiocasa systemd[1]: Stopped Volumio Backend Module. Mar 13 20:16:04 fabiocasa systemd[1]: Started Volumio Backend Module. Mar 13 20:16:04 fabiocasa systemd[1]: Started dynamicswap service. Mar 13 20:16:04 fabiocasa systemd[1]: dynamicswap.service: Succeeded. Mar 13 20:16:05 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 13 20:16:05 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 13 20:16:05 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 13 20:16:05 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 13 20:16:05 fabiocasa volumio[1861]: info: ------------------------------------------- Mar 13 20:16:05 fabiocasa volumio[1861]: info: ----- Volumio3 ---- Mar 13 20:16:05 fabiocasa volumio[1861]: info: ------------------------------------------- Mar 13 20:16:05 fabiocasa volumio[1861]: info: ----- System startup ---- Mar 13 20:16:05 fabiocasa volumio[1861]: info: ------------------------------------------- Mar 13 20:16:06 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:16:06 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 13 20:16:06 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:16:06 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:16:06 fabiocasa go-librespot[1882]: Librespot-go daemon starting... Mar 13 20:16:06 fabiocasa go-librespot[1882]: time="2025-03-13T20:16:06+01:00" level=info msg="generated new device id: 66ab3ef6cac70a9f380db0db6f49556dcdef5801" Mar 13 20:16:06 fabiocasa go-librespot[1882]: time="2025-03-13T20:16:06+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:16:06 fabiocasa go-librespot[1882]: time="2025-03-13T20:16:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:16:06 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:16:06 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:16:06 fabiocasa volumio[1861]: info: MYVOLUMIO Environment detected Mar 13 20:16:06 fabiocasa volumio[1861]: info: Plugin folders cleanup Mar 13 20:16:06 fabiocasa volumio[1861]: info: Scanning into folder /volumio/app/plugins/ Mar 13 20:16:06 fabiocasa volumio[1861]: info: Scanning category audio_interface Mar 13 20:16:06 fabiocasa volumio[1861]: info: Scanning category miscellanea Mar 13 20:16:06 fabiocasa volumio[1861]: info: Scanning category music_service Mar 13 20:16:06 fabiocasa volumio[1861]: info: Scanning category plugins.json Mar 13 20:16:06 fabiocasa volumio[1861]: info: Scanning category system_controller Mar 13 20:16:06 fabiocasa volumio[1861]: info: Scanning category user_interface Mar 13 20:16:06 fabiocasa volumio[1861]: info: Scanning into folder /data/plugins/ Mar 13 20:16:06 fabiocasa volumio[1861]: info: Scanning category music_service Mar 13 20:16:06 fabiocasa volumio[1861]: info: Plugin folders cleanup completed Mar 13 20:16:06 fabiocasa volumio[1861]: info: ------------------------------------------- Mar 13 20:16:06 fabiocasa volumio[1861]: info: ----- Core plugins startup ---- Mar 13 20:16:06 fabiocasa volumio[1861]: info: ------------------------------------------- Mar 13 20:16:06 fabiocasa volumio[1861]: info: Loading plugins from folder /volumio/app/plugins/ Mar 13 20:16:06 fabiocasa volumio[1861]: info: Adding plugin upnp to MyMusic Plugins Mar 13 20:16:06 fabiocasa volumio[1861]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 13 20:16:06 fabiocasa volumio[1861]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 13 20:16:06 fabiocasa volumio[1861]: info: Loading plugins from folder /data/plugins/ Mar 13 20:16:06 fabiocasa volumio[1861]: info: Loading plugin "system"... Mar 13 20:16:06 fabiocasa volumio[1861]: info: Loading plugin "appearance"... Mar 13 20:16:07 fabiocasa wpa_supplicant[877]: wlan0: Failed to initiate sched scan Mar 13 20:16:07 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 13 20:16:07 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 13 20:16:07 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 13 20:16:07 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 13 20:16:07 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 13 20:16:07 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 13 20:16:07 fabiocasa volumio[1861]: info: Loading plugin "network"... Mar 13 20:16:07 fabiocasa volumio[1861]: info: Refreshing Cached IP Addresses Mar 13 20:16:07 fabiocasa sudo[1895]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 13 20:16:07 fabiocasa sudo[1895]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:07 fabiocasa sudo[1895]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:07 fabiocasa sudo[1897]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 13 20:16:07 fabiocasa sudo[1897]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:07 fabiocasa sudo[1897]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:07 fabiocasa volumio[1861]: info: Loading plugin "services"... Mar 13 20:16:07 fabiocasa volumio[1861]: info: Loading plugin "alsa_controller"... Mar 13 20:16:07 fabiocasa sudo[1906]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 13 20:16:07 fabiocasa sudo[1906]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:07 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:16:07 fabiocasa volumio[1861]: info: Loading plugin "wizard"... Mar 13 20:16:07 fabiocasa volumio[1861]: info: Loading plugin "networkfs"... Mar 13 20:16:07 fabiocasa volumio[1861]: info: Starting Udev Watcher for removable devices Mar 13 20:16:07 fabiocasa volumio[1861]: info: Ignoring mount for partition: boot Mar 13 20:16:07 fabiocasa volumio[1861]: info: Ignoring mount for partition: volumio Mar 13 20:16:07 fabiocasa volumio[1861]: info: Ignoring mount for partition: volumio_data Mar 13 20:16:07 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:16:07 fabiocasa volumio[1861]: info: Loading plugin "volumio_command_line_client"... Mar 13 20:16:07 fabiocasa volumio[1861]: info: Loading plugin "upnp"... Mar 13 20:16:07 fabiocasa volumio[1861]: info: [1741893367885] Starting Upmpd Daemon Mar 13 20:16:07 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:16:07 fabiocasa volumio[1861]: info: Loading plugin "my_music"... Mar 13 20:16:07 fabiocasa volumio[1861]: info: Loading plugin "mpd"... Mar 13 20:16:08 fabiocasa volumio[1861]: info: Loading plugin "upnp_browser"... Mar 13 20:16:08 fabiocasa volumio[1861]: info: Loading plugin "alarm-clock"... Mar 13 20:16:08 fabiocasa volumio[1861]: info: Loading plugin "airplay_emulation"... Mar 13 20:16:08 fabiocasa volumio[1861]: info: Starting Shairport Sync Mar 13 20:16:08 fabiocasa volumio[1861]: info: Loading plugin "last_100"... Mar 13 20:16:08 fabiocasa volumio[1861]: info: Loading plugin "webradio"... Mar 13 20:16:08 fabiocasa volumio[1861]: info: Loading plugin "i2s_dacs"... Mar 13 20:16:08 fabiocasa volumio[1861]: info: Loading plugin "volumiodiscovery"... Mar 13 20:16:08 fabiocasa volumio[1861]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 13 20:16:08 fabiocasa volumio[1861]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:16:08 fabiocasa volumio[1861]: *** WARNING *** For more information see Mar 13 20:16:08 fabiocasa volumio[1861]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 13 20:16:08 fabiocasa volumio[1861]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:16:08 fabiocasa volumio[1861]: *** WARNING *** For more information see Mar 13 20:16:08 fabiocasa node[1861]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 13 20:16:08 fabiocasa node[1861]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:16:08 fabiocasa node[1861]: *** WARNING *** For more information see Mar 13 20:16:08 fabiocasa node[1861]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 13 20:16:08 fabiocasa node[1861]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:16:08 fabiocasa node[1861]: *** WARNING *** For more information see Mar 13 20:16:08 fabiocasa volumio[1861]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 13 20:16:08 fabiocasa volumio[1861]: info: Discovery: Started advertising with name: FabioCasa Mar 13 20:16:08 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:16:08 fabiocasa volumio[1861]: info: Loading plugin "spop"... Mar 13 20:16:09 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:16:09 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 13 20:16:09 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:16:09 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:16:09 fabiocasa go-librespot[1924]: Librespot-go daemon starting... Mar 13 20:16:09 fabiocasa go-librespot[1924]: time="2025-03-13T20:16:09+01:00" level=info msg="generated new device id: 3471c863e5f91ef3891c55e22b2f63a2b184a3f1" Mar 13 20:16:09 fabiocasa go-librespot[1924]: time="2025-03-13T20:16:09+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:16:09 fabiocasa go-librespot[1924]: time="2025-03-13T20:16:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:16:09 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:16:09 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:16:09 fabiocasa volumio[1861]: info: Loading plugin "squeezelite_mc"... Mar 13 20:16:10 fabiocasa sudo[1906]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:10 fabiocasa volumio-remote-updater[576]: [2025-03-13 20:16:10] [connect] Successful connection Mar 13 20:16:10 fabiocasa volumio[1861]: info: Loading plugin "ytmusic"... Mar 13 20:16:11 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 13 20:16:11 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 13 20:16:11 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 13 20:16:12 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 13 20:16:12 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:16:12 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 13 20:16:12 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:16:12 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:16:12 fabiocasa go-librespot[1935]: Librespot-go daemon starting... Mar 13 20:16:12 fabiocasa go-librespot[1935]: time="2025-03-13T20:16:12+01:00" level=info msg="generated new device id: 3bed899f04cc3ecf157cb243ccbe0af2dbf0f4e0" Mar 13 20:16:12 fabiocasa go-librespot[1935]: time="2025-03-13T20:16:12+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:16:12 fabiocasa go-librespot[1935]: time="2025-03-13T20:16:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:16:12 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:16:12 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:16:13 fabiocasa volumio[1861]: info: Loading plugin "outputs"... Mar 13 20:16:13 fabiocasa volumio[1861]: info: Loading plugin "albumart"... Mar 13 20:16:13 fabiocasa volumio[1861]: info: Plugin example_plugin is not enabled Mar 13 20:16:13 fabiocasa volumio[1861]: info: Loading plugin "inputs"... Mar 13 20:16:13 fabiocasa volumio[1861]: info: Loading plugin "updater_comm"... Mar 13 20:16:13 fabiocasa volumio[1861]: info: Plugin mpdemulation is not enabled Mar 13 20:16:13 fabiocasa volumio[1861]: info: Loading plugin "rest_api"... Mar 13 20:16:13 fabiocasa volumio[1861]: info: Loading plugin "websocket"... Mar 13 20:16:13 fabiocasa volumio[1861]: info: Starting Socket.io Server version 2.3.0 Mar 13 20:16:13 fabiocasa volumio[1861]: info: Loading plugin "radio_paradise"... Mar 13 20:16:13 fabiocasa volumio[1861]: Forking 3 albumart workers Mar 13 20:16:13 fabiocasa volumio[1861]: info: Applying required configuration parameters for plugin radio_paradise Mar 13 20:16:13 fabiocasa volumio[1861]: info: [1741893373699] [RadioParadise] API delay: 5 Mar 13 20:16:13 fabiocasa volumio[1861]: info: Loading i18n strings for locale it Mar 13 20:16:13 fabiocasa volumio[1861]: Updating browse sources language Mar 13 20:16:13 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:13 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 13 20:16:13 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 13 20:16:13 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 13 20:16:13 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 13 20:16:13 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 13 20:16:13 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 13 20:16:13 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:16:13 fabiocasa volumio[1861]: info: CoreCommandRouter::initPlayerControls Mar 13 20:16:13 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:13 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:13 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:13 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:13 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:13 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:13 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:13 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:13 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:16:13 fabiocasa volumio[1861]: Express server listening on port 3000 Mar 13 20:16:13 fabiocasa volumio[1861]: [Metrics] WebUI: 8s 494.76ms Mar 13 20:16:13 fabiocasa volumio[1861]: info: CoreStateMachine::resetVolumioState Mar 13 20:16:13 fabiocasa volumio[1861]: info: CoreStateMachine::getcurrentVolume Mar 13 20:16:13 fabiocasa volumio[1861]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:16:14 fabiocasa volumio[1861]: info: Volumio Network Manager: Network status updated: 0 Mar 13 20:16:14 fabiocasa volumio-remote-updater[576]: [2025-03-13 20:16:14] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1741893370 101 Mar 13 20:16:14 fabiocasa volumio[1861]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:14 fabiocasa volumio[1861]: info: Reloading queue from file Mar 13 20:16:14 fabiocasa volumio[1861]: info: Setting Device type: Raspberry PI Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreStateMachine::setRepeat null single undefined Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreStateMachine::pushState Mar 13 20:16:14 fabiocasa volumio[1861]: info: CorePlayQueue::getTrack 0 Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::volumioPushState Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreStateMachine::setRandom true Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreStateMachine::pushState Mar 13 20:16:14 fabiocasa volumio[1861]: info: CorePlayQueue::getTrack 0 Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::volumioPushState Mar 13 20:16:14 fabiocasa volumio[1861]: info: Completed loading Core Plugins Mar 13 20:16:14 fabiocasa volumio[1861]: info: Preparing to generate the ALSA configuration file Mar 13 20:16:14 fabiocasa volumio[1861]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreStateMachine::pushState Mar 13 20:16:14 fabiocasa volumio[1861]: info: CorePlayQueue::getTrack 0 Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::volumioPushState Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreStateMachine::updateTrackBlock Mar 13 20:16:14 fabiocasa volumio[1861]: info: CorePlayQueue::getTrackBlock Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:16:14 fabiocasa volumio[1861]: info: Asound.conf file unchanged, so no further update is needed Mar 13 20:16:14 fabiocasa volumio[1861]: info: Output device has changed, restarting MPD Mar 13 20:16:14 fabiocasa volumio[1861]: Starting albumart workers Mar 13 20:16:14 fabiocasa volumio[1861]: info: Output device has changed, restarting Shairport Sync Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:14 fabiocasa sudo[1997]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 13 20:16:14 fabiocasa sudo[1997]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:14 fabiocasa volumio[1861]: Starting albumart workers Mar 13 20:16:14 fabiocasa sudo[1997]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:14 fabiocasa sudo[1999]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 13 20:16:14 fabiocasa sudo[1999]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:14 fabiocasa volumio[1861]: Starting albumart workers Mar 13 20:16:14 fabiocasa systemd[1]: Stopping Music Player Daemon... Mar 13 20:16:14 fabiocasa systemd[1]: mpd.service: Succeeded. Mar 13 20:16:14 fabiocasa systemd[1]: Stopped Music Player Daemon. Mar 13 20:16:14 fabiocasa volumio[1861]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:16:14 fabiocasa volumio[1861]: info: ___________ START PLUGINS ___________ Mar 13 20:16:14 fabiocasa volumio[1861]: info: ControllerMpd::onStart: Initializing MPD Mar 13 20:16:14 fabiocasa volumio[1861]: info: Creating MPD Configuration file Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:16:14 fabiocasa volumio[1861]: info: [1741893374768] CoreMusicLibrary::Adding element Server multimediali Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:14 fabiocasa sudo[2008]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 13 20:16:14 fabiocasa sudo[2008]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:14 fabiocasa systemd[1]: Starting Music Player Daemon... Mar 13 20:16:14 fabiocasa sudo[2008]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:14 fabiocasa sudo[2010]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:14 fabiocasa sudo[2010]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:14 fabiocasa systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Mar 13 20:16:14 fabiocasa systemd[1]: mpd.service: Succeeded. Mar 13 20:16:14 fabiocasa systemd[1]: Stopped Music Player Daemon. Mar 13 20:16:14 fabiocasa systemd[1]: Starting Music Player Daemon... Mar 13 20:16:14 fabiocasa volumio[1861]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:14 fabiocasa volumio[1861]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:16:14 fabiocasa volumio[1861]: info: [1741893374950] CoreMusicLibrary::Adding element Last_100 Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:16:14 fabiocasa volumio[1861]: info: [1741893374954] CoreMusicLibrary::Adding element Webradio Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:14 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:16:14 fabiocasa volumio[1861]: info: Initializing BBC Radios Mar 13 20:16:15 fabiocasa sudo[2016]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 13 20:16:15 fabiocasa sudo[2016]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:15 fabiocasa sudo[2016]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:15 fabiocasa volumio[1861]: info: Creating Spotify config file Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:15 fabiocasa volumio[1861]: info: [squeezelite_mc] Starting proxy server... Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:16:15 fabiocasa volumio[1861]: info: [1741893375306] CoreMusicLibrary::Adding element YouTube Music Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:15 fabiocasa volumio[1861]: Cannot find translation for source YouTube Music Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:16:15 fabiocasa volumio[1861]: info: [1741893375318] CoreMusicLibrary::Adding element Radio Paradise Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:15 fabiocasa volumio[1861]: Cannot find translation for source YouTube Music Mar 13 20:16:15 fabiocasa volumio[1861]: Cannot find translation for source Radio Paradise Mar 13 20:16:15 fabiocasa volumio[1861]: info: Volumio Calling Home Mar 13 20:16:15 fabiocasa volumio[1861]: info: [squeezelite_mc] Proxy server started on port 34465 Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:16:15 fabiocasa volumio[1861]: Unhandled rejection Error: No sockets available, cannot start. Mar 13 20:16:15 fabiocasa volumio[1861]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Mar 13 20:16:15 fabiocasa volumio[1861]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Mar 13 20:16:15 fabiocasa volumio[1861]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Mar 13 20:16:15 fabiocasa volumio[1861]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Mar 13 20:16:15 fabiocasa volumio[1861]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Mar 13 20:16:15 fabiocasa volumio[1861]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Mar 13 20:16:15 fabiocasa volumio[1861]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Mar 13 20:16:15 fabiocasa volumio[1861]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Mar 13 20:16:15 fabiocasa volumio[1861]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Mar 13 20:16:15 fabiocasa volumio[1861]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Mar 13 20:16:15 fabiocasa volumio[1861]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Mar 13 20:16:15 fabiocasa volumio[1861]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Mar 13 20:16:15 fabiocasa volumio[1861]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Mar 13 20:16:15 fabiocasa volumio[1861]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Mar 13 20:16:15 fabiocasa volumio[1861]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Mar 13 20:16:15 fabiocasa volumio[1861]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 13 20:16:15 fabiocasa volumio[1861]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Mar 13 20:16:15 fabiocasa volumio[1861]: info: MPD Permissions set Mar 13 20:16:15 fabiocasa volumio[1861]: info: MPD Permissions set Mar 13 20:16:15 fabiocasa volumio[1861]: info: Spotify config file written Mar 13 20:16:15 fabiocasa sudo[2063]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 13 20:16:15 fabiocasa sudo[2063]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:15 fabiocasa volumio[1861]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 13 20:16:15 fabiocasa volumio[1861]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:16:15 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:16:15 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreStateMachine::pushState Mar 13 20:16:15 fabiocasa volumio[1861]: info: CorePlayQueue::getTrack 0 Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::volumioPushState Mar 13 20:16:15 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:15 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:16:15 fabiocasa go-librespot[2065]: Librespot-go daemon starting... Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:15 fabiocasa systemd[1]: Stopping go-librespot Daemon... Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:15 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:15 fabiocasa systemd[1]: go-librespot-daemon.service: Succeeded. Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:15 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:15 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:16:15 fabiocasa sudo[2063]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:15 fabiocasa go-librespot[2071]: Librespot-go daemon starting... Mar 13 20:16:15 fabiocasa go-librespot[2071]: time="2025-03-13T20:16:15+01:00" level=info msg="generated new device id: f281cf00f75bdc60b1c6d27bc569bf69be7876fb" Mar 13 20:16:15 fabiocasa go-librespot[2071]: time="2025-03-13T20:16:15+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:16:15 fabiocasa go-librespot[2071]: time="2025-03-13T20:16:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:15 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:16:15 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:16:15 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:15 fabiocasa volumio[1861]: info: No need to fix Spotify hosts Mar 13 20:16:16 fabiocasa volumio[1861]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:16:16 fabiocasa volumio[1861]: info: CoreStateMachine::pushState Mar 13 20:16:16 fabiocasa volumio[1861]: info: CorePlayQueue::getTrack 0 Mar 13 20:16:16 fabiocasa volumio[1861]: info: CoreCommandRouter::volumioPushState Mar 13 20:16:16 fabiocasa volumio[1861]: info: [squeezelite_mc] Server discovery started Mar 13 20:16:16 fabiocasa volumio[1861]: info: [squeezelite_mc] Player finder started Mar 13 20:16:16 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:16 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:16 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:16 fabiocasa volumio[1861]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:16:16 fabiocasa volumio[1861]: info: [squeezelite_mc] Executing aplay -D hw:2 --nonblock -f MPEG /dev/zero 2>&1 || true Mar 13 20:16:16 fabiocasa volumio[1861]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 13 20:16:16 fabiocasa volumio[1861]: Error: send ENETUNREACH 255.255.255.255:3483 Mar 13 20:16:16 fabiocasa volumio[1861]: at doSend (dgram.js:692:16) Mar 13 20:16:16 fabiocasa volumio[1861]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Mar 13 20:16:16 fabiocasa volumio[1861]: at afterDns (dgram.js:638:5) Mar 13 20:16:16 fabiocasa volumio[1861]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Mar 13 20:16:16 fabiocasa volumio[1861]: errno: -101, Mar 13 20:16:16 fabiocasa volumio[1861]: code: 'ENETUNREACH', Mar 13 20:16:16 fabiocasa volumio[1861]: syscall: 'send', Mar 13 20:16:16 fabiocasa volumio[1861]: address: '255.255.255.255', Mar 13 20:16:16 fabiocasa volumio[1861]: port: 3483 Mar 13 20:16:16 fabiocasa volumio[1861]: } Mar 13 20:16:16 fabiocasa volumio[1861]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 13 20:16:16 fabiocasa kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 13 20:16:16 fabiocasa sudo[2093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-13 20:15 Mar 13 20:16:16 fabiocasa sudo[2093]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:16 fabiocasa mpd[2023]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 13 20:16:16 fabiocasa mpd[2023]: output: No 'audio_output' defined in config file Mar 13 20:16:16 fabiocasa mpd[2023]: output: Successfully detected a sndio audio device Mar 13 20:16:16 fabiocasa mpd[2023]: zeroconf: No global port, disabling zeroconf Mar 13 20:16:16 fabiocasa systemd[1]: Started Music Player Daemon. Mar 13 20:16:16 fabiocasa sudo[2010]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:16 fabiocasa sudo[1999]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:16 fabiocasa sudo[2093]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:16 fabiocasa volumio-remote-updater[576]: [2025-03-13 20:16:16] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 13 20:16:16 fabiocasa volumio-remote-updater[576]: [2025-03-13 20:16:16] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 13 20:16:16 fabiocasa systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:16:16 fabiocasa systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 13 20:16:17 fabiocasa systemd[1]: Started dynamicswap service. Mar 13 20:16:17 fabiocasa systemd[1]: dynamicswap.service: Succeeded. Mar 13 20:16:17 fabiocasa systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Mar 13 20:16:17 fabiocasa systemd[1]: volumio.service: Scheduled restart job, restart counter is at 38. Mar 13 20:16:17 fabiocasa systemd[1]: Stopped Volumio Backend Module. Mar 13 20:16:17 fabiocasa systemd[1]: Started Volumio Backend Module. Mar 13 20:16:17 fabiocasa systemd[1]: Started dynamicswap service. Mar 13 20:16:17 fabiocasa systemd[1]: dynamicswap.service: Succeeded. Mar 13 20:16:17 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Mar 13 20:16:17 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Mar 13 20:16:18 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Mar 13 20:16:18 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Mar 13 20:16:18 fabiocasa volumio[2108]: info: ------------------------------------------- Mar 13 20:16:18 fabiocasa volumio[2108]: info: ----- Volumio3 ---- Mar 13 20:16:18 fabiocasa volumio[2108]: info: ------------------------------------------- Mar 13 20:16:18 fabiocasa volumio[2108]: info: ----- System startup ---- Mar 13 20:16:18 fabiocasa volumio[2108]: info: ------------------------------------------- Mar 13 20:16:18 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:16:18 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 13 20:16:18 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:16:19 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:16:19 fabiocasa go-librespot[2129]: Librespot-go daemon starting... Mar 13 20:16:19 fabiocasa go-librespot[2129]: time="2025-03-13T20:16:19+01:00" level=info msg="generated new device id: 7fa16f40571271a92aab47f7082d8df9db634ec0" Mar 13 20:16:19 fabiocasa go-librespot[2129]: time="2025-03-13T20:16:19+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:16:19 fabiocasa go-librespot[2129]: time="2025-03-13T20:16:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:16:19 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:16:19 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:16:19 fabiocasa volumio[2108]: info: MYVOLUMIO Environment detected Mar 13 20:16:19 fabiocasa volumio[2108]: info: Plugin folders cleanup Mar 13 20:16:19 fabiocasa volumio[2108]: info: Scanning into folder /volumio/app/plugins/ Mar 13 20:16:19 fabiocasa volumio[2108]: info: Scanning category audio_interface Mar 13 20:16:19 fabiocasa volumio[2108]: info: Scanning category miscellanea Mar 13 20:16:19 fabiocasa volumio[2108]: info: Scanning category music_service Mar 13 20:16:19 fabiocasa volumio[2108]: info: Scanning category plugins.json Mar 13 20:16:19 fabiocasa volumio[2108]: info: Scanning category system_controller Mar 13 20:16:19 fabiocasa volumio[2108]: info: Scanning category user_interface Mar 13 20:16:19 fabiocasa volumio[2108]: info: Scanning into folder /data/plugins/ Mar 13 20:16:19 fabiocasa volumio[2108]: info: Scanning category music_service Mar 13 20:16:19 fabiocasa volumio[2108]: info: Plugin folders cleanup completed Mar 13 20:16:19 fabiocasa volumio[2108]: info: ------------------------------------------- Mar 13 20:16:19 fabiocasa volumio[2108]: info: ----- Core plugins startup ---- Mar 13 20:16:19 fabiocasa volumio[2108]: info: ------------------------------------------- Mar 13 20:16:19 fabiocasa volumio[2108]: info: Loading plugins from folder /volumio/app/plugins/ Mar 13 20:16:19 fabiocasa volumio[2108]: info: Adding plugin upnp to MyMusic Plugins Mar 13 20:16:19 fabiocasa volumio[2108]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 13 20:16:19 fabiocasa volumio[2108]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 13 20:16:19 fabiocasa volumio[2108]: info: Loading plugins from folder /data/plugins/ Mar 13 20:16:19 fabiocasa volumio[2108]: info: Loading plugin "system"... Mar 13 20:16:19 fabiocasa volumio[2108]: info: Loading plugin "appearance"... Mar 13 20:16:20 fabiocasa wpa_supplicant[877]: wlan0: Trying to associate with SSID 'TISCALI-effe-5G' Mar 13 20:16:20 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Mar 13 20:16:20 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Mar 13 20:16:20 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Mar 13 20:16:20 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Mar 13 20:16:20 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Mar 13 20:16:20 fabiocasa kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Mar 13 20:16:20 fabiocasa dhcpcd[889]: wlan0: carrier acquired Mar 13 20:16:20 fabiocasa wpa_supplicant[877]: wlan0: Associated with 98:0d:67:37:a9:a2 Mar 13 20:16:20 fabiocasa wpa_supplicant[877]: wlan0: CTRL-EVENT-CONNECTED - Connection to 98:0d:67:37:a9:a2 completed [id=0 id_str=] Mar 13 20:16:20 fabiocasa wpa_supplicant[877]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Mar 13 20:16:20 fabiocasa wpa_supplicant[877]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=IT Mar 13 20:16:20 fabiocasa dhcpcd[889]: wlan0: IAID eb:b3:33:4e Mar 13 20:16:20 fabiocasa dhcpcd[889]: wlan0: carrier lost Mar 13 20:16:20 fabiocasa dhcpcd[889]: wlan0: carrier acquired Mar 13 20:16:20 fabiocasa dhcpcd[889]: wlan0: IAID eb:b3:33:4e Mar 13 20:16:20 fabiocasa volumio[2108]: info: Loading plugin "network"... Mar 13 20:16:20 fabiocasa volumio[2108]: info: Refreshing Cached IP Addresses Mar 13 20:16:20 fabiocasa dhcpcd[889]: wlan0: soliciting a DHCP lease Mar 13 20:16:20 fabiocasa sudo[2154]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 13 20:16:20 fabiocasa sudo[2154]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:20 fabiocasa dhcpcd[889]: wlan0: soliciting an IPv6 router Mar 13 20:16:20 fabiocasa sudo[2154]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:20 fabiocasa sudo[2156]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 13 20:16:20 fabiocasa sudo[2156]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:20 fabiocasa sudo[2156]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:20 fabiocasa volumio[2108]: info: Loading plugin "services"... Mar 13 20:16:20 fabiocasa volumio[2108]: info: Loading plugin "alsa_controller"... Mar 13 20:16:20 fabiocasa sudo[2168]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 13 20:16:20 fabiocasa sudo[2168]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:20 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:16:20 fabiocasa volumio[2108]: info: Loading plugin "wizard"... Mar 13 20:16:20 fabiocasa volumio[2108]: info: Loading plugin "networkfs"... Mar 13 20:16:20 fabiocasa volumio[2108]: info: Starting Udev Watcher for removable devices Mar 13 20:16:20 fabiocasa volumio[2108]: info: Ignoring mount for partition: boot Mar 13 20:16:20 fabiocasa volumio[2108]: info: Ignoring mount for partition: volumio Mar 13 20:16:20 fabiocasa volumio[2108]: info: Ignoring mount for partition: volumio_data Mar 13 20:16:20 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:16:20 fabiocasa volumio[2108]: info: Loading plugin "volumio_command_line_client"... Mar 13 20:16:20 fabiocasa volumio[2108]: info: Loading plugin "upnp"... Mar 13 20:16:20 fabiocasa volumio[2108]: info: [1741893380902] Starting Upmpd Daemon Mar 13 20:16:20 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:16:20 fabiocasa volumio[2108]: info: Loading plugin "my_music"... Mar 13 20:16:20 fabiocasa volumio[2108]: info: Loading plugin "mpd"... Mar 13 20:16:21 fabiocasa volumio[2108]: info: Loading plugin "upnp_browser"... Mar 13 20:16:21 fabiocasa volumio[2108]: info: Loading plugin "alarm-clock"... Mar 13 20:16:21 fabiocasa volumio[2108]: info: Loading plugin "airplay_emulation"... Mar 13 20:16:21 fabiocasa volumio[2108]: info: Starting Shairport Sync Mar 13 20:16:21 fabiocasa volumio[2108]: info: Loading plugin "last_100"... Mar 13 20:16:21 fabiocasa volumio[2108]: info: Loading plugin "webradio"... Mar 13 20:16:21 fabiocasa volumio[2108]: info: Loading plugin "i2s_dacs"... Mar 13 20:16:21 fabiocasa volumio[2108]: info: Loading plugin "volumiodiscovery"... Mar 13 20:16:21 fabiocasa volumio[2108]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 13 20:16:21 fabiocasa volumio[2108]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:16:21 fabiocasa volumio[2108]: *** WARNING *** For more information see Mar 13 20:16:21 fabiocasa node[2108]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 13 20:16:21 fabiocasa volumio[2108]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 13 20:16:21 fabiocasa volumio[2108]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:16:21 fabiocasa volumio[2108]: *** WARNING *** For more information see Mar 13 20:16:21 fabiocasa node[2108]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:16:21 fabiocasa node[2108]: *** WARNING *** For more information see Mar 13 20:16:21 fabiocasa node[2108]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 13 20:16:21 fabiocasa node[2108]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 20:16:21 fabiocasa node[2108]: *** WARNING *** For more information see Mar 13 20:16:21 fabiocasa volumio[2108]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 13 20:16:21 fabiocasa volumio[2108]: info: Discovery: Started advertising with name: FabioCasa Mar 13 20:16:21 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 20:16:21 fabiocasa volumio[2108]: info: Loading plugin "spop"... Mar 13 20:16:21 fabiocasa volumio-remote-updater[576]: [2025-03-13 20:16:21] [connect] Successful connection Mar 13 20:16:22 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:16:22 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 13 20:16:22 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:16:22 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:16:22 fabiocasa go-librespot[2186]: Librespot-go daemon starting... Mar 13 20:16:22 fabiocasa go-librespot[2186]: time="2025-03-13T20:16:22+01:00" level=info msg="generated new device id: 0c704927f6a1574ec03ac875f31083f6dd1dbfc4" Mar 13 20:16:22 fabiocasa go-librespot[2186]: time="2025-03-13T20:16:22+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:16:22 fabiocasa go-librespot[2186]: time="2025-03-13T20:16:22+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:16:22 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:16:22 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:16:22 fabiocasa volumio[2108]: info: Loading plugin "squeezelite_mc"... Mar 13 20:16:23 fabiocasa volumio[2108]: info: Loading plugin "ytmusic"... Mar 13 20:16:23 fabiocasa dhcpcd[889]: wlan0: offered 192.168.103.144 from 192.168.103.254 Mar 13 20:16:24 fabiocasa sudo[2168]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:24 fabiocasa dhcpcd[889]: wlan0: probing address 192.168.103.144/24 Mar 13 20:16:25 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:16:25 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 13 20:16:25 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:16:25 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:16:25 fabiocasa go-librespot[2194]: Librespot-go daemon starting... Mar 13 20:16:25 fabiocasa go-librespot[2194]: time="2025-03-13T20:16:25+01:00" level=info msg="generated new device id: 9d9d5b4ef52a9b384346d32a33226b1e183a1b2f" Mar 13 20:16:25 fabiocasa go-librespot[2194]: time="2025-03-13T20:16:25+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:16:25 fabiocasa go-librespot[2194]: time="2025-03-13T20:16:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:16:25 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:16:25 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:16:26 fabiocasa volumio[2108]: info: Loading plugin "outputs"... Mar 13 20:16:26 fabiocasa volumio[2108]: info: Loading plugin "albumart"... Mar 13 20:16:26 fabiocasa volumio[2108]: info: Plugin example_plugin is not enabled Mar 13 20:16:26 fabiocasa volumio[2108]: info: Loading plugin "inputs"... Mar 13 20:16:26 fabiocasa volumio[2108]: info: Loading plugin "updater_comm"... Mar 13 20:16:26 fabiocasa volumio[2108]: info: Plugin mpdemulation is not enabled Mar 13 20:16:26 fabiocasa volumio[2108]: info: Loading plugin "rest_api"... Mar 13 20:16:26 fabiocasa volumio[2108]: info: Loading plugin "websocket"... Mar 13 20:16:26 fabiocasa volumio[2108]: info: Starting Socket.io Server version 2.3.0 Mar 13 20:16:26 fabiocasa volumio[2108]: info: Loading plugin "radio_paradise"... Mar 13 20:16:26 fabiocasa volumio[2108]: Forking 3 albumart workers Mar 13 20:16:26 fabiocasa volumio[2108]: info: Applying required configuration parameters for plugin radio_paradise Mar 13 20:16:26 fabiocasa volumio[2108]: info: [1741893386841] [RadioParadise] API delay: 5 Mar 13 20:16:26 fabiocasa volumio[2108]: info: Loading i18n strings for locale it Mar 13 20:16:26 fabiocasa volumio[2108]: Updating browse sources language Mar 13 20:16:26 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::initPlayerControls Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:16:27 fabiocasa volumio[2108]: Express server listening on port 3000 Mar 13 20:16:27 fabiocasa volumio[2108]: [Metrics] WebUI: 8s 657.57ms Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreStateMachine::resetVolumioState Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreStateMachine::getcurrentVolume Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:16:27 fabiocasa volumio[2108]: info: Volumio Network Manager: Network status updated: 0 Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:27 fabiocasa volumio[2108]: info: Reloading queue from file Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreStateMachine::setRepeat null single undefined Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreStateMachine::pushState Mar 13 20:16:27 fabiocasa volumio[2108]: info: CorePlayQueue::getTrack 0 Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::volumioPushState Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreStateMachine::setRandom true Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreStateMachine::pushState Mar 13 20:16:27 fabiocasa volumio[2108]: info: CorePlayQueue::getTrack 0 Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::volumioPushState Mar 13 20:16:27 fabiocasa volumio[2108]: info: Setting Device type: Raspberry PI Mar 13 20:16:27 fabiocasa volumio[2108]: info: Completed loading Core Plugins Mar 13 20:16:27 fabiocasa volumio[2108]: info: Preparing to generate the ALSA configuration file Mar 13 20:16:27 fabiocasa volumio[2108]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreStateMachine::pushState Mar 13 20:16:27 fabiocasa volumio[2108]: info: CorePlayQueue::getTrack 0 Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::volumioPushState Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreStateMachine::updateTrackBlock Mar 13 20:16:27 fabiocasa volumio[2108]: info: CorePlayQueue::getTrackBlock Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:16:27 fabiocasa volumio[2108]: info: Asound.conf file unchanged, so no further update is needed Mar 13 20:16:27 fabiocasa volumio[2108]: info: Output device has changed, restarting MPD Mar 13 20:16:27 fabiocasa volumio[2108]: Starting albumart workers Mar 13 20:16:27 fabiocasa volumio[2108]: Starting albumart workers Mar 13 20:16:27 fabiocasa volumio[2108]: info: Output device has changed, restarting Shairport Sync Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:27 fabiocasa sudo[2278]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 13 20:16:27 fabiocasa sudo[2278]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:27 fabiocasa volumio[2108]: Starting albumart workers Mar 13 20:16:27 fabiocasa sudo[2278]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:27 fabiocasa sudo[2280]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 13 20:16:27 fabiocasa sudo[2280]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:27 fabiocasa volumio[2108]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:16:27 fabiocasa volumio[2108]: info: ___________ START PLUGINS ___________ Mar 13 20:16:27 fabiocasa volumio[2108]: info: ControllerMpd::onStart: Initializing MPD Mar 13 20:16:27 fabiocasa volumio[2108]: info: Creating MPD Configuration file Mar 13 20:16:27 fabiocasa systemd[1]: Stopping Music Player Daemon... Mar 13 20:16:27 fabiocasa systemd[1]: mpd.service: Succeeded. Mar 13 20:16:27 fabiocasa systemd[1]: Stopped Music Player Daemon. Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:16:27 fabiocasa volumio[2108]: info: [1741893387853] CoreMusicLibrary::Adding element Server multimediali Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:27 fabiocasa sudo[2287]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 13 20:16:27 fabiocasa sudo[2287]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:27 fabiocasa sudo[2287]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:27 fabiocasa systemd[1]: Starting Music Player Daemon... Mar 13 20:16:27 fabiocasa sudo[2290]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 13 20:16:27 fabiocasa sudo[2290]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:27 fabiocasa systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Mar 13 20:16:27 fabiocasa systemd[1]: mpd.service: Succeeded. Mar 13 20:16:27 fabiocasa systemd[1]: Stopped Music Player Daemon. Mar 13 20:16:27 fabiocasa systemd[1]: Starting Music Player Daemon... Mar 13 20:16:27 fabiocasa volumio[2108]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:27 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:28 fabiocasa volumio[2108]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 20:16:28 fabiocasa volumio[2108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:16:28 fabiocasa volumio[2108]: info: [1741893388080] CoreMusicLibrary::Adding element Last_100 Mar 13 20:16:28 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:28 fabiocasa volumio[2108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:16:28 fabiocasa volumio[2108]: info: [1741893388100] CoreMusicLibrary::Adding element Webradio Mar 13 20:16:28 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:28 fabiocasa sudo[2296]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 13 20:16:28 fabiocasa sudo[2296]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:28 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:16:28 fabiocasa sudo[2296]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:28 fabiocasa volumio[2108]: info: Initializing BBC Radios Mar 13 20:16:28 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 20:16:28 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:28 fabiocasa volumio[2108]: info: Creating Spotify config file Mar 13 20:16:28 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:28 fabiocasa volumio[2108]: info: [squeezelite_mc] Starting proxy server... Mar 13 20:16:28 fabiocasa volumio[2108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:16:28 fabiocasa volumio[2108]: info: [1741893388651] CoreMusicLibrary::Adding element YouTube Music Mar 13 20:16:28 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:28 fabiocasa volumio[2108]: Cannot find translation for source YouTube Music Mar 13 20:16:28 fabiocasa volumio[2108]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 20:16:28 fabiocasa volumio[2108]: info: [1741893388661] CoreMusicLibrary::Adding element Radio Paradise Mar 13 20:16:28 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 20:16:28 fabiocasa volumio[2108]: Cannot find translation for source YouTube Music Mar 13 20:16:28 fabiocasa volumio[2108]: Cannot find translation for source Radio Paradise Mar 13 20:16:28 fabiocasa volumio[2108]: info: Volumio Calling Home Mar 13 20:16:28 fabiocasa systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 13 20:16:28 fabiocasa systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 13 20:16:28 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:16:28 fabiocasa volumio[2108]: info: [squeezelite_mc] Proxy server started on port 36075 Mar 13 20:16:28 fabiocasa volumio[2108]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 20:16:28 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:16:28 fabiocasa go-librespot[2339]: Librespot-go daemon starting... Mar 13 20:16:28 fabiocasa volumio[2108]: Unhandled rejection Error: No sockets available, cannot start. Mar 13 20:16:28 fabiocasa volumio[2108]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Mar 13 20:16:28 fabiocasa volumio[2108]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Mar 13 20:16:28 fabiocasa volumio[2108]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Mar 13 20:16:28 fabiocasa volumio[2108]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Mar 13 20:16:28 fabiocasa volumio[2108]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Mar 13 20:16:28 fabiocasa volumio[2108]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Mar 13 20:16:28 fabiocasa volumio[2108]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Mar 13 20:16:28 fabiocasa volumio[2108]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Mar 13 20:16:28 fabiocasa volumio[2108]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Mar 13 20:16:28 fabiocasa volumio[2108]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Mar 13 20:16:28 fabiocasa volumio[2108]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Mar 13 20:16:28 fabiocasa volumio[2108]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Mar 13 20:16:28 fabiocasa volumio[2108]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Mar 13 20:16:28 fabiocasa volumio[2108]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Mar 13 20:16:28 fabiocasa volumio[2108]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Mar 13 20:16:28 fabiocasa volumio[2108]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 13 20:16:28 fabiocasa go-librespot[2339]: time="2025-03-13T20:16:28+01:00" level=info msg="generated new device id: e19e5b3cefefae1c5ddef7520f358bcc6756a614" Mar 13 20:16:28 fabiocasa go-librespot[2339]: time="2025-03-13T20:16:28+01:00" level=fatal msg="unknown credentials: " Mar 13 20:16:28 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:16:28 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:16:28 fabiocasa volumio[2108]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Mar 13 20:16:28 fabiocasa volumio[2108]: info: MPD Permissions set Mar 13 20:16:28 fabiocasa ntpd[779]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Mar 13 20:16:28 fabiocasa volumio[2108]: info: Spotify config file written Mar 13 20:16:28 fabiocasa sudo[2350]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 13 20:16:28 fabiocasa sudo[2350]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:28 fabiocasa volumio[2108]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 13 20:16:28 fabiocasa volumio[2108]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:16:28 fabiocasa volumio[2108]: info: CoreStateMachine::pushState Mar 13 20:16:28 fabiocasa volumio[2108]: info: CorePlayQueue::getTrack 0 Mar 13 20:16:28 fabiocasa volumio[2108]: info: CoreCommandRouter::volumioPushState Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa systemd[1]: Stopped go-librespot Daemon. Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa systemd[1]: Started go-librespot Daemon. Mar 13 20:16:29 fabiocasa volumio[2108]: info: No need to fix Spotify hosts Mar 13 20:16:29 fabiocasa go-librespot[2352]: Librespot-go daemon starting... Mar 13 20:16:29 fabiocasa sudo[2350]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:29 fabiocasa go-librespot[2352]: time="2025-03-13T20:16:29+01:00" level=info msg="generated new device id: 7b6f992bfbb6f0e5f8ef5b574788cbed07147998" Mar 13 20:16:29 fabiocasa go-librespot[2352]: time="2025-03-13T20:16:29+01:00" level=debug msg="stored credentials found for ffranceschini" Mar 13 20:16:29 fabiocasa go-librespot[2352]: time="2025-03-13T20:16:29+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 13 20:16:29 fabiocasa systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 13 20:16:29 fabiocasa systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 13 20:16:29 fabiocasa volumio[2108]: info: VolumeController:: Volume=100 Mute =false Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreStateMachine::pushState Mar 13 20:16:29 fabiocasa volumio[2108]: info: CorePlayQueue::getTrack 0 Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::volumioPushState Mar 13 20:16:29 fabiocasa volumio[2108]: info: [squeezelite_mc] Server discovery started Mar 13 20:16:29 fabiocasa volumio[2108]: info: [squeezelite_mc] Player finder started Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 20:16:29 fabiocasa volumio[2108]: info: [squeezelite_mc] Executing aplay -D hw:2 --nonblock -f MPEG /dev/zero 2>&1 || true Mar 13 20:16:29 fabiocasa volumio[2108]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 13 20:16:29 fabiocasa volumio[2108]: Error: send ENETUNREACH 255.255.255.255:3483 Mar 13 20:16:29 fabiocasa volumio[2108]: at doSend (dgram.js:692:16) Mar 13 20:16:29 fabiocasa volumio[2108]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) Mar 13 20:16:29 fabiocasa volumio[2108]: at afterDns (dgram.js:638:5) Mar 13 20:16:29 fabiocasa volumio[2108]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Mar 13 20:16:29 fabiocasa volumio[2108]: errno: -101, Mar 13 20:16:29 fabiocasa volumio[2108]: code: 'ENETUNREACH', Mar 13 20:16:29 fabiocasa volumio[2108]: syscall: 'send', Mar 13 20:16:29 fabiocasa volumio[2108]: address: '255.255.255.255', Mar 13 20:16:29 fabiocasa volumio[2108]: port: 3483 Mar 13 20:16:29 fabiocasa volumio[2108]: } Mar 13 20:16:29 fabiocasa volumio[2108]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 13 20:16:29 fabiocasa kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Mar 13 20:16:29 fabiocasa sudo[2378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-13 20:15 Mar 13 20:16:29 fabiocasa sudo[2378]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 20:16:29 fabiocasa mpd[2301]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 13 20:16:29 fabiocasa mpd[2301]: output: No 'audio_output' defined in config file Mar 13 20:16:29 fabiocasa mpd[2301]: output: Successfully detected a sndio audio device Mar 13 20:16:29 fabiocasa mpd[2301]: zeroconf: No global port, disabling zeroconf Mar 13 20:16:29 fabiocasa systemd[1]: Started Music Player Daemon. Mar 13 20:16:29 fabiocasa sudo[2290]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:29 fabiocasa sudo[2280]: pam_unix(sudo:session): session closed for user root Mar 13 20:16:29 fabiocasa dhcpcd[889]: wlan0: leased 192.168.103.144 for 86400 seconds Mar 13 20:16:29 fabiocasa avahi-daemon[599]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.103.144. Mar 13 20:16:29 fabiocasa avahi-daemon[599]: New relevant interface wlan0.IPv4 for mDNS. Mar 13 20:16:29 fabiocasa dhcpcd[889]: wlan0: adding route to 192.168.103.0/24 Mar 13 20:16:29 fabiocasa avahi-daemon[599]: Registering new address record for 192.168.103.144 on wlan0.IPv4. Mar 13 20:16:29 fabiocasa dhcpcd[889]: wlan0: adding default route via 192.168.103.254 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"