-- Logs begin at Wed 2025-04-30 04:14:24 EDT, end at Tue 2025-05-13 15:26:32 EDT. -- May 13 15:25:05 volumio volumio[24405]: error: error May 13 15:25:09 volumio ntpd[815]: Soliciting pool server 2600:3c00::f03c:91ff:fedf:5654 May 13 15:25:10 volumio ntpd[815]: Soliciting pool server 172.235.60.8 May 13 15:25:31 volumio dhcpcd[1034]: wlan0: carrier lost May 13 15:25:31 volumio wpa_supplicant[948]: wlan0: CTRL-EVENT-ASSOC-REJECT status_code=1 May 13 15:25:31 volumio wpa_supplicant[948]: nl80211: Failed to open /proc/sys/net/ipv4/conf/wlan0/drop_unicast_in_l2_multicast: No such file or directory May 13 15:25:31 volumio wpa_supplicant[948]: nl80211: Failed to set IPv4 unicast in multicast filter May 13 15:25:31 volumio avahi-daemon[539]: Withdrawing address record for 192.168.1.5 on wlan0. May 13 15:25:31 volumio avahi-daemon[539]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.5. May 13 15:25:31 volumio avahi-daemon[539]: Interface wlan0.IPv4 no longer relevant for mDNS. May 13 15:25:31 volumio volumio[24405]: info: Discovery: A device disappeared from network May 13 15:25:31 volumio dhcpcd[1034]: wlan0: deleting route to 192.168.1.0/24 May 13 15:25:31 volumio dhcpcd[1034]: wlan0: deleting default route via 192.168.1.1 May 13 15:25:32 volumio ntpd[815]: Deleting interface #18 wlan0, 192.168.1.5#123, interface stats: received=0, sent=10, dropped=0, active_time=52 secs May 13 15:25:32 volumio ntpd[815]: 45.79.82.45 local addr 192.168.1.5 -> May 13 15:25:32 volumio ntpd[815]: 68.183.107.237 local addr 192.168.1.5 -> May 13 15:25:32 volumio ntpd[815]: 162.159.200.123 local addr 192.168.1.5 -> May 13 15:25:32 volumio ntpd[815]: 162.159.200.1 local addr 192.168.1.5 -> May 13 15:25:32 volumio ntpd[815]: 142.202.190.19 local addr 192.168.1.5 -> May 13 15:25:32 volumio ntpd[815]: 168.235.69.132 local addr 192.168.1.5 -> May 13 15:25:32 volumio ntpd[815]: 199.101.96.52 local addr 192.168.1.5 -> May 13 15:25:32 volumio ntpd[815]: 168.215.194.18 local addr 192.168.1.5 -> May 13 15:25:33 volumio volumio[24405]: info: Volumio Network Manager: Network status updated: 0 May 13 15:25:40 volumio volumio[24405]: info: Discovery: Browse raised the following error Error: getaddrinfo -3008 May 13 15:25:41 volumio ntpd[815]: error resolving pool 3.debian.pool.ntp.org: System error (-11) May 13 15:25:43 volumio volumio[24405]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 15:25:43 volumio volumio[24405]: Error: send ENETUNREACH 255.255.255.255:3483 May 13 15:25:43 volumio volumio[24405]: at doSend (dgram.js:714:16) May 13 15:25:43 volumio volumio[24405]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:452:18) May 13 15:25:43 volumio volumio[24405]: at afterDns (dgram.js:660:5) May 13 15:25:43 volumio volumio[24405]: at processTicksAndRejections (internal/process/task_queues.js:83:21) { May 13 15:25:43 volumio volumio[24405]: errno: -101, May 13 15:25:43 volumio volumio[24405]: code: 'ENETUNREACH', May 13 15:25:43 volumio volumio[24405]: syscall: 'send', May 13 15:25:43 volumio volumio[24405]: address: '255.255.255.255', May 13 15:25:43 volumio volumio[24405]: port: 3483 May 13 15:25:43 volumio volumio[24405]: } May 13 15:25:43 volumio volumio[24405]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 15:25:43 volumio sudo[12593]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-13 15:24 May 13 15:25:43 volumio sudo[12593]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:43 volumio sudo[12593]: pam_unix(sudo:session): session closed for user root May 13 15:25:43 volumio volumio-remote-updater[534]: [2025-05-13 15:25:43] [error] handle_read_frame error: websocketpp.transport:7 (End of File) May 13 15:25:43 volumio volumio-remote-updater[534]: [2025-05-13 15:25:43] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] May 13 15:25:43 volumio go-librespot[24656]: time="2025-05-13T15:25:43-04:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" May 13 15:25:43 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE May 13 15:25:43 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. May 13 15:25:43 volumio systemd[1]: Started dynamicswap service. May 13 15:25:43 volumio systemd[1]: dynamicswap.service: Succeeded. May 13 15:25:44 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. May 13 15:25:44 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 46. May 13 15:25:44 volumio systemd[1]: Stopped Volumio Backend Module. May 13 15:25:44 volumio systemd[1]: Started Volumio Backend Module. May 13 15:25:44 volumio systemd[1]: Started dynamicswap service. May 13 15:25:44 volumio systemd[1]: dynamicswap.service: Succeeded. May 13 15:25:45 volumio volumio[12615]: info: ------------------------------------------- May 13 15:25:45 volumio volumio[12615]: info: ----- Volumio3 ---- May 13 15:25:45 volumio volumio[12615]: info: ------------------------------------------- May 13 15:25:45 volumio volumio[12615]: info: ----- System startup ---- May 13 15:25:45 volumio volumio[12615]: info: ------------------------------------------- May 13 15:25:45 volumio volumio[12615]: info: MYVOLUMIO Environment detected May 13 15:25:45 volumio volumio[12615]: info: Plugin folders cleanup May 13 15:25:45 volumio volumio[12615]: info: Scanning into folder /volumio/app/plugins/ May 13 15:25:45 volumio volumio[12615]: info: Scanning category audio_interface May 13 15:25:45 volumio volumio[12615]: info: Scanning category miscellanea May 13 15:25:45 volumio volumio[12615]: info: Scanning category music_service May 13 15:25:45 volumio volumio[12615]: info: Scanning category plugins.json May 13 15:25:45 volumio volumio[12615]: info: Scanning category system_controller May 13 15:25:45 volumio volumio[12615]: info: Scanning category user_interface May 13 15:25:45 volumio volumio[12615]: info: Scanning into folder /data/plugins/ May 13 15:25:45 volumio volumio[12615]: info: Scanning category music_service May 13 15:25:45 volumio volumio[12615]: info: Scanning category user_interface May 13 15:25:45 volumio volumio[12615]: info: Plugin folders cleanup completed May 13 15:25:45 volumio volumio[12615]: info: ------------------------------------------- May 13 15:25:45 volumio volumio[12615]: info: ----- Core plugins startup ---- May 13 15:25:45 volumio volumio[12615]: info: ------------------------------------------- May 13 15:25:45 volumio volumio[12615]: info: Loading plugins from folder /volumio/app/plugins/ May 13 15:25:45 volumio volumio[12615]: info: Adding plugin upnp to MyMusic Plugins May 13 15:25:45 volumio volumio[12615]: info: Adding plugin airplay_emulation to MyMusic Plugins May 13 15:25:45 volumio volumio[12615]: info: Adding plugin upnp_browser to MyMusic Plugins May 13 15:25:45 volumio volumio[12615]: info: Loading plugins from folder /data/plugins/ May 13 15:25:45 volumio volumio[12615]: info: Loading plugin "system"... May 13 15:25:45 volumio volumio[12615]: info: Loading plugin "appearance"... May 13 15:25:46 volumio volumio[12615]: info: Loading plugin "network"... May 13 15:25:46 volumio volumio[12615]: info: Refreshing Cached IP Addresses May 13 15:25:46 volumio sudo[12644]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 13 15:25:46 volumio sudo[12644]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:46 volumio volumio[12615]: info: Loading plugin "services"... May 13 15:25:46 volumio sudo[12647]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 13 15:25:46 volumio volumio[12615]: info: Loading plugin "alsa_controller"... May 13 15:25:46 volumio sudo[12658]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 13 15:25:46 volumio sudo[12647]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:46 volumio sudo[12644]: pam_unix(sudo:session): session closed for user root May 13 15:25:46 volumio sudo[12658]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:46 volumio sudo[12647]: pam_unix(sudo:session): session closed for user root May 13 15:25:46 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:25:46 volumio volumio[12615]: info: Loading plugin "wizard"... May 13 15:25:46 volumio volumio[12615]: info: Loading plugin "networkfs"... May 13 15:25:46 volumio volumio[12615]: info: Cannot mount NAS NAS at system boot, trial number 1 ,retrying in 5 seconds May 13 15:25:46 volumio volumio[12615]: info: Starting Udev Watcher for removable devices May 13 15:25:46 volumio volumio[12615]: info: Ignoring mount for partition: BOOT May 13 15:25:46 volumio volumio[12615]: info: Ignoring mount for partition: volumio May 13 15:25:46 volumio volumio[12615]: info: Ignoring mount for partition: volumio_data May 13 15:25:46 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:25:46 volumio volumio[12615]: info: Loading plugin "volumio_command_line_client"... May 13 15:25:46 volumio volumio[12615]: info: Loading plugin "upnp"... May 13 15:25:46 volumio volumio[12615]: info: [1747164346480] Starting Upmpd Daemon May 13 15:25:46 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:25:46 volumio volumio[12615]: info: Loading plugin "my_music"... May 13 15:25:46 volumio volumio[12615]: info: Loading plugin "mpd"... May 13 15:25:46 volumio volumio[12615]: info: Loading plugin "upnp_browser"... May 13 15:25:46 volumio volumio[12615]: info: Loading plugin "alarm-clock"... May 13 15:25:46 volumio volumio[12615]: info: Loading plugin "airplay_emulation"... May 13 15:25:46 volumio volumio[12615]: info: Starting Shairport Sync May 13 15:25:46 volumio volumio[12615]: info: Loading plugin "last_100"... May 13 15:25:46 volumio volumio[12615]: info: Loading plugin "webradio"... May 13 15:25:47 volumio volumio[12615]: info: Loading plugin "i2s_dacs"... May 13 15:25:47 volumio volumio[12615]: info: I2S DAC not set, start Auto-detection May 13 15:25:47 volumio volumio[12615]: info: Loading plugin "volumiodiscovery"... May 13 15:25:47 volumio nmbd[806]: [2025/05/13 15:25:47.041291, 0] ../source3/nmbd/nmbd.c:361(reload_interfaces) May 13 15:25:47 volumio nmbd[806]: reload_interfaces: No subnets to listen to. Waiting.. May 13 15:25:47 volumio volumio[12615]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 13 15:25:47 volumio node[12615]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 13 15:25:47 volumio node[12615]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:25:47 volumio volumio[12615]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:25:47 volumio volumio[12615]: *** WARNING *** For more information see May 13 15:25:47 volumio volumio[12615]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 13 15:25:47 volumio volumio[12615]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:25:47 volumio volumio[12615]: *** WARNING *** For more information see May 13 15:25:47 volumio node[12615]: *** WARNING *** For more information see May 13 15:25:47 volumio node[12615]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 13 15:25:47 volumio node[12615]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:25:47 volumio node[12615]: *** WARNING *** For more information see May 13 15:25:47 volumio volumio[12615]: info: Applying required configuration parameters for plugin volumiodiscovery May 13 15:25:47 volumio volumio[12615]: info: Discovery: Started advertising with name: Volumio May 13 15:25:47 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:25:47 volumio volumio[12615]: info: Loading plugin "spop"... May 13 15:25:47 volumio sudo[12658]: pam_unix(sudo:session): session closed for user root May 13 15:25:47 volumio volumio[12615]: info: Loading plugin "squeezelite_mc"... May 13 15:25:48 volumio volumio[12615]: info: Loading plugin "youtube2"... May 13 15:25:48 volumio volumio[12615]: info: Loading plugin "now_playing"... May 13 15:25:48 volumio volumio-remote-updater[534]: [2025-05-13 15:25:48] [connect] Successful connection May 13 15:25:49 volumio volumio[12615]: info: Loading plugin "outputs"... May 13 15:25:49 volumio volumio[12615]: info: Loading plugin "albumart"... May 13 15:25:49 volumio volumio[12615]: info: Plugin example_plugin is not enabled May 13 15:25:49 volumio volumio[12615]: info: Loading plugin "inputs"... May 13 15:25:49 volumio volumio[12615]: info: Loading plugin "updater_comm"... May 13 15:25:49 volumio volumio[12615]: info: Plugin mpdemulation is not enabled May 13 15:25:49 volumio volumio[12615]: info: Loading plugin "rest_api"... May 13 15:25:49 volumio volumio[12615]: info: Loading plugin "websocket"... May 13 15:25:49 volumio volumio[12615]: info: Starting Socket.io Server version 2.3.0 May 13 15:25:49 volumio volumio[12615]: info: Loading plugin "lms"... May 13 15:25:49 volumio volumio[12615]: info: Loading i18n strings for locale en May 13 15:25:49 volumio volumio[12615]: Updating browse sources language May 13 15:25:49 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:25:49 volumio volumio[12615]: Forking 3 albumart workers May 13 15:25:49 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:25:49 volumio volumio[12615]: info: CoreCommandRouter::initPlayerControls May 13 15:25:49 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:49 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:49 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:49 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:49 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:49 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:49 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:49 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:49 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:25:49 volumio volumio[12615]: Express server listening on port 3000 May 13 15:25:49 volumio volumio[12615]: [Metrics] WebUI: 4s 970.34ms May 13 15:25:49 volumio volumio[12615]: info: CoreStateMachine::resetVolumioState May 13 15:25:49 volumio volumio[12615]: info: CoreStateMachine::getcurrentVolume May 13 15:25:49 volumio volumio[12615]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:25:49 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:25:49 volumio volumio[12615]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' May 13 15:25:49 volumio volumio[12615]: info: Completed loading Core Plugins May 13 15:25:49 volumio volumio[12615]: info: Preparing to generate the ALSA configuration file May 13 15:25:49 volumio volumio[12615]: info: Volumio Network Manager: Network status updated: 0 May 13 15:25:49 volumio volumio[12615]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 1 May 13 15:25:50 volumio volumio[12615]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 2 May 13 15:25:50 volumio volumio-remote-updater[534]: [2025-05-13 15:25:50] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1747164348 101 May 13 15:25:50 volumio volumio[12615]: 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: 3 May 13 15:25:50 volumio volumio[12615]: info: Reloading queue from file May 13 15:25:50 volumio volumio[12615]: info: Asound.conf file unchanged, so no further update is needed May 13 15:25:50 volumio volumio[12615]: info: Output device has changed, restarting MPD May 13 15:25:50 volumio volumio[12615]: info: Output device has changed, restarting Shairport Sync May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:25:50 volumio sudo[12744]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 13 15:25:50 volumio sudo[12746]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 13 15:25:50 volumio volumio[12615]: info: ___________ START PLUGINS ___________ May 13 15:25:50 volumio volumio[12615]: info: ControllerMpd::onStart: Initializing MPD May 13 15:25:50 volumio sudo[12744]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:50 volumio volumio[12615]: info: Creating MPD Configuration file May 13 15:25:50 volumio sudo[12746]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:50 volumio sudo[12744]: pam_unix(sudo:session): session closed for user root May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:25:50 volumio volumio[12615]: info: [1747164350265] CoreMusicLibrary::Adding element Media Servers May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:25:50 volumio sudo[12758]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 13 15:25:50 volumio sudo[12758]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:50 volumio systemd[1]: Stopping Music Player Daemon... May 13 15:25:50 volumio sudo[12763]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:25:50 volumio sudo[12758]: pam_unix(sudo:session): session closed for user root May 13 15:25:50 volumio sudo[12763]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:25:50 volumio systemd[1]: mpd.service: Succeeded. May 13 15:25:50 volumio systemd[1]: Stopped Music Player Daemon. May 13 15:25:50 volumio systemd[1]: Starting Music Player Daemon... May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:25:50 volumio volumio[12615]: info: [1747164350458] CoreMusicLibrary::Adding element Last_100 May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:25:50 volumio volumio[12615]: info: [1747164350461] CoreMusicLibrary::Adding element Webradio May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:25:50 volumio volumio[12615]: Starting albumart workers May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:25:50 volumio volumio[12615]: info: Initializing BBC Radios May 13 15:25:50 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM May 13 15:25:50 volumio systemd[1]: mpd.service: Succeeded. May 13 15:25:50 volumio systemd[1]: Stopped Music Player Daemon. May 13 15:25:50 volumio systemd[1]: Starting Music Player Daemon... May 13 15:25:50 volumio volumio[12615]: Starting albumart workers May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:25:50 volumio volumio[12615]: Starting albumart workers May 13 15:25:50 volumio volumio[12615]: info: Creating Spotify config file May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:50 volumio sudo[12787]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 13 15:25:50 volumio volumio[12615]: info: [squeezelite_mc] Starting proxy server... May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:25:50 volumio volumio[12615]: info: [1747164350636] CoreMusicLibrary::Adding element YouTube2 May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:25:50 volumio volumio[12615]: Cannot find translation for source YouTube2 May 13 15:25:50 volumio volumio[12615]: info: [now-playing-config] Config is up to date. May 13 15:25:50 volumio sudo[12787]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 13 15:25:50 volumio volumio[12615]: info: Discovery: Getting this device information May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::volumioGetState May 13 15:25:50 volumio volumio[12615]: info: CorePlayQueue::getTrack 0 May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 13 15:25:50 volumio sudo[12787]: pam_unix(sudo:session): session closed for user root May 13 15:25:50 volumio volumio[12615]: info: Volumio Calling Home May 13 15:25:50 volumio sudo[12805]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver May 13 15:25:50 volumio sudo[12805]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:50 volumio systemd[1]: Starting Logitech Media Server Daemon... May 13 15:25:50 volumio volumio[12615]: info: [squeezelite_mc] Proxy server started on port 44237 May 13 15:25:50 volumio volumio[12615]: info: [now-playing-app] App is listening on port 4004. May 13 15:25:50 volumio systemd[1]: Started Logitech Media Server Daemon. May 13 15:25:50 volumio sudo[12805]: pam_unix(sudo:session): session closed for user root May 13 15:25:50 volumio systemd[12819]: logitechmediaserver.service: Failed to execute command: No such file or directory May 13 15:25:50 volumio systemd[12819]: logitechmediaserver.service: Failed at step EXEC spawning /usr/sbin/squeezeboxserver: No such file or directory May 13 15:25:50 volumio systemd[1]: logitechmediaserver.service: Main process exited, code=exited, status=203/EXEC May 13 15:25:50 volumio systemd[1]: logitechmediaserver.service: Failed with result 'exit-code'. May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:25:50 volumio volumio[12615]: info: CoreStateMachine::setRepeat false single undefined May 13 15:25:50 volumio volumio[12615]: info: CoreStateMachine::pushState May 13 15:25:50 volumio volumio[12615]: info: CorePlayQueue::getTrack 0 May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::volumioPushState May 13 15:25:50 volumio volumio[12615]: info: CoreStateMachine::setRandom undefined May 13 15:25:50 volumio volumio[12615]: info: CoreStateMachine::pushState May 13 15:25:50 volumio volumio[12615]: info: CorePlayQueue::getTrack 0 May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:25:50 volumio volumio[12615]: info: CoreCommandRouter::volumioPushState May 13 15:25:50 volumio volumio[12615]: info: Setting Device type: Tinkerboard May 13 15:25:51 volumio volumio[12615]: info: VolumeController:: Volume=100 Mute =false May 13 15:25:51 volumio volumio[12615]: info: CoreStateMachine::pushState May 13 15:25:51 volumio volumio[12615]: info: CorePlayQueue::getTrack 0 May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::volumioPushState May 13 15:25:51 volumio volumio[12615]: info: CoreStateMachine::updateTrackBlock May 13 15:25:51 volumio volumio[12615]: info: CorePlayQueue::getTrackBlock May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:25:51 volumio volumio[12615]: Unhandled rejection Error: No sockets available, cannot start. May 13 15:25:51 volumio volumio[12615]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) May 13 15:25:51 volumio volumio[12615]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) May 13 15:25:51 volumio volumio[12615]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 May 13 15:25:51 volumio volumio[12615]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) May 13 15:25:51 volumio volumio[12615]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) May 13 15:25:51 volumio volumio[12615]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) May 13 15:25:51 volumio volumio[12615]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) May 13 15:25:51 volumio volumio[12615]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) May 13 15:25:51 volumio volumio[12615]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) May 13 15:25:51 volumio volumio[12615]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) May 13 15:25:51 volumio volumio[12615]: at HashMap. (/volumio/app/pluginmanager.js:496:31) May 13 15:25:51 volumio volumio[12615]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) May 13 15:25:51 volumio volumio[12615]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) May 13 15:25:51 volumio volumio[12615]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) May 13 15:25:51 volumio volumio[12615]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) May 13 15:25:51 volumio volumio[12615]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 13 15:25:51 volumio volumio[12615]: info: logitechmediaserver started May 13 15:25:51 volumio volumio[12615]: info: MPD Permissions set May 13 15:25:51 volumio volumio[12615]: info: Spotify config file written May 13 15:25:51 volumio volumio[12615]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 13 15:25:51 volumio sudo[12841]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio sudo[12841]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 13 15:25:51 volumio systemd[1]: Stopping go-librespot Daemon... May 13 15:25:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM May 13 15:25:51 volumio systemd[1]: go-librespot-daemon.service: Succeeded. May 13 15:25:51 volumio systemd[1]: Stopped go-librespot Daemon. May 13 15:25:51 volumio systemd[1]: Started go-librespot Daemon. May 13 15:25:51 volumio sudo[12841]: pam_unix(sudo:session): session closed for user root May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: No need to fix Spotify hosts May 13 15:25:51 volumio go-librespot[12869]: Librespot-go daemon starting... May 13 15:25:51 volumio go-librespot[12869]: time="2025-05-13T15:25:51-04:00" level=info msg="generated new device id: 432879ae8a0d6dd1bdd4798f443ed06ef7047de0" May 13 15:25:51 volumio go-librespot[12869]: time="2025-05-13T15:25:51-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 13 15:25:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 15:25:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 15:25:51 volumio volumio[12615]: info: VolumeController:: Volume=100 Mute =false May 13 15:25:51 volumio volumio[12615]: info: CoreStateMachine::pushState May 13 15:25:51 volumio volumio[12615]: info: CorePlayQueue::getTrack 0 May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::volumioPushState May 13 15:25:51 volumio volumio[12615]: info: [squeezelite_mc] Server discovery started May 13 15:25:51 volumio volumio[12615]: info: [squeezelite_mc] Player finder started May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:25:51 volumio volumio[12615]: info: [squeezelite_mc] Executing aplay -D hw:0 --nonblock -f MPEG /dev/zero 2>&1 || true May 13 15:25:51 volumio volumio[12615]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 15:25:51 volumio volumio[12615]: Error: send ENETUNREACH 255.255.255.255:3483 May 13 15:25:51 volumio volumio[12615]: at doSend (dgram.js:714:16) May 13 15:25:51 volumio volumio[12615]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:452:18) May 13 15:25:51 volumio volumio[12615]: at afterDns (dgram.js:660:5) May 13 15:25:51 volumio volumio[12615]: at processTicksAndRejections (internal/process/task_queues.js:83:21) { May 13 15:25:51 volumio volumio[12615]: errno: -101, May 13 15:25:51 volumio volumio[12615]: code: 'ENETUNREACH', May 13 15:25:51 volumio volumio[12615]: syscall: 'send', May 13 15:25:51 volumio volumio[12615]: address: '255.255.255.255', May 13 15:25:51 volumio volumio[12615]: port: 3483 May 13 15:25:51 volumio volumio[12615]: } May 13 15:25:51 volumio volumio[12615]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 15:25:51 volumio sudo[12892]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-13 15:24 May 13 15:25:51 volumio sudo[12892]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:51 volumio sudo[12892]: pam_unix(sudo:session): session closed for user root May 13 15:25:52 volumio volumio-remote-updater[534]: [2025-05-13 15:25:52] [error] handle_read_frame error: websocketpp.transport:7 (End of File) May 13 15:25:52 volumio volumio-remote-updater[534]: [2025-05-13 15:25:52] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] May 13 15:25:52 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE May 13 15:25:52 volumio sudo[12763]: pam_unix(sudo:session): session closed for user root May 13 15:25:52 volumio sudo[12746]: pam_unix(sudo:session): session closed for user root May 13 15:25:52 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. May 13 15:25:52 volumio systemd[1]: Started dynamicswap service. May 13 15:25:52 volumio systemd[1]: dynamicswap.service: Succeeded. May 13 15:25:52 volumio mpd[12817]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 13 15:25:52 volumio mpd[12817]: output: No 'audio_output' defined in config file May 13 15:25:52 volumio mpd[12817]: output: Successfully detected a sndio audio device May 13 15:25:52 volumio mpd[12817]: zeroconf: No global port, disabling zeroconf May 13 15:25:52 volumio systemd[1]: Started Music Player Daemon. May 13 15:25:52 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. May 13 15:25:52 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 47. May 13 15:25:52 volumio systemd[1]: Stopped Volumio Backend Module. May 13 15:25:52 volumio systemd[1]: Started Volumio Backend Module. May 13 15:25:52 volumio systemd[1]: Started dynamicswap service. May 13 15:25:52 volumio systemd[1]: dynamicswap.service: Succeeded. May 13 15:25:53 volumio volumio[12921]: info: ------------------------------------------- May 13 15:25:53 volumio volumio[12921]: info: ----- Volumio3 ---- May 13 15:25:53 volumio volumio[12921]: info: ------------------------------------------- May 13 15:25:53 volumio volumio[12921]: info: ----- System startup ---- May 13 15:25:53 volumio volumio[12921]: info: ------------------------------------------- May 13 15:25:53 volumio volumio[12921]: info: MYVOLUMIO Environment detected May 13 15:25:53 volumio volumio[12921]: info: Plugin folders cleanup May 13 15:25:53 volumio volumio[12921]: info: Scanning into folder /volumio/app/plugins/ May 13 15:25:53 volumio volumio[12921]: info: Scanning category audio_interface May 13 15:25:53 volumio volumio[12921]: info: Scanning category miscellanea May 13 15:25:53 volumio volumio[12921]: info: Scanning category music_service May 13 15:25:53 volumio volumio[12921]: info: Scanning category plugins.json May 13 15:25:53 volumio volumio[12921]: info: Scanning category system_controller May 13 15:25:53 volumio volumio[12921]: info: Scanning category user_interface May 13 15:25:53 volumio volumio[12921]: info: Scanning into folder /data/plugins/ May 13 15:25:53 volumio volumio[12921]: info: Scanning category music_service May 13 15:25:53 volumio volumio[12921]: info: Scanning category user_interface May 13 15:25:53 volumio volumio[12921]: info: Plugin folders cleanup completed May 13 15:25:53 volumio volumio[12921]: info: ------------------------------------------- May 13 15:25:53 volumio volumio[12921]: info: ----- Core plugins startup ---- May 13 15:25:53 volumio volumio[12921]: info: ------------------------------------------- May 13 15:25:53 volumio volumio[12921]: info: Loading plugins from folder /volumio/app/plugins/ May 13 15:25:53 volumio volumio[12921]: info: Adding plugin upnp to MyMusic Plugins May 13 15:25:53 volumio volumio[12921]: info: Adding plugin airplay_emulation to MyMusic Plugins May 13 15:25:53 volumio volumio[12921]: info: Adding plugin upnp_browser to MyMusic Plugins May 13 15:25:53 volumio volumio[12921]: info: Loading plugins from folder /data/plugins/ May 13 15:25:53 volumio volumio[12921]: info: Loading plugin "system"... May 13 15:25:53 volumio volumio[12921]: info: Loading plugin "appearance"... May 13 15:25:54 volumio volumio[12921]: info: Loading plugin "network"... May 13 15:25:54 volumio volumio[12921]: info: Refreshing Cached IP Addresses May 13 15:25:54 volumio sudo[12949]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 13 15:25:54 volumio sudo[12951]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 13 15:25:54 volumio volumio[12921]: info: Loading plugin "services"... May 13 15:25:54 volumio volumio[12921]: info: Loading plugin "alsa_controller"... May 13 15:25:54 volumio sudo[12951]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:54 volumio sudo[12949]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:54 volumio sudo[12951]: pam_unix(sudo:session): session closed for user root May 13 15:25:54 volumio sudo[12949]: pam_unix(sudo:session): session closed for user root May 13 15:25:54 volumio sudo[12963]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 13 15:25:54 volumio sudo[12963]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:54 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 15:25:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. May 13 15:25:54 volumio systemd[1]: Stopped go-librespot Daemon. May 13 15:25:54 volumio systemd[1]: Started go-librespot Daemon. May 13 15:25:54 volumio go-librespot[12997]: Librespot-go daemon starting... May 13 15:25:54 volumio go-librespot[12997]: time="2025-05-13T15:25:54-04:00" level=info msg="generated new device id: c799c801bfc49b4bd9bf43e258b6232f3986c430" May 13 15:25:54 volumio go-librespot[12997]: time="2025-05-13T15:25:54-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 13 15:25:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 15:25:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 15:25:54 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:25:54 volumio volumio[12921]: info: Loading plugin "wizard"... May 13 15:25:54 volumio volumio[12921]: info: Loading plugin "networkfs"... May 13 15:25:54 volumio volumio[12921]: info: Cannot mount NAS NAS at system boot, trial number 1 ,retrying in 5 seconds May 13 15:25:54 volumio volumio[12921]: info: Starting Udev Watcher for removable devices May 13 15:25:54 volumio volumio[12921]: info: Ignoring mount for partition: BOOT May 13 15:25:54 volumio volumio[12921]: info: Ignoring mount for partition: volumio May 13 15:25:54 volumio volumio[12921]: info: Ignoring mount for partition: volumio_data May 13 15:25:54 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:25:54 volumio volumio[12921]: info: Loading plugin "volumio_command_line_client"... May 13 15:25:54 volumio volumio[12921]: info: Loading plugin "upnp"... May 13 15:25:54 volumio volumio[12921]: info: [1747164354694] Starting Upmpd Daemon May 13 15:25:54 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:25:54 volumio volumio[12921]: info: Loading plugin "my_music"... May 13 15:25:54 volumio volumio[12921]: info: Loading plugin "mpd"... May 13 15:25:54 volumio volumio[12921]: info: Loading plugin "upnp_browser"... May 13 15:25:55 volumio volumio[12921]: info: Loading plugin "alarm-clock"... May 13 15:25:55 volumio volumio[12921]: info: Loading plugin "airplay_emulation"... May 13 15:25:55 volumio volumio[12921]: info: Starting Shairport Sync May 13 15:25:55 volumio volumio[12921]: info: Loading plugin "last_100"... May 13 15:25:55 volumio volumio[12921]: info: Loading plugin "webradio"... May 13 15:25:55 volumio volumio[12921]: info: Loading plugin "i2s_dacs"... May 13 15:25:55 volumio volumio[12921]: info: I2S DAC not set, start Auto-detection May 13 15:25:55 volumio volumio[12921]: info: Loading plugin "volumiodiscovery"... May 13 15:25:55 volumio volumio[12921]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 13 15:25:55 volumio volumio[12921]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:25:55 volumio volumio[12921]: *** WARNING *** For more information see May 13 15:25:55 volumio volumio[12921]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 13 15:25:55 volumio node[12921]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 13 15:25:55 volumio volumio[12921]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:25:55 volumio volumio[12921]: *** WARNING *** For more information see May 13 15:25:55 volumio node[12921]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:25:55 volumio node[12921]: *** WARNING *** For more information see May 13 15:25:55 volumio node[12921]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 13 15:25:55 volumio node[12921]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:25:55 volumio node[12921]: *** WARNING *** For more information see May 13 15:25:55 volumio volumio[12921]: info: Applying required configuration parameters for plugin volumiodiscovery May 13 15:25:55 volumio volumio[12921]: info: Discovery: Started advertising with name: Volumio May 13 15:25:55 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:25:55 volumio volumio[12921]: info: Loading plugin "spop"... May 13 15:25:55 volumio sudo[12963]: pam_unix(sudo:session): session closed for user root May 13 15:25:55 volumio volumio[12921]: info: Loading plugin "squeezelite_mc"... May 13 15:25:56 volumio volumio[12921]: info: Loading plugin "youtube2"... May 13 15:25:56 volumio volumio[12921]: info: Loading plugin "now_playing"... May 13 15:25:57 volumio volumio-remote-updater[534]: [2025-05-13 15:25:57] [connect] Successful connection May 13 15:25:57 volumio volumio[12921]: info: Loading plugin "outputs"... May 13 15:25:57 volumio volumio[12921]: info: Loading plugin "albumart"... May 13 15:25:57 volumio volumio[12921]: info: Plugin example_plugin is not enabled May 13 15:25:57 volumio volumio[12921]: info: Loading plugin "inputs"... May 13 15:25:57 volumio volumio[12921]: info: Loading plugin "updater_comm"... May 13 15:25:57 volumio volumio[12921]: info: Plugin mpdemulation is not enabled May 13 15:25:57 volumio volumio[12921]: info: Loading plugin "rest_api"... May 13 15:25:57 volumio volumio[12921]: info: Loading plugin "websocket"... May 13 15:25:57 volumio volumio[12921]: info: Starting Socket.io Server version 2.3.0 May 13 15:25:57 volumio volumio[12921]: info: Loading plugin "lms"... May 13 15:25:57 volumio volumio[12921]: info: Loading i18n strings for locale en May 13 15:25:57 volumio volumio[12921]: Updating browse sources language May 13 15:25:57 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:25:57 volumio volumio[12921]: Forking 3 albumart workers May 13 15:25:57 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 15:25:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. May 13 15:25:57 volumio systemd[1]: Stopped go-librespot Daemon. May 13 15:25:57 volumio systemd[1]: Started go-librespot Daemon. May 13 15:25:57 volumio go-librespot[13022]: Librespot-go daemon starting... May 13 15:25:57 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:25:57 volumio volumio[12921]: info: CoreCommandRouter::initPlayerControls May 13 15:25:57 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:57 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:25:57 volumio volumio[12921]: Express server listening on port 3000 May 13 15:25:57 volumio volumio[12921]: [Metrics] WebUI: 4s 828.80ms May 13 15:25:57 volumio go-librespot[13022]: time="2025-05-13T15:25:57-04:00" level=info msg="generated new device id: b5de2305799bd422772223cbcaa1b81d5682bf06" May 13 15:25:57 volumio volumio[12921]: info: CoreStateMachine::resetVolumioState May 13 15:25:57 volumio volumio[12921]: info: CoreStateMachine::getcurrentVolume May 13 15:25:57 volumio volumio[12921]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:25:57 volumio go-librespot[13022]: time="2025-05-13T15:25:57-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 13 15:25:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 15:25:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 15:25:57 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:25:57 volumio volumio[12921]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' May 13 15:25:57 volumio volumio[12921]: info: Completed loading Core Plugins May 13 15:25:57 volumio volumio[12921]: info: Preparing to generate the ALSA configuration file May 13 15:25:58 volumio volumio[12921]: info: Volumio Network Manager: Network status updated: 0 May 13 15:25:58 volumio volumio-remote-updater[534]: [2025-05-13 15:25:58] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1747164357 101 May 13 15:25:58 volumio volumio[12921]: 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 May 13 15:25:58 volumio volumio[12921]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 2 May 13 15:25:58 volumio volumio[12921]: info: Reloading queue from file May 13 15:25:58 volumio volumio[12921]: info: Asound.conf file unchanged, so no further update is needed May 13 15:25:58 volumio volumio[12921]: info: Output device has changed, restarting MPD May 13 15:25:58 volumio volumio[12921]: info: Output device has changed, restarting Shairport Sync May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:25:58 volumio sudo[13060]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 13 15:25:58 volumio sudo[13059]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 13 15:25:58 volumio sudo[13059]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:58 volumio sudo[13060]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:58 volumio sudo[13059]: pam_unix(sudo:session): session closed for user root May 13 15:25:58 volumio volumio[12921]: info: ___________ START PLUGINS ___________ May 13 15:25:58 volumio volumio[12921]: info: ControllerMpd::onStart: Initializing MPD May 13 15:25:58 volumio volumio[12921]: info: Creating MPD Configuration file May 13 15:25:58 volumio systemd[1]: Stopping Music Player Daemon... May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:25:58 volumio volumio[12921]: info: [1747164358384] CoreMusicLibrary::Adding element Media Servers May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:25:58 volumio sudo[13079]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 13 15:25:58 volumio systemd[1]: mpd.service: Succeeded. May 13 15:25:58 volumio systemd[1]: Stopped Music Player Daemon. May 13 15:25:58 volumio systemd[1]: Starting Music Player Daemon... May 13 15:25:58 volumio sudo[13080]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 13 15:25:58 volumio sudo[13079]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:58 volumio sudo[13080]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:58 volumio sudo[13079]: pam_unix(sudo:session): session closed for user root May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:25:58 volumio volumio[12921]: info: [1747164358567] CoreMusicLibrary::Adding element Last_100 May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:25:58 volumio volumio[12921]: info: [1747164358570] CoreMusicLibrary::Adding element Webradio May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:25:58 volumio volumio[12921]: info: Initializing BBC Radios May 13 15:25:58 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM May 13 15:25:58 volumio systemd[1]: mpd.service: Succeeded. May 13 15:25:58 volumio systemd[1]: Stopped Music Player Daemon. May 13 15:25:58 volumio systemd[1]: Starting Music Player Daemon... May 13 15:25:58 volumio volumio[12921]: Starting albumart workers May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:25:58 volumio volumio[12921]: info: Creating Spotify config file May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:58 volumio volumio[12921]: Starting albumart workers May 13 15:25:58 volumio volumio[12921]: info: [squeezelite_mc] Starting proxy server... May 13 15:25:58 volumio sudo[13103]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:25:58 volumio volumio[12921]: info: [1747164358715] CoreMusicLibrary::Adding element YouTube2 May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:25:58 volumio volumio[12921]: Cannot find translation for source YouTube2 May 13 15:25:58 volumio volumio[12921]: info: [now-playing-config] Config is up to date. May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 13 15:25:58 volumio volumio[12921]: info: Discovery: Getting this device information May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::volumioGetState May 13 15:25:58 volumio sudo[13103]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:58 volumio volumio[12921]: info: CorePlayQueue::getTrack 0 May 13 15:25:58 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 13 15:25:58 volumio sudo[13103]: pam_unix(sudo:session): session closed for user root May 13 15:25:58 volumio volumio[12921]: info: Volumio Calling Home May 13 15:25:58 volumio volumio[12921]: Starting albumart workers May 13 15:25:58 volumio sudo[13120]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver May 13 15:25:58 volumio sudo[13120]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:58 volumio systemd[1]: Starting Logitech Media Server Daemon... May 13 15:25:58 volumio volumio[12921]: info: [squeezelite_mc] Proxy server started on port 39345 May 13 15:25:58 volumio volumio[12921]: info: [now-playing-app] App is listening on port 4004. May 13 15:25:58 volumio systemd[1]: Started Logitech Media Server Daemon. May 13 15:25:58 volumio sudo[13120]: pam_unix(sudo:session): session closed for user root May 13 15:25:58 volumio systemd[13133]: logitechmediaserver.service: Failed to execute command: No such file or directory May 13 15:25:58 volumio systemd[13133]: logitechmediaserver.service: Failed at step EXEC spawning /usr/sbin/squeezeboxserver: No such file or directory May 13 15:25:58 volumio systemd[1]: logitechmediaserver.service: Main process exited, code=exited, status=203/EXEC May 13 15:25:58 volumio systemd[1]: logitechmediaserver.service: Failed with result 'exit-code'. May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:25:59 volumio volumio[12921]: info: CoreStateMachine::setRepeat false single undefined May 13 15:25:59 volumio volumio[12921]: info: CoreStateMachine::pushState May 13 15:25:59 volumio volumio[12921]: info: CorePlayQueue::getTrack 0 May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::volumioPushState May 13 15:25:59 volumio volumio[12921]: info: CoreStateMachine::setRandom undefined May 13 15:25:59 volumio volumio[12921]: info: CoreStateMachine::pushState May 13 15:25:59 volumio volumio[12921]: info: CorePlayQueue::getTrack 0 May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::volumioPushState May 13 15:25:59 volumio volumio[12921]: info: Setting Device type: Tinkerboard May 13 15:25:59 volumio volumio[12921]: info: VolumeController:: Volume=100 Mute =false May 13 15:25:59 volumio volumio[12921]: info: CoreStateMachine::pushState May 13 15:25:59 volumio volumio[12921]: info: CorePlayQueue::getTrack 0 May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::volumioPushState May 13 15:25:59 volumio volumio[12921]: info: CoreStateMachine::updateTrackBlock May 13 15:25:59 volumio volumio[12921]: info: CorePlayQueue::getTrackBlock May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:25:59 volumio volumio[12921]: Unhandled rejection Error: No sockets available, cannot start. May 13 15:25:59 volumio volumio[12921]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) May 13 15:25:59 volumio volumio[12921]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) May 13 15:25:59 volumio volumio[12921]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 May 13 15:25:59 volumio volumio[12921]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) May 13 15:25:59 volumio volumio[12921]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) May 13 15:25:59 volumio volumio[12921]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) May 13 15:25:59 volumio volumio[12921]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) May 13 15:25:59 volumio volumio[12921]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) May 13 15:25:59 volumio volumio[12921]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) May 13 15:25:59 volumio volumio[12921]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) May 13 15:25:59 volumio volumio[12921]: at HashMap. (/volumio/app/pluginmanager.js:496:31) May 13 15:25:59 volumio volumio[12921]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) May 13 15:25:59 volumio volumio[12921]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) May 13 15:25:59 volumio volumio[12921]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) May 13 15:25:59 volumio volumio[12921]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) May 13 15:25:59 volumio volumio[12921]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 13 15:25:59 volumio volumio[12921]: info: logitechmediaserver started May 13 15:25:59 volumio volumio[12921]: info: MPD Permissions set May 13 15:25:59 volumio volumio[12921]: info: MPD Permissions set May 13 15:25:59 volumio volumio[12921]: info: Spotify config file written May 13 15:25:59 volumio volumio[12921]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio sudo[13147]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 13 15:25:59 volumio sudo[13147]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio systemd[1]: Stopped go-librespot Daemon. May 13 15:25:59 volumio systemd[1]: Started go-librespot Daemon. May 13 15:25:59 volumio go-librespot[13171]: Librespot-go daemon starting... May 13 15:25:59 volumio sudo[13147]: pam_unix(sudo:session): session closed for user root May 13 15:25:59 volumio go-librespot[13171]: time="2025-05-13T15:25:59-04:00" level=info msg="generated new device id: 368ebe733974f1775926f85025f8221e50c5055b" May 13 15:25:59 volumio go-librespot[13171]: time="2025-05-13T15:25:59-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 13 15:25:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 15:25:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: No need to fix Spotify hosts May 13 15:25:59 volumio volumio[12921]: info: VolumeController:: Volume=100 Mute =false May 13 15:25:59 volumio volumio[12921]: info: CoreStateMachine::pushState May 13 15:25:59 volumio volumio[12921]: info: CorePlayQueue::getTrack 0 May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::volumioPushState May 13 15:25:59 volumio volumio[12921]: info: [squeezelite_mc] Server discovery started May 13 15:25:59 volumio volumio[12921]: info: [squeezelite_mc] Player finder started May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:25:59 volumio volumio[12921]: info: [squeezelite_mc] Executing aplay -D hw:0 --nonblock -f MPEG /dev/zero 2>&1 || true May 13 15:25:59 volumio ntpd[815]: Soliciting pool server 44.190.5.123 May 13 15:25:59 volumio volumio[12921]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 15:25:59 volumio volumio[12921]: Error: send ENETUNREACH 255.255.255.255:3483 May 13 15:25:59 volumio volumio[12921]: at doSend (dgram.js:714:16) May 13 15:25:59 volumio volumio[12921]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:452:18) May 13 15:25:59 volumio volumio[12921]: at afterDns (dgram.js:660:5) May 13 15:25:59 volumio volumio[12921]: at processTicksAndRejections (internal/process/task_queues.js:83:21) { May 13 15:25:59 volumio volumio[12921]: errno: -101, May 13 15:25:59 volumio volumio[12921]: code: 'ENETUNREACH', May 13 15:25:59 volumio volumio[12921]: syscall: 'send', May 13 15:25:59 volumio volumio[12921]: address: '255.255.255.255', May 13 15:25:59 volumio volumio[12921]: port: 3483 May 13 15:25:59 volumio volumio[12921]: } May 13 15:25:59 volumio volumio[12921]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 15:26:00 volumio sudo[13206]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-13 15:24 May 13 15:26:00 volumio sudo[13206]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:00 volumio sudo[13206]: pam_unix(sudo:session): session closed for user root May 13 15:26:00 volumio volumio-remote-updater[534]: [2025-05-13 15:26:00] [error] handle_read_frame error: websocketpp.transport:7 (End of File) May 13 15:26:00 volumio volumio-remote-updater[534]: [2025-05-13 15:26:00] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] May 13 15:26:00 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE May 13 15:26:00 volumio sudo[13080]: pam_unix(sudo:session): session closed for user root May 13 15:26:00 volumio sudo[13060]: pam_unix(sudo:session): session closed for user root May 13 15:26:00 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. May 13 15:26:00 volumio systemd[1]: Started dynamicswap service. May 13 15:26:00 volumio systemd[1]: dynamicswap.service: Succeeded. May 13 15:26:00 volumio mpd[13130]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 13 15:26:00 volumio mpd[13130]: output: No 'audio_output' defined in config file May 13 15:26:00 volumio mpd[13130]: output: Successfully detected a sndio audio device May 13 15:26:00 volumio mpd[13130]: zeroconf: No global port, disabling zeroconf May 13 15:26:00 volumio systemd[1]: Started Music Player Daemon. May 13 15:26:00 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. May 13 15:26:00 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 48. May 13 15:26:00 volumio systemd[1]: Started dynamicswap service. May 13 15:26:00 volumio systemd[1]: Stopped Volumio Backend Module. May 13 15:26:00 volumio systemd[1]: Started Volumio Backend Module. May 13 15:26:00 volumio systemd[1]: dynamicswap.service: Succeeded. May 13 15:26:01 volumio volumio[13235]: info: ------------------------------------------- May 13 15:26:01 volumio volumio[13235]: info: ----- Volumio3 ---- May 13 15:26:01 volumio volumio[13235]: info: ------------------------------------------- May 13 15:26:01 volumio volumio[13235]: info: ----- System startup ---- May 13 15:26:01 volumio volumio[13235]: info: ------------------------------------------- May 13 15:26:01 volumio volumio[13235]: info: MYVOLUMIO Environment detected May 13 15:26:01 volumio volumio[13235]: info: Plugin folders cleanup May 13 15:26:01 volumio volumio[13235]: info: Scanning into folder /volumio/app/plugins/ May 13 15:26:01 volumio volumio[13235]: info: Scanning category audio_interface May 13 15:26:01 volumio volumio[13235]: info: Scanning category miscellanea May 13 15:26:01 volumio volumio[13235]: info: Scanning category music_service May 13 15:26:01 volumio volumio[13235]: info: Scanning category plugins.json May 13 15:26:01 volumio volumio[13235]: info: Scanning category system_controller May 13 15:26:01 volumio volumio[13235]: info: Scanning category user_interface May 13 15:26:01 volumio volumio[13235]: info: Scanning into folder /data/plugins/ May 13 15:26:01 volumio volumio[13235]: info: Scanning category music_service May 13 15:26:01 volumio volumio[13235]: info: Scanning category user_interface May 13 15:26:01 volumio volumio[13235]: info: Plugin folders cleanup completed May 13 15:26:01 volumio volumio[13235]: info: ------------------------------------------- May 13 15:26:01 volumio volumio[13235]: info: ----- Core plugins startup ---- May 13 15:26:01 volumio volumio[13235]: info: ------------------------------------------- May 13 15:26:01 volumio volumio[13235]: info: Loading plugins from folder /volumio/app/plugins/ May 13 15:26:01 volumio volumio[13235]: info: Adding plugin upnp to MyMusic Plugins May 13 15:26:01 volumio volumio[13235]: info: Adding plugin airplay_emulation to MyMusic Plugins May 13 15:26:01 volumio volumio[13235]: info: Adding plugin upnp_browser to MyMusic Plugins May 13 15:26:01 volumio volumio[13235]: info: Loading plugins from folder /data/plugins/ May 13 15:26:01 volumio volumio[13235]: info: Loading plugin "system"... May 13 15:26:01 volumio volumio[13235]: info: Loading plugin "appearance"... May 13 15:26:02 volumio volumio[13235]: info: Loading plugin "network"... May 13 15:26:02 volumio volumio[13235]: info: Refreshing Cached IP Addresses May 13 15:26:02 volumio sudo[13261]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 13 15:26:02 volumio sudo[13263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 13 15:26:02 volumio volumio[13235]: info: Loading plugin "services"... May 13 15:26:02 volumio volumio[13235]: info: Loading plugin "alsa_controller"... May 13 15:26:02 volumio sudo[13261]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:02 volumio sudo[13263]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:02 volumio sudo[13261]: pam_unix(sudo:session): session closed for user root May 13 15:26:02 volumio sudo[13263]: pam_unix(sudo:session): session closed for user root May 13 15:26:02 volumio sudo[13280]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 13 15:26:02 volumio sudo[13280]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:02 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 15:26:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. May 13 15:26:02 volumio systemd[1]: Stopped go-librespot Daemon. May 13 15:26:02 volumio systemd[1]: Started go-librespot Daemon. May 13 15:26:02 volumio go-librespot[13305]: Librespot-go daemon starting... May 13 15:26:02 volumio go-librespot[13305]: time="2025-05-13T15:26:02-04:00" level=info msg="generated new device id: f2b33806870914c6cebbecf26515ef09ba9468f4" May 13 15:26:02 volumio go-librespot[13305]: time="2025-05-13T15:26:02-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 13 15:26:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 15:26:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 15:26:02 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:26:02 volumio volumio[13235]: info: Loading plugin "wizard"... May 13 15:26:02 volumio volumio[13235]: info: Loading plugin "networkfs"... May 13 15:26:02 volumio volumio[13235]: info: Cannot mount NAS NAS at system boot, trial number 1 ,retrying in 5 seconds May 13 15:26:02 volumio volumio[13235]: info: Starting Udev Watcher for removable devices May 13 15:26:02 volumio volumio[13235]: info: Ignoring mount for partition: BOOT May 13 15:26:02 volumio volumio[13235]: info: Ignoring mount for partition: volumio May 13 15:26:02 volumio volumio[13235]: info: Ignoring mount for partition: volumio_data May 13 15:26:02 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:26:02 volumio volumio[13235]: info: Loading plugin "volumio_command_line_client"... May 13 15:26:02 volumio volumio[13235]: info: Loading plugin "upnp"... May 13 15:26:02 volumio volumio[13235]: info: [1747164362706] Starting Upmpd Daemon May 13 15:26:02 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:26:02 volumio volumio[13235]: info: Loading plugin "my_music"... May 13 15:26:02 volumio volumio[13235]: info: Loading plugin "mpd"... May 13 15:26:02 volumio volumio[13235]: info: Loading plugin "upnp_browser"... May 13 15:26:03 volumio volumio[13235]: info: Loading plugin "alarm-clock"... May 13 15:26:03 volumio volumio[13235]: info: Loading plugin "airplay_emulation"... May 13 15:26:03 volumio volumio[13235]: info: Starting Shairport Sync May 13 15:26:03 volumio volumio[13235]: info: Loading plugin "last_100"... May 13 15:26:03 volumio volumio[13235]: info: Loading plugin "webradio"... May 13 15:26:03 volumio volumio[13235]: info: Loading plugin "i2s_dacs"... May 13 15:26:03 volumio volumio[13235]: info: I2S DAC not set, start Auto-detection May 13 15:26:03 volumio volumio[13235]: info: Loading plugin "volumiodiscovery"... May 13 15:26:03 volumio volumio[13235]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 13 15:26:03 volumio volumio[13235]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:26:03 volumio volumio[13235]: *** WARNING *** For more information see May 13 15:26:03 volumio volumio[13235]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 13 15:26:03 volumio volumio[13235]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:26:03 volumio node[13235]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 13 15:26:03 volumio volumio[13235]: *** WARNING *** For more information see May 13 15:26:03 volumio node[13235]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:26:03 volumio node[13235]: *** WARNING *** For more information see May 13 15:26:03 volumio node[13235]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 13 15:26:03 volumio node[13235]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:26:03 volumio node[13235]: *** WARNING *** For more information see May 13 15:26:03 volumio volumio[13235]: info: Applying required configuration parameters for plugin volumiodiscovery May 13 15:26:03 volumio volumio[13235]: info: Discovery: Started advertising with name: Volumio May 13 15:26:03 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:26:03 volumio volumio[13235]: info: Loading plugin "spop"... May 13 15:26:03 volumio volumio[13235]: info: Loading plugin "squeezelite_mc"... May 13 15:26:03 volumio sudo[13280]: pam_unix(sudo:session): session closed for user root May 13 15:26:04 volumio volumio[13235]: info: Loading plugin "youtube2"... May 13 15:26:04 volumio volumio[13235]: info: Loading plugin "now_playing"... May 13 15:26:05 volumio volumio-remote-updater[534]: [2025-05-13 15:26:05] [connect] Successful connection May 13 15:26:05 volumio volumio[13235]: info: Loading plugin "outputs"... May 13 15:26:05 volumio volumio[13235]: info: Loading plugin "albumart"... May 13 15:26:05 volumio volumio[13235]: info: Plugin example_plugin is not enabled May 13 15:26:05 volumio volumio[13235]: info: Loading plugin "inputs"... May 13 15:26:05 volumio volumio[13235]: info: Loading plugin "updater_comm"... May 13 15:26:05 volumio volumio[13235]: info: Plugin mpdemulation is not enabled May 13 15:26:05 volumio volumio[13235]: info: Loading plugin "rest_api"... May 13 15:26:05 volumio volumio[13235]: info: Loading plugin "websocket"... May 13 15:26:05 volumio volumio[13235]: info: Starting Socket.io Server version 2.3.0 May 13 15:26:05 volumio volumio[13235]: info: Loading plugin "lms"... May 13 15:26:05 volumio volumio[13235]: info: Loading i18n strings for locale en May 13 15:26:05 volumio volumio[13235]: Updating browse sources language May 13 15:26:05 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:05 volumio volumio[13235]: Forking 3 albumart workers May 13 15:26:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 15:26:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. May 13 15:26:05 volumio systemd[1]: Stopped go-librespot Daemon. May 13 15:26:05 volumio systemd[1]: Started go-librespot Daemon. May 13 15:26:05 volumio go-librespot[13348]: Librespot-go daemon starting... May 13 15:26:05 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:26:05 volumio volumio[13235]: info: CoreCommandRouter::initPlayerControls May 13 15:26:05 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:05 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:05 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:05 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:05 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:05 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:05 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:26:05 volumio volumio[13235]: Express server listening on port 3000 May 13 15:26:05 volumio volumio[13235]: [Metrics] WebUI: 4s 864.60ms May 13 15:26:05 volumio go-librespot[13348]: time="2025-05-13T15:26:05-04:00" level=info msg="generated new device id: 2f0f1a0ab4fa9db85973fcc7acc821f0b3c6e49f" May 13 15:26:05 volumio go-librespot[13348]: time="2025-05-13T15:26:05-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 13 15:26:05 volumio volumio[13235]: info: CoreStateMachine::resetVolumioState May 13 15:26:05 volumio volumio[13235]: info: CoreStateMachine::getcurrentVolume May 13 15:26:05 volumio volumio[13235]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:26:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 15:26:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 15:26:05 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:05 volumio volumio[13235]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' May 13 15:26:05 volumio volumio[13235]: info: Completed loading Core Plugins May 13 15:26:06 volumio volumio[13235]: info: Preparing to generate the ALSA configuration file May 13 15:26:06 volumio volumio[13235]: info: Volumio Network Manager: Network status updated: 0 May 13 15:26:06 volumio volumio[13235]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 1 May 13 15:26:06 volumio volumio-remote-updater[534]: [2025-05-13 15:26:06] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1747164365 101 May 13 15:26:06 volumio volumio[13235]: 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: 2 May 13 15:26:06 volumio volumio[13235]: info: Reloading queue from file May 13 15:26:06 volumio volumio[13235]: info: Asound.conf file unchanged, so no further update is needed May 13 15:26:06 volumio volumio[13235]: info: Output device has changed, restarting MPD May 13 15:26:06 volumio volumio[13235]: info: Output device has changed, restarting Shairport Sync May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:06 volumio sudo[13375]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 13 15:26:06 volumio volumio[13235]: info: ___________ START PLUGINS ___________ May 13 15:26:06 volumio volumio[13235]: info: ControllerMpd::onStart: Initializing MPD May 13 15:26:06 volumio volumio[13235]: info: Creating MPD Configuration file May 13 15:26:06 volumio sudo[13376]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 13 15:26:06 volumio sudo[13375]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:06 volumio sudo[13388]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 13 15:26:06 volumio sudo[13376]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:26:06 volumio volumio[13235]: info: [1747164366326] CoreMusicLibrary::Adding element Media Servers May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:06 volumio sudo[13375]: pam_unix(sudo:session): session closed for user root May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:06 volumio sudo[13388]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:06 volumio systemd[1]: Stopping Music Player Daemon... May 13 15:26:06 volumio sudo[13394]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:06 volumio sudo[13388]: pam_unix(sudo:session): session closed for user root May 13 15:26:06 volumio sudo[13394]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:06 volumio systemd[1]: mpd.service: Succeeded. May 13 15:26:06 volumio systemd[1]: Stopped Music Player Daemon. May 13 15:26:06 volumio systemd[1]: Starting Music Player Daemon... May 13 15:26:06 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM May 13 15:26:06 volumio systemd[1]: mpd.service: Succeeded. May 13 15:26:06 volumio systemd[1]: Stopped Music Player Daemon. May 13 15:26:06 volumio systemd[1]: Starting Music Player Daemon... May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:26:06 volumio volumio[13235]: info: [1747164366504] CoreMusicLibrary::Adding element Last_100 May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:26:06 volumio volumio[13235]: info: [1747164366506] CoreMusicLibrary::Adding element Webradio May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:26:06 volumio volumio[13235]: info: Initializing BBC Radios May 13 15:26:06 volumio sudo[13417]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 13 15:26:06 volumio sudo[13417]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:06 volumio sudo[13417]: pam_unix(sudo:session): session closed for user root May 13 15:26:06 volumio volumio[13235]: Starting albumart workers May 13 15:26:06 volumio volumio[13235]: info: Creating Spotify config file May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:06 volumio volumio[13235]: Starting albumart workers May 13 15:26:06 volumio volumio[13235]: info: [squeezelite_mc] Starting proxy server... May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:26:06 volumio volumio[13235]: info: [1747164366687] CoreMusicLibrary::Adding element YouTube2 May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:06 volumio volumio[13235]: Cannot find translation for source YouTube2 May 13 15:26:06 volumio volumio[13235]: Starting albumart workers May 13 15:26:06 volumio volumio[13235]: info: [now-playing-config] Config is up to date. May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 13 15:26:06 volumio volumio[13235]: info: Discovery: Getting this device information May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::volumioGetState May 13 15:26:06 volumio volumio[13235]: info: CorePlayQueue::getTrack 0 May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 13 15:26:06 volumio volumio[13235]: info: Volumio Calling Home May 13 15:26:06 volumio sudo[13438]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver May 13 15:26:06 volumio sudo[13438]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:06 volumio volumio[13235]: info: [squeezelite_mc] Proxy server started on port 33845 May 13 15:26:06 volumio volumio[13235]: info: [now-playing-app] App is listening on port 4004. May 13 15:26:06 volumio systemd[1]: Starting Logitech Media Server Daemon... May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:26:06 volumio volumio[13235]: info: CoreStateMachine::setRepeat false single undefined May 13 15:26:06 volumio volumio[13235]: info: CoreStateMachine::pushState May 13 15:26:06 volumio volumio[13235]: info: CorePlayQueue::getTrack 0 May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:26:06 volumio volumio[13235]: info: CoreCommandRouter::volumioPushState May 13 15:26:06 volumio systemd[1]: Started Logitech Media Server Daemon. May 13 15:26:06 volumio sudo[13438]: pam_unix(sudo:session): session closed for user root May 13 15:26:07 volumio volumio[13235]: info: CoreStateMachine::setRandom undefined May 13 15:26:07 volumio volumio[13235]: info: CoreStateMachine::pushState May 13 15:26:07 volumio volumio[13235]: info: CorePlayQueue::getTrack 0 May 13 15:26:07 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:26:07 volumio volumio[13235]: info: CoreCommandRouter::volumioPushState May 13 15:26:07 volumio systemd[13450]: logitechmediaserver.service: Failed to execute command: No such file or directory May 13 15:26:07 volumio systemd[13450]: logitechmediaserver.service: Failed at step EXEC spawning /usr/sbin/squeezeboxserver: No such file or directory May 13 15:26:07 volumio systemd[1]: logitechmediaserver.service: Main process exited, code=exited, status=203/EXEC May 13 15:26:07 volumio systemd[1]: logitechmediaserver.service: Failed with result 'exit-code'. May 13 15:26:07 volumio volumio[13235]: info: Setting Device type: Tinkerboard May 13 15:26:07 volumio volumio[13235]: info: VolumeController:: Volume=100 Mute =false May 13 15:26:07 volumio volumio[13235]: info: CoreStateMachine::pushState May 13 15:26:07 volumio volumio[13235]: info: CorePlayQueue::getTrack 0 May 13 15:26:07 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:26:07 volumio volumio[13235]: info: CoreCommandRouter::volumioPushState May 13 15:26:07 volumio volumio[13235]: info: CoreStateMachine::updateTrackBlock May 13 15:26:07 volumio volumio[13235]: info: CorePlayQueue::getTrackBlock May 13 15:26:07 volumio volumio[13235]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:26:07 volumio volumio[13235]: Unhandled rejection Error: No sockets available, cannot start. May 13 15:26:07 volumio volumio[13235]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) May 13 15:26:07 volumio volumio[13235]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) May 13 15:26:07 volumio volumio[13235]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 May 13 15:26:07 volumio volumio[13235]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) May 13 15:26:07 volumio volumio[13235]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) May 13 15:26:07 volumio volumio[13235]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) May 13 15:26:07 volumio volumio[13235]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) May 13 15:26:07 volumio volumio[13235]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) May 13 15:26:07 volumio volumio[13235]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) May 13 15:26:07 volumio volumio[13235]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) May 13 15:26:07 volumio volumio[13235]: at HashMap. (/volumio/app/pluginmanager.js:496:31) May 13 15:26:07 volumio volumio[13235]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) May 13 15:26:07 volumio volumio[13235]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) May 13 15:26:07 volumio volumio[13235]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) May 13 15:26:07 volumio volumio[13235]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) May 13 15:26:07 volumio volumio[13235]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 13 15:26:07 volumio volumio[13235]: info: logitechmediaserver started May 13 15:26:07 volumio volumio[13235]: info: MPD Permissions set May 13 15:26:07 volumio volumio[13235]: info: MPD Permissions set May 13 15:26:07 volumio volumio[13235]: info: VolumeController:: Volume=100 Mute =false May 13 15:26:07 volumio volumio[13235]: info: CoreStateMachine::pushState May 13 15:26:07 volumio volumio[13235]: info: CorePlayQueue::getTrack 0 May 13 15:26:07 volumio volumio[13235]: info: CoreCommandRouter::volumioPushState May 13 15:26:07 volumio volumio[13235]: info: [squeezelite_mc] Server discovery started May 13 15:26:07 volumio volumio[13235]: info: [squeezelite_mc] Player finder started May 13 15:26:07 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:07 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:07 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:07 volumio volumio[13235]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:26:07 volumio volumio[13235]: info: [squeezelite_mc] Executing aplay -D hw:0 --nonblock -f MPEG /dev/zero 2>&1 || true May 13 15:26:07 volumio volumio[13235]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 15:26:07 volumio volumio[13235]: Error: send ENETUNREACH 255.255.255.255:3483 May 13 15:26:07 volumio volumio[13235]: at doSend (dgram.js:714:16) May 13 15:26:07 volumio volumio[13235]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:452:18) May 13 15:26:07 volumio volumio[13235]: at afterDns (dgram.js:660:5) May 13 15:26:07 volumio volumio[13235]: at processTicksAndRejections (internal/process/task_queues.js:83:21) { May 13 15:26:07 volumio volumio[13235]: errno: -101, May 13 15:26:07 volumio volumio[13235]: code: 'ENETUNREACH', May 13 15:26:07 volumio volumio[13235]: syscall: 'send', May 13 15:26:07 volumio volumio[13235]: address: '255.255.255.255', May 13 15:26:07 volumio volumio[13235]: port: 3483 May 13 15:26:07 volumio volumio[13235]: } May 13 15:26:07 volumio volumio[13235]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 15:26:07 volumio sudo[13491]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-13 15:25 May 13 15:26:07 volumio sudo[13491]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:07 volumio sudo[13491]: pam_unix(sudo:session): session closed for user root May 13 15:26:07 volumio volumio-remote-updater[534]: [2025-05-13 15:26:07] [error] handle_read_frame error: websocketpp.transport:7 (End of File) May 13 15:26:07 volumio volumio-remote-updater[534]: [2025-05-13 15:26:07] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] May 13 15:26:07 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE May 13 15:26:07 volumio sudo[13376]: pam_unix(sudo:session): session closed for user root May 13 15:26:07 volumio sudo[13394]: pam_unix(sudo:session): session closed for user root May 13 15:26:07 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. May 13 15:26:07 volumio systemd[1]: Started dynamicswap service. May 13 15:26:07 volumio systemd[1]: dynamicswap.service: Succeeded. May 13 15:26:08 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. May 13 15:26:08 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 49. May 13 15:26:08 volumio systemd[1]: Started dynamicswap service. May 13 15:26:08 volumio systemd[1]: Stopped Volumio Backend Module. May 13 15:26:08 volumio systemd[1]: Started Volumio Backend Module. May 13 15:26:08 volumio systemd[1]: dynamicswap.service: Succeeded. May 13 15:26:08 volumio mpd[13439]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 13 15:26:08 volumio mpd[13439]: output: No 'audio_output' defined in config file May 13 15:26:08 volumio mpd[13439]: output: Successfully detected a sndio audio device May 13 15:26:08 volumio mpd[13439]: zeroconf: No global port, disabling zeroconf May 13 15:26:08 volumio systemd[1]: Started Music Player Daemon. May 13 15:26:09 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 15:26:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. May 13 15:26:09 volumio systemd[1]: Stopped go-librespot Daemon. May 13 15:26:09 volumio systemd[1]: Started go-librespot Daemon. May 13 15:26:09 volumio go-librespot[13540]: Librespot-go daemon starting... May 13 15:26:09 volumio go-librespot[13540]: time="2025-05-13T15:26:09-04:00" level=info msg="generated new device id: 1dc42cabcc191294f888c1621ab69d6cc4d07c16" May 13 15:26:09 volumio go-librespot[13540]: time="2025-05-13T15:26:09-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 13 15:26:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 15:26:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 15:26:09 volumio volumio[13518]: info: ------------------------------------------- May 13 15:26:09 volumio volumio[13518]: info: ----- Volumio3 ---- May 13 15:26:09 volumio volumio[13518]: info: ------------------------------------------- May 13 15:26:09 volumio volumio[13518]: info: ----- System startup ---- May 13 15:26:09 volumio volumio[13518]: info: ------------------------------------------- May 13 15:26:09 volumio volumio[13518]: info: MYVOLUMIO Environment detected May 13 15:26:09 volumio volumio[13518]: info: Plugin folders cleanup May 13 15:26:09 volumio volumio[13518]: info: Scanning into folder /volumio/app/plugins/ May 13 15:26:09 volumio volumio[13518]: info: Scanning category audio_interface May 13 15:26:09 volumio volumio[13518]: info: Scanning category miscellanea May 13 15:26:09 volumio volumio[13518]: info: Scanning category music_service May 13 15:26:09 volumio volumio[13518]: info: Scanning category plugins.json May 13 15:26:09 volumio volumio[13518]: info: Scanning category system_controller May 13 15:26:09 volumio volumio[13518]: info: Scanning category user_interface May 13 15:26:09 volumio volumio[13518]: info: Scanning into folder /data/plugins/ May 13 15:26:09 volumio volumio[13518]: info: Scanning category music_service May 13 15:26:09 volumio volumio[13518]: info: Scanning category user_interface May 13 15:26:09 volumio volumio[13518]: info: Plugin folders cleanup completed May 13 15:26:09 volumio volumio[13518]: info: ------------------------------------------- May 13 15:26:09 volumio volumio[13518]: info: ----- Core plugins startup ---- May 13 15:26:09 volumio volumio[13518]: info: ------------------------------------------- May 13 15:26:09 volumio volumio[13518]: info: Loading plugins from folder /volumio/app/plugins/ May 13 15:26:09 volumio volumio[13518]: info: Adding plugin upnp to MyMusic Plugins May 13 15:26:09 volumio volumio[13518]: info: Adding plugin airplay_emulation to MyMusic Plugins May 13 15:26:09 volumio volumio[13518]: info: Adding plugin upnp_browser to MyMusic Plugins May 13 15:26:09 volumio volumio[13518]: info: Loading plugins from folder /data/plugins/ May 13 15:26:09 volumio volumio[13518]: info: Loading plugin "system"... May 13 15:26:09 volumio volumio[13518]: info: Loading plugin "appearance"... May 13 15:26:10 volumio volumio[13518]: info: Loading plugin "network"... May 13 15:26:10 volumio volumio[13518]: info: Refreshing Cached IP Addresses May 13 15:26:10 volumio sudo[13553]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 13 15:26:10 volumio sudo[13553]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:10 volumio volumio[13518]: info: Loading plugin "services"... May 13 15:26:10 volumio volumio[13518]: info: Loading plugin "alsa_controller"... May 13 15:26:10 volumio sudo[13555]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 13 15:26:10 volumio sudo[13553]: pam_unix(sudo:session): session closed for user root May 13 15:26:10 volumio sudo[13567]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 13 15:26:10 volumio sudo[13555]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:10 volumio sudo[13567]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:10 volumio sudo[13555]: pam_unix(sudo:session): session closed for user root May 13 15:26:10 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:26:10 volumio volumio[13518]: info: Loading plugin "wizard"... May 13 15:26:10 volumio volumio[13518]: info: Loading plugin "networkfs"... May 13 15:26:10 volumio volumio[13518]: info: Cannot mount NAS NAS at system boot, trial number 1 ,retrying in 5 seconds May 13 15:26:10 volumio volumio[13518]: info: Starting Udev Watcher for removable devices May 13 15:26:10 volumio volumio[13518]: info: Ignoring mount for partition: BOOT May 13 15:26:10 volumio volumio[13518]: info: Ignoring mount for partition: volumio May 13 15:26:10 volumio volumio[13518]: info: Ignoring mount for partition: volumio_data May 13 15:26:10 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:26:10 volumio volumio[13518]: info: Loading plugin "volumio_command_line_client"... May 13 15:26:10 volumio volumio[13518]: info: Loading plugin "upnp"... May 13 15:26:10 volumio volumio[13518]: info: [1747164370498] Starting Upmpd Daemon May 13 15:26:10 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:26:10 volumio volumio[13518]: info: Loading plugin "my_music"... May 13 15:26:10 volumio volumio[13518]: info: Loading plugin "mpd"... May 13 15:26:10 volumio volumio[13518]: info: Loading plugin "upnp_browser"... May 13 15:26:10 volumio volumio[13518]: info: Loading plugin "alarm-clock"... May 13 15:26:11 volumio volumio[13518]: info: Loading plugin "airplay_emulation"... May 13 15:26:11 volumio volumio[13518]: info: Starting Shairport Sync May 13 15:26:11 volumio volumio[13518]: info: Loading plugin "last_100"... May 13 15:26:11 volumio volumio[13518]: info: Loading plugin "webradio"... May 13 15:26:11 volumio volumio[13518]: info: Loading plugin "i2s_dacs"... May 13 15:26:11 volumio volumio[13518]: info: I2S DAC not set, start Auto-detection May 13 15:26:11 volumio volumio[13518]: info: Loading plugin "volumiodiscovery"... May 13 15:26:11 volumio volumio[13518]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 13 15:26:11 volumio volumio[13518]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:26:11 volumio volumio[13518]: *** WARNING *** For more information see May 13 15:26:11 volumio volumio[13518]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 13 15:26:11 volumio volumio[13518]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:26:11 volumio node[13518]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 13 15:26:11 volumio volumio[13518]: *** WARNING *** For more information see May 13 15:26:11 volumio node[13518]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:26:11 volumio node[13518]: *** WARNING *** For more information see May 13 15:26:11 volumio node[13518]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 13 15:26:11 volumio node[13518]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:26:11 volumio node[13518]: *** WARNING *** For more information see May 13 15:26:11 volumio volumio[13518]: info: Applying required configuration parameters for plugin volumiodiscovery May 13 15:26:11 volumio volumio[13518]: info: Discovery: Started advertising with name: Volumio May 13 15:26:11 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:26:11 volumio volumio[13518]: info: Loading plugin "spop"... May 13 15:26:11 volumio sudo[13567]: pam_unix(sudo:session): session closed for user root May 13 15:26:11 volumio volumio[13518]: info: Loading plugin "squeezelite_mc"... May 13 15:26:12 volumio volumio[13518]: info: Loading plugin "youtube2"... May 13 15:26:12 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 15:26:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. May 13 15:26:12 volumio systemd[1]: Stopped go-librespot Daemon. May 13 15:26:12 volumio systemd[1]: Started go-librespot Daemon. May 13 15:26:12 volumio go-librespot[13610]: Librespot-go daemon starting... May 13 15:26:12 volumio go-librespot[13610]: time="2025-05-13T15:26:12-04:00" level=info msg="generated new device id: fcf75b9fe151f2cf7bc3641d5e733e9a8740c74f" May 13 15:26:12 volumio go-librespot[13610]: time="2025-05-13T15:26:12-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 13 15:26:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 15:26:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 15:26:12 volumio volumio-remote-updater[534]: [2025-05-13 15:26:12] [connect] Successful connection May 13 15:26:12 volumio volumio[13518]: info: Loading plugin "now_playing"... May 13 15:26:13 volumio volumio[13518]: info: Loading plugin "outputs"... May 13 15:26:13 volumio volumio[13518]: info: Loading plugin "albumart"... May 13 15:26:13 volumio volumio[13518]: info: Plugin example_plugin is not enabled May 13 15:26:13 volumio volumio[13518]: info: Loading plugin "inputs"... May 13 15:26:13 volumio volumio[13518]: info: Loading plugin "updater_comm"... May 13 15:26:13 volumio volumio[13518]: info: Plugin mpdemulation is not enabled May 13 15:26:13 volumio volumio[13518]: info: Loading plugin "rest_api"... May 13 15:26:13 volumio volumio[13518]: info: Loading plugin "websocket"... May 13 15:26:13 volumio volumio[13518]: info: Starting Socket.io Server version 2.3.0 May 13 15:26:13 volumio volumio[13518]: info: Loading plugin "lms"... May 13 15:26:13 volumio volumio[13518]: info: Loading i18n strings for locale en May 13 15:26:13 volumio volumio[13518]: Updating browse sources language May 13 15:26:13 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:13 volumio volumio[13518]: Forking 3 albumart workers May 13 15:26:13 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:26:13 volumio volumio[13518]: info: CoreCommandRouter::initPlayerControls May 13 15:26:13 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:13 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:13 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:13 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:13 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:13 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:13 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:13 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:26:13 volumio volumio[13518]: Express server listening on port 3000 May 13 15:26:13 volumio volumio[13518]: [Metrics] WebUI: 4s 996.45ms May 13 15:26:13 volumio volumio[13518]: info: CoreStateMachine::resetVolumioState May 13 15:26:13 volumio volumio[13518]: info: CoreStateMachine::getcurrentVolume May 13 15:26:13 volumio volumio[13518]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:26:13 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:13 volumio volumio[13518]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' May 13 15:26:13 volumio volumio[13518]: info: Completed loading Core Plugins May 13 15:26:13 volumio volumio[13518]: info: Preparing to generate the ALSA configuration file May 13 15:26:13 volumio volumio[13518]: info: Volumio Network Manager: Network status updated: 0 May 13 15:26:13 volumio volumio-remote-updater[534]: [2025-05-13 15:26:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1747164372 101 May 13 15:26:14 volumio volumio[13518]: 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 May 13 15:26:14 volumio volumio[13518]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 2 May 13 15:26:14 volumio volumio[13518]: info: Reloading queue from file May 13 15:26:14 volumio volumio[13518]: info: Asound.conf file unchanged, so no further update is needed May 13 15:26:14 volumio volumio[13518]: info: Output device has changed, restarting MPD May 13 15:26:14 volumio volumio[13518]: info: Output device has changed, restarting Shairport Sync May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:14 volumio sudo[13658]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 13 15:26:14 volumio sudo[13656]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 13 15:26:14 volumio sudo[13658]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:14 volumio sudo[13656]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:14 volumio volumio[13518]: info: ___________ START PLUGINS ___________ May 13 15:26:14 volumio volumio[13518]: info: ControllerMpd::onStart: Initializing MPD May 13 15:26:14 volumio volumio[13518]: info: Creating MPD Configuration file May 13 15:26:14 volumio sudo[13656]: pam_unix(sudo:session): session closed for user root May 13 15:26:14 volumio systemd[1]: Stopping Music Player Daemon... May 13 15:26:14 volumio sudo[13674]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:26:14 volumio volumio[13518]: info: [1747164374294] CoreMusicLibrary::Adding element Media Servers May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:14 volumio sudo[13674]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:14 volumio sudo[13680]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 13 15:26:14 volumio sudo[13674]: pam_unix(sudo:session): session closed for user root May 13 15:26:14 volumio systemd[1]: mpd.service: Succeeded. May 13 15:26:14 volumio systemd[1]: Stopped Music Player Daemon. May 13 15:26:14 volumio systemd[1]: Starting Music Player Daemon... May 13 15:26:14 volumio sudo[13680]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:26:14 volumio volumio[13518]: info: [1747164374495] CoreMusicLibrary::Adding element Last_100 May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:14 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM May 13 15:26:14 volumio systemd[1]: mpd.service: Succeeded. May 13 15:26:14 volumio systemd[1]: Stopped Music Player Daemon. May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:26:14 volumio volumio[13518]: info: [1747164374501] CoreMusicLibrary::Adding element Webradio May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:14 volumio systemd[1]: Starting Music Player Daemon... May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:26:14 volumio volumio[13518]: info: Initializing BBC Radios May 13 15:26:14 volumio volumio[13518]: Starting albumart workers May 13 15:26:14 volumio volumio[13518]: Starting albumart workers May 13 15:26:14 volumio volumio[13518]: Starting albumart workers May 13 15:26:14 volumio sudo[13699]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 13 15:26:14 volumio sudo[13699]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:14 volumio sudo[13699]: pam_unix(sudo:session): session closed for user root May 13 15:26:14 volumio volumio[13518]: info: Creating Spotify config file May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:14 volumio volumio[13518]: info: [squeezelite_mc] Starting proxy server... May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:26:14 volumio volumio[13518]: info: [1747164374718] CoreMusicLibrary::Adding element YouTube2 May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:14 volumio volumio[13518]: Cannot find translation for source YouTube2 May 13 15:26:14 volumio volumio[13518]: info: [now-playing-config] Config is up to date. May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 13 15:26:14 volumio volumio[13518]: info: Discovery: Getting this device information May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::volumioGetState May 13 15:26:14 volumio volumio[13518]: info: CorePlayQueue::getTrack 0 May 13 15:26:14 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 13 15:26:14 volumio volumio[13518]: info: Volumio Calling Home May 13 15:26:14 volumio sudo[13720]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver May 13 15:26:14 volumio sudo[13720]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:14 volumio volumio[13518]: info: [squeezelite_mc] Proxy server started on port 41333 May 13 15:26:14 volumio systemd[1]: Starting Logitech Media Server Daemon... May 13 15:26:14 volumio volumio[13518]: info: [now-playing-app] App is listening on port 4004. May 13 15:26:14 volumio systemd[1]: Started Logitech Media Server Daemon. May 13 15:26:14 volumio sudo[13720]: pam_unix(sudo:session): session closed for user root May 13 15:26:15 volumio systemd[13731]: logitechmediaserver.service: Failed to execute command: No such file or directory May 13 15:26:15 volumio systemd[13731]: logitechmediaserver.service: Failed at step EXEC spawning /usr/sbin/squeezeboxserver: No such file or directory May 13 15:26:15 volumio systemd[1]: logitechmediaserver.service: Main process exited, code=exited, status=203/EXEC May 13 15:26:15 volumio systemd[1]: logitechmediaserver.service: Failed with result 'exit-code'. May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:26:15 volumio volumio[13518]: info: CoreStateMachine::setRepeat false single undefined May 13 15:26:15 volumio volumio[13518]: info: CoreStateMachine::pushState May 13 15:26:15 volumio volumio[13518]: info: CorePlayQueue::getTrack 0 May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::volumioPushState May 13 15:26:15 volumio volumio[13518]: info: CoreStateMachine::setRandom undefined May 13 15:26:15 volumio volumio[13518]: info: CoreStateMachine::pushState May 13 15:26:15 volumio volumio[13518]: info: CorePlayQueue::getTrack 0 May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::volumioPushState May 13 15:26:15 volumio volumio[13518]: info: Setting Device type: Tinkerboard May 13 15:26:15 volumio volumio[13518]: info: VolumeController:: Volume=100 Mute =false May 13 15:26:15 volumio volumio[13518]: info: CoreStateMachine::pushState May 13 15:26:15 volumio volumio[13518]: info: CorePlayQueue::getTrack 0 May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::volumioPushState May 13 15:26:15 volumio volumio[13518]: info: CoreStateMachine::updateTrackBlock May 13 15:26:15 volumio volumio[13518]: info: CorePlayQueue::getTrackBlock May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:26:15 volumio volumio[13518]: Unhandled rejection Error: No sockets available, cannot start. May 13 15:26:15 volumio volumio[13518]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) May 13 15:26:15 volumio volumio[13518]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) May 13 15:26:15 volumio volumio[13518]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 May 13 15:26:15 volumio volumio[13518]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) May 13 15:26:15 volumio volumio[13518]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) May 13 15:26:15 volumio volumio[13518]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) May 13 15:26:15 volumio volumio[13518]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) May 13 15:26:15 volumio volumio[13518]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) May 13 15:26:15 volumio volumio[13518]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) May 13 15:26:15 volumio volumio[13518]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) May 13 15:26:15 volumio volumio[13518]: at HashMap. (/volumio/app/pluginmanager.js:496:31) May 13 15:26:15 volumio volumio[13518]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) May 13 15:26:15 volumio volumio[13518]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) May 13 15:26:15 volumio volumio[13518]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) May 13 15:26:15 volumio volumio[13518]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) May 13 15:26:15 volumio volumio[13518]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 13 15:26:15 volumio volumio[13518]: info: logitechmediaserver started May 13 15:26:15 volumio volumio[13518]: info: MPD Permissions set May 13 15:26:15 volumio volumio[13518]: info: MPD Permissions set May 13 15:26:15 volumio volumio[13518]: info: Spotify config file written May 13 15:26:15 volumio volumio[13518]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 13 15:26:15 volumio sudo[13763]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio sudo[13763]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 13 15:26:15 volumio systemd[1]: Stopped go-librespot Daemon. May 13 15:26:15 volumio systemd[1]: Started go-librespot Daemon. May 13 15:26:15 volumio sudo[13763]: pam_unix(sudo:session): session closed for user root May 13 15:26:15 volumio go-librespot[13775]: Librespot-go daemon starting... May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio go-librespot[13775]: time="2025-05-13T15:26:15-04:00" level=info msg="generated new device id: 1d838aa8801c8179c89da10705c1b844c129afb6" May 13 15:26:15 volumio go-librespot[13775]: time="2025-05-13T15:26:15-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 13 15:26:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 15:26:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: No need to fix Spotify hosts May 13 15:26:15 volumio volumio[13518]: info: VolumeController:: Volume=100 Mute =false May 13 15:26:15 volumio volumio[13518]: info: CoreStateMachine::pushState May 13 15:26:15 volumio volumio[13518]: info: CorePlayQueue::getTrack 0 May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::volumioPushState May 13 15:26:15 volumio volumio[13518]: info: [squeezelite_mc] Server discovery started May 13 15:26:15 volumio volumio[13518]: info: [squeezelite_mc] Player finder started May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:26:15 volumio volumio[13518]: info: [squeezelite_mc] Executing aplay -D hw:0 --nonblock -f MPEG /dev/zero 2>&1 || true May 13 15:26:15 volumio volumio[13518]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 15:26:15 volumio volumio[13518]: Error: send ENETUNREACH 255.255.255.255:3483 May 13 15:26:15 volumio volumio[13518]: at doSend (dgram.js:714:16) May 13 15:26:15 volumio volumio[13518]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:452:18) May 13 15:26:15 volumio volumio[13518]: at afterDns (dgram.js:660:5) May 13 15:26:15 volumio volumio[13518]: at processTicksAndRejections (internal/process/task_queues.js:83:21) { May 13 15:26:15 volumio volumio[13518]: errno: -101, May 13 15:26:15 volumio volumio[13518]: code: 'ENETUNREACH', May 13 15:26:15 volumio volumio[13518]: syscall: 'send', May 13 15:26:15 volumio volumio[13518]: address: '255.255.255.255', May 13 15:26:15 volumio volumio[13518]: port: 3483 May 13 15:26:15 volumio volumio[13518]: } May 13 15:26:15 volumio volumio[13518]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 15:26:15 volumio ntpd[815]: Soliciting pool server 45.79.51.42 May 13 15:26:15 volumio ntpd[815]: error resolving pool 2.debian.pool.ntp.org: System error (-11) May 13 15:26:15 volumio sudo[13804]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-13 15:25 May 13 15:26:15 volumio sudo[13804]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:15 volumio sudo[13804]: pam_unix(sudo:session): session closed for user root May 13 15:26:16 volumio volumio-remote-updater[534]: [2025-05-13 15:26:16] [error] handle_read_frame error: websocketpp.transport:7 (End of File) May 13 15:26:16 volumio volumio-remote-updater[534]: [2025-05-13 15:26:16] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] May 13 15:26:16 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE May 13 15:26:16 volumio sudo[13680]: pam_unix(sudo:session): session closed for user root May 13 15:26:16 volumio sudo[13658]: pam_unix(sudo:session): session closed for user root May 13 15:26:16 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. May 13 15:26:16 volumio systemd[1]: Started dynamicswap service. May 13 15:26:16 volumio systemd[1]: dynamicswap.service: Succeeded. May 13 15:26:16 volumio mpd[13724]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 13 15:26:16 volumio mpd[13724]: output: No 'audio_output' defined in config file May 13 15:26:16 volumio mpd[13724]: output: Successfully detected a sndio audio device May 13 15:26:16 volumio mpd[13724]: zeroconf: No global port, disabling zeroconf May 13 15:26:16 volumio systemd[1]: Started Music Player Daemon. May 13 15:26:16 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. May 13 15:26:16 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 50. May 13 15:26:16 volumio systemd[1]: Stopped Volumio Backend Module. May 13 15:26:16 volumio systemd[1]: Started Volumio Backend Module. May 13 15:26:16 volumio systemd[1]: Started dynamicswap service. May 13 15:26:16 volumio systemd[1]: dynamicswap.service: Succeeded. May 13 15:26:17 volumio volumio[13833]: info: ------------------------------------------- May 13 15:26:17 volumio volumio[13833]: info: ----- Volumio3 ---- May 13 15:26:17 volumio volumio[13833]: info: ------------------------------------------- May 13 15:26:17 volumio volumio[13833]: info: ----- System startup ---- May 13 15:26:17 volumio volumio[13833]: info: ------------------------------------------- May 13 15:26:17 volumio volumio[13833]: info: MYVOLUMIO Environment detected May 13 15:26:17 volumio volumio[13833]: info: Plugin folders cleanup May 13 15:26:17 volumio volumio[13833]: info: Scanning into folder /volumio/app/plugins/ May 13 15:26:17 volumio volumio[13833]: info: Scanning category audio_interface May 13 15:26:17 volumio volumio[13833]: info: Scanning category miscellanea May 13 15:26:17 volumio volumio[13833]: info: Scanning category music_service May 13 15:26:17 volumio volumio[13833]: info: Scanning category plugins.json May 13 15:26:17 volumio volumio[13833]: info: Scanning category system_controller May 13 15:26:17 volumio volumio[13833]: info: Scanning category user_interface May 13 15:26:17 volumio volumio[13833]: info: Scanning into folder /data/plugins/ May 13 15:26:17 volumio volumio[13833]: info: Scanning category music_service May 13 15:26:17 volumio volumio[13833]: info: Scanning category user_interface May 13 15:26:17 volumio volumio[13833]: info: Plugin folders cleanup completed May 13 15:26:17 volumio volumio[13833]: info: ------------------------------------------- May 13 15:26:17 volumio volumio[13833]: info: ----- Core plugins startup ---- May 13 15:26:17 volumio volumio[13833]: info: ------------------------------------------- May 13 15:26:17 volumio volumio[13833]: info: Loading plugins from folder /volumio/app/plugins/ May 13 15:26:17 volumio volumio[13833]: info: Adding plugin upnp to MyMusic Plugins May 13 15:26:17 volumio volumio[13833]: info: Adding plugin airplay_emulation to MyMusic Plugins May 13 15:26:17 volumio volumio[13833]: info: Adding plugin upnp_browser to MyMusic Plugins May 13 15:26:17 volumio volumio[13833]: info: Loading plugins from folder /data/plugins/ May 13 15:26:17 volumio volumio[13833]: info: Loading plugin "system"... May 13 15:26:17 volumio volumio[13833]: info: Loading plugin "appearance"... May 13 15:26:18 volumio volumio[13833]: info: Loading plugin "network"... May 13 15:26:18 volumio volumio[13833]: info: Refreshing Cached IP Addresses May 13 15:26:18 volumio sudo[13860]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 13 15:26:18 volumio sudo[13862]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 13 15:26:18 volumio volumio[13833]: info: Loading plugin "services"... May 13 15:26:18 volumio sudo[13860]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:18 volumio volumio[13833]: info: Loading plugin "alsa_controller"... May 13 15:26:18 volumio sudo[13862]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:18 volumio sudo[13860]: pam_unix(sudo:session): session closed for user root May 13 15:26:18 volumio sudo[13862]: pam_unix(sudo:session): session closed for user root May 13 15:26:18 volumio sudo[13875]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 13 15:26:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 15:26:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. May 13 15:26:18 volumio systemd[1]: Stopped go-librespot Daemon. May 13 15:26:18 volumio systemd[1]: Started go-librespot Daemon. May 13 15:26:18 volumio sudo[13875]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:18 volumio go-librespot[13900]: Librespot-go daemon starting... May 13 15:26:18 volumio go-librespot[13900]: time="2025-05-13T15:26:18-04:00" level=info msg="generated new device id: 49617002593300955f588d8c8e04dee2a6b4d0ac" May 13 15:26:18 volumio go-librespot[13900]: time="2025-05-13T15:26:18-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 13 15:26:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 15:26:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 15:26:18 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:26:18 volumio volumio[13833]: info: Loading plugin "wizard"... May 13 15:26:18 volumio volumio[13833]: info: Loading plugin "networkfs"... May 13 15:26:18 volumio volumio[13833]: info: Cannot mount NAS NAS at system boot, trial number 1 ,retrying in 5 seconds May 13 15:26:18 volumio volumio[13833]: info: Starting Udev Watcher for removable devices May 13 15:26:18 volumio volumio[13833]: info: Ignoring mount for partition: BOOT May 13 15:26:18 volumio volumio[13833]: info: Ignoring mount for partition: volumio May 13 15:26:18 volumio volumio[13833]: info: Ignoring mount for partition: volumio_data May 13 15:26:18 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:26:18 volumio volumio[13833]: info: Loading plugin "volumio_command_line_client"... May 13 15:26:18 volumio volumio[13833]: info: Loading plugin "upnp"... May 13 15:26:18 volumio volumio[13833]: info: [1747164378734] Starting Upmpd Daemon May 13 15:26:18 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:26:18 volumio volumio[13833]: info: Loading plugin "my_music"... May 13 15:26:18 volumio volumio[13833]: info: Loading plugin "mpd"... May 13 15:26:18 volumio volumio[13833]: info: Loading plugin "upnp_browser"... May 13 15:26:19 volumio volumio[13833]: info: Loading plugin "alarm-clock"... May 13 15:26:19 volumio volumio[13833]: info: Loading plugin "airplay_emulation"... May 13 15:26:19 volumio volumio[13833]: info: Starting Shairport Sync May 13 15:26:19 volumio volumio[13833]: info: Loading plugin "last_100"... May 13 15:26:19 volumio volumio[13833]: info: Loading plugin "webradio"... May 13 15:26:19 volumio volumio[13833]: info: Loading plugin "i2s_dacs"... May 13 15:26:19 volumio volumio[13833]: info: I2S DAC not set, start Auto-detection May 13 15:26:19 volumio volumio[13833]: info: Loading plugin "volumiodiscovery"... May 13 15:26:19 volumio volumio[13833]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 13 15:26:19 volumio volumio[13833]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:26:19 volumio volumio[13833]: *** WARNING *** For more information see May 13 15:26:19 volumio volumio[13833]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 13 15:26:19 volumio volumio[13833]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:26:19 volumio node[13833]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 13 15:26:19 volumio volumio[13833]: *** WARNING *** For more information see May 13 15:26:19 volumio node[13833]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:26:19 volumio node[13833]: *** WARNING *** For more information see May 13 15:26:19 volumio node[13833]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 13 15:26:19 volumio node[13833]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:26:19 volumio node[13833]: *** WARNING *** For more information see May 13 15:26:19 volumio volumio[13833]: info: Applying required configuration parameters for plugin volumiodiscovery May 13 15:26:19 volumio volumio[13833]: info: Discovery: Started advertising with name: Volumio May 13 15:26:19 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:26:19 volumio volumio[13833]: info: Loading plugin "spop"... May 13 15:26:19 volumio volumio[13833]: info: Loading plugin "squeezelite_mc"... May 13 15:26:19 volumio sudo[13875]: pam_unix(sudo:session): session closed for user root May 13 15:26:20 volumio volumio[13833]: info: Loading plugin "youtube2"... May 13 15:26:20 volumio volumio[13833]: info: Loading plugin "now_playing"... May 13 15:26:21 volumio volumio-remote-updater[534]: [2025-05-13 15:26:21] [connect] Successful connection May 13 15:26:21 volumio volumio[13833]: info: Loading plugin "outputs"... May 13 15:26:21 volumio volumio[13833]: info: Loading plugin "albumart"... May 13 15:26:21 volumio volumio[13833]: info: Plugin example_plugin is not enabled May 13 15:26:21 volumio volumio[13833]: info: Loading plugin "inputs"... May 13 15:26:21 volumio volumio[13833]: info: Loading plugin "updater_comm"... May 13 15:26:21 volumio volumio[13833]: info: Plugin mpdemulation is not enabled May 13 15:26:21 volumio volumio[13833]: info: Loading plugin "rest_api"... May 13 15:26:21 volumio volumio[13833]: info: Loading plugin "websocket"... May 13 15:26:21 volumio volumio[13833]: info: Starting Socket.io Server version 2.3.0 May 13 15:26:21 volumio volumio[13833]: info: Loading plugin "lms"... May 13 15:26:21 volumio volumio[13833]: info: Loading i18n strings for locale en May 13 15:26:21 volumio volumio[13833]: Updating browse sources language May 13 15:26:21 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:21 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 15:26:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. May 13 15:26:21 volumio systemd[1]: Stopped go-librespot Daemon. May 13 15:26:21 volumio systemd[1]: Started go-librespot Daemon. May 13 15:26:21 volumio go-librespot[13932]: Librespot-go daemon starting... May 13 15:26:21 volumio volumio[13833]: Forking 3 albumart workers May 13 15:26:21 volumio go-librespot[13932]: time="2025-05-13T15:26:21-04:00" level=info msg="generated new device id: c09620d57f30c83cc8aae50f964dda4d02efdedb" May 13 15:26:21 volumio go-librespot[13932]: time="2025-05-13T15:26:21-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 13 15:26:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 15:26:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 15:26:21 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:26:21 volumio volumio[13833]: info: CoreCommandRouter::initPlayerControls May 13 15:26:21 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:21 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:21 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:21 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:26:21 volumio volumio[13833]: Express server listening on port 3000 May 13 15:26:21 volumio volumio[13833]: [Metrics] WebUI: 4s 888.18ms May 13 15:26:21 volumio volumio[13833]: info: CoreStateMachine::resetVolumioState May 13 15:26:21 volumio volumio[13833]: info: CoreStateMachine::getcurrentVolume May 13 15:26:21 volumio volumio[13833]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:26:21 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:22 volumio volumio[13833]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' May 13 15:26:22 volumio volumio[13833]: info: Completed loading Core Plugins May 13 15:26:22 volumio volumio[13833]: info: Preparing to generate the ALSA configuration file May 13 15:26:22 volumio volumio[13833]: info: Volumio Network Manager: Network status updated: 0 May 13 15:26:22 volumio volumio[13833]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 1 May 13 15:26:22 volumio volumio-remote-updater[534]: [2025-05-13 15:26:22] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1747164381 101 May 13 15:26:22 volumio volumio[13833]: 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: 2 May 13 15:26:22 volumio volumio[13833]: info: Reloading queue from file May 13 15:26:22 volumio volumio[13833]: info: Asound.conf file unchanged, so no further update is needed May 13 15:26:22 volumio volumio[13833]: info: Output device has changed, restarting MPD May 13 15:26:22 volumio volumio[13833]: info: Output device has changed, restarting Shairport Sync May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:22 volumio sudo[13971]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 13 15:26:22 volumio sudo[13971]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:22 volumio sudo[13971]: pam_unix(sudo:session): session closed for user root May 13 15:26:22 volumio sudo[13973]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 13 15:26:22 volumio volumio[13833]: info: ___________ START PLUGINS ___________ May 13 15:26:22 volumio volumio[13833]: info: ControllerMpd::onStart: Initializing MPD May 13 15:26:22 volumio volumio[13833]: info: Creating MPD Configuration file May 13 15:26:22 volumio sudo[13973]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:26:22 volumio volumio[13833]: info: [1747164382370] CoreMusicLibrary::Adding element Media Servers May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:22 volumio systemd[1]: Stopping Music Player Daemon... May 13 15:26:22 volumio sudo[13990]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:22 volumio sudo[13990]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:22 volumio sudo[13992]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:22 volumio systemd[1]: mpd.service: Succeeded. May 13 15:26:22 volumio systemd[1]: Stopped Music Player Daemon. May 13 15:26:22 volumio systemd[1]: Starting Music Player Daemon... May 13 15:26:22 volumio sudo[13990]: pam_unix(sudo:session): session closed for user root May 13 15:26:22 volumio sudo[13992]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:26:22 volumio volumio[13833]: info: [1747164382559] CoreMusicLibrary::Adding element Last_100 May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:26:22 volumio volumio[13833]: info: [1747164382562] CoreMusicLibrary::Adding element Webradio May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:26:22 volumio volumio[13833]: info: Initializing BBC Radios May 13 15:26:22 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM May 13 15:26:22 volumio systemd[1]: mpd.service: Succeeded. May 13 15:26:22 volumio systemd[1]: Stopped Music Player Daemon. May 13 15:26:22 volumio systemd[1]: Starting Music Player Daemon... May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:22 volumio volumio[13833]: info: Creating Spotify config file May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:22 volumio volumio[13833]: Starting albumart workers May 13 15:26:22 volumio volumio[13833]: info: [squeezelite_mc] Starting proxy server... May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:26:22 volumio volumio[13833]: info: [1747164382706] CoreMusicLibrary::Adding element YouTube2 May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:22 volumio volumio[13833]: Cannot find translation for source YouTube2 May 13 15:26:22 volumio volumio[13833]: Starting albumart workers May 13 15:26:22 volumio volumio[13833]: info: [now-playing-config] Config is up to date. May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 13 15:26:22 volumio volumio[13833]: info: Discovery: Getting this device information May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::volumioGetState May 13 15:26:22 volumio volumio[13833]: info: CorePlayQueue::getTrack 0 May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 13 15:26:22 volumio volumio[13833]: info: Volumio Calling Home May 13 15:26:22 volumio sudo[14019]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 13 15:26:22 volumio sudo[14019]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:22 volumio sudo[14028]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver May 13 15:26:22 volumio sudo[14028]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:22 volumio sudo[14019]: pam_unix(sudo:session): session closed for user root May 13 15:26:22 volumio volumio[13833]: Starting albumart workers May 13 15:26:22 volumio volumio[13833]: info: [squeezelite_mc] Proxy server started on port 34842 May 13 15:26:22 volumio volumio[13833]: info: [now-playing-app] App is listening on port 4004. May 13 15:26:22 volumio systemd[1]: Starting Logitech Media Server Daemon... May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:26:22 volumio systemd[1]: Started Logitech Media Server Daemon. May 13 15:26:22 volumio sudo[14028]: pam_unix(sudo:session): session closed for user root May 13 15:26:22 volumio systemd[14046]: logitechmediaserver.service: Failed to execute command: No such file or directory May 13 15:26:22 volumio systemd[14046]: logitechmediaserver.service: Failed at step EXEC spawning /usr/sbin/squeezeboxserver: No such file or directory May 13 15:26:22 volumio systemd[1]: logitechmediaserver.service: Main process exited, code=exited, status=203/EXEC May 13 15:26:22 volumio systemd[1]: logitechmediaserver.service: Failed with result 'exit-code'. May 13 15:26:22 volumio volumio[13833]: info: CoreStateMachine::setRepeat false single undefined May 13 15:26:22 volumio volumio[13833]: info: CoreStateMachine::pushState May 13 15:26:22 volumio volumio[13833]: info: CorePlayQueue::getTrack 0 May 13 15:26:22 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::volumioPushState May 13 15:26:23 volumio volumio[13833]: info: CoreStateMachine::setRandom undefined May 13 15:26:23 volumio volumio[13833]: info: CoreStateMachine::pushState May 13 15:26:23 volumio volumio[13833]: info: CorePlayQueue::getTrack 0 May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::volumioPushState May 13 15:26:23 volumio volumio[13833]: info: Setting Device type: Tinkerboard May 13 15:26:23 volumio volumio[13833]: info: VolumeController:: Volume=100 Mute =false May 13 15:26:23 volumio volumio[13833]: info: CoreStateMachine::pushState May 13 15:26:23 volumio volumio[13833]: info: CorePlayQueue::getTrack 0 May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::volumioPushState May 13 15:26:23 volumio volumio[13833]: info: CoreStateMachine::updateTrackBlock May 13 15:26:23 volumio volumio[13833]: info: CorePlayQueue::getTrackBlock May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:26:23 volumio volumio[13833]: Unhandled rejection Error: No sockets available, cannot start. May 13 15:26:23 volumio volumio[13833]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) May 13 15:26:23 volumio volumio[13833]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) May 13 15:26:23 volumio volumio[13833]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 May 13 15:26:23 volumio volumio[13833]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) May 13 15:26:23 volumio volumio[13833]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) May 13 15:26:23 volumio volumio[13833]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) May 13 15:26:23 volumio volumio[13833]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) May 13 15:26:23 volumio volumio[13833]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) May 13 15:26:23 volumio volumio[13833]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) May 13 15:26:23 volumio volumio[13833]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) May 13 15:26:23 volumio volumio[13833]: at HashMap. (/volumio/app/pluginmanager.js:496:31) May 13 15:26:23 volumio volumio[13833]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) May 13 15:26:23 volumio volumio[13833]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) May 13 15:26:23 volumio volumio[13833]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) May 13 15:26:23 volumio volumio[13833]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) May 13 15:26:23 volumio volumio[13833]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 13 15:26:23 volumio volumio[13833]: info: logitechmediaserver started May 13 15:26:23 volumio volumio[13833]: info: MPD Permissions set May 13 15:26:23 volumio volumio[13833]: info: Spotify config file written May 13 15:26:23 volumio volumio[13833]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 13 15:26:23 volumio sudo[14064]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio sudo[14064]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 13 15:26:23 volumio systemd[1]: Stopped go-librespot Daemon. May 13 15:26:23 volumio systemd[1]: Started go-librespot Daemon. May 13 15:26:23 volumio sudo[14064]: pam_unix(sudo:session): session closed for user root May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: No need to fix Spotify hosts May 13 15:26:23 volumio go-librespot[14081]: Librespot-go daemon starting... May 13 15:26:23 volumio go-librespot[14081]: time="2025-05-13T15:26:23-04:00" level=info msg="generated new device id: e801eb2bc04088336d50f658632ae3e0cd9d5201" May 13 15:26:23 volumio go-librespot[14081]: time="2025-05-13T15:26:23-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 13 15:26:23 volumio volumio[13833]: info: VolumeController:: Volume=100 Mute =false May 13 15:26:23 volumio volumio[13833]: info: CoreStateMachine::pushState May 13 15:26:23 volumio volumio[13833]: info: CorePlayQueue::getTrack 0 May 13 15:26:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 15:26:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::volumioPushState May 13 15:26:23 volumio volumio[13833]: info: [squeezelite_mc] Server discovery started May 13 15:26:23 volumio volumio[13833]: info: [squeezelite_mc] Player finder started May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:26:23 volumio volumio[13833]: info: [squeezelite_mc] Executing aplay -D hw:0 --nonblock -f MPEG /dev/zero 2>&1 || true May 13 15:26:23 volumio volumio[13833]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 15:26:23 volumio volumio[13833]: Error: send ENETUNREACH 255.255.255.255:3483 May 13 15:26:23 volumio volumio[13833]: at doSend (dgram.js:714:16) May 13 15:26:23 volumio volumio[13833]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:452:18) May 13 15:26:23 volumio volumio[13833]: at afterDns (dgram.js:660:5) May 13 15:26:23 volumio volumio[13833]: at processTicksAndRejections (internal/process/task_queues.js:83:21) { May 13 15:26:23 volumio volumio[13833]: errno: -101, May 13 15:26:23 volumio volumio[13833]: code: 'ENETUNREACH', May 13 15:26:23 volumio volumio[13833]: syscall: 'send', May 13 15:26:23 volumio volumio[13833]: address: '255.255.255.255', May 13 15:26:23 volumio volumio[13833]: port: 3483 May 13 15:26:23 volumio volumio[13833]: } May 13 15:26:23 volumio volumio[13833]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 15:26:23 volumio sudo[14119]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-13 15:25 May 13 15:26:23 volumio sudo[14119]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:24 volumio sudo[14119]: pam_unix(sudo:session): session closed for user root May 13 15:26:24 volumio volumio-remote-updater[534]: [2025-05-13 15:26:24] [error] handle_read_frame error: websocketpp.transport:7 (End of File) May 13 15:26:24 volumio volumio-remote-updater[534]: [2025-05-13 15:26:24] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] May 13 15:26:24 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE May 13 15:26:24 volumio sudo[13973]: pam_unix(sudo:session): session closed for user root May 13 15:26:24 volumio sudo[13992]: pam_unix(sudo:session): session closed for user root May 13 15:26:24 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. May 13 15:26:24 volumio systemd[1]: Started dynamicswap service. May 13 15:26:24 volumio systemd[1]: dynamicswap.service: Succeeded. May 13 15:26:24 volumio mpd[14044]: decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 13 15:26:24 volumio mpd[14044]: output: No 'audio_output' defined in config file May 13 15:26:24 volumio mpd[14044]: output: Successfully detected a sndio audio device May 13 15:26:24 volumio mpd[14044]: zeroconf: No global port, disabling zeroconf May 13 15:26:24 volumio systemd[1]: Started Music Player Daemon. May 13 15:26:24 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. May 13 15:26:24 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 51. May 13 15:26:24 volumio systemd[1]: Stopped Volumio Backend Module. May 13 15:26:24 volumio systemd[1]: Started Volumio Backend Module. May 13 15:26:24 volumio systemd[1]: Started dynamicswap service. May 13 15:26:24 volumio systemd[1]: dynamicswap.service: Succeeded. May 13 15:26:25 volumio volumio[14148]: info: ------------------------------------------- May 13 15:26:25 volumio volumio[14148]: info: ----- Volumio3 ---- May 13 15:26:25 volumio volumio[14148]: info: ------------------------------------------- May 13 15:26:25 volumio volumio[14148]: info: ----- System startup ---- May 13 15:26:25 volumio volumio[14148]: info: ------------------------------------------- May 13 15:26:25 volumio volumio[14148]: info: MYVOLUMIO Environment detected May 13 15:26:25 volumio volumio[14148]: info: Plugin folders cleanup May 13 15:26:25 volumio volumio[14148]: info: Scanning into folder /volumio/app/plugins/ May 13 15:26:25 volumio volumio[14148]: info: Scanning category audio_interface May 13 15:26:25 volumio volumio[14148]: info: Scanning category miscellanea May 13 15:26:25 volumio volumio[14148]: info: Scanning category music_service May 13 15:26:25 volumio volumio[14148]: info: Scanning category plugins.json May 13 15:26:25 volumio volumio[14148]: info: Scanning category system_controller May 13 15:26:25 volumio volumio[14148]: info: Scanning category user_interface May 13 15:26:25 volumio volumio[14148]: info: Scanning into folder /data/plugins/ May 13 15:26:25 volumio volumio[14148]: info: Scanning category music_service May 13 15:26:25 volumio volumio[14148]: info: Scanning category user_interface May 13 15:26:25 volumio volumio[14148]: info: Plugin folders cleanup completed May 13 15:26:25 volumio volumio[14148]: info: ------------------------------------------- May 13 15:26:25 volumio volumio[14148]: info: ----- Core plugins startup ---- May 13 15:26:25 volumio volumio[14148]: info: ------------------------------------------- May 13 15:26:25 volumio volumio[14148]: info: Loading plugins from folder /volumio/app/plugins/ May 13 15:26:25 volumio volumio[14148]: info: Adding plugin upnp to MyMusic Plugins May 13 15:26:25 volumio volumio[14148]: info: Adding plugin airplay_emulation to MyMusic Plugins May 13 15:26:25 volumio volumio[14148]: info: Adding plugin upnp_browser to MyMusic Plugins May 13 15:26:25 volumio volumio[14148]: info: Loading plugins from folder /data/plugins/ May 13 15:26:25 volumio volumio[14148]: info: Loading plugin "system"... May 13 15:26:25 volumio volumio[14148]: info: Loading plugin "appearance"... May 13 15:26:26 volumio volumio[14148]: info: Loading plugin "network"... May 13 15:26:26 volumio volumio[14148]: info: Refreshing Cached IP Addresses May 13 15:26:26 volumio sudo[14175]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 13 15:26:26 volumio sudo[14177]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 13 15:26:26 volumio volumio[14148]: info: Loading plugin "services"... May 13 15:26:26 volumio volumio[14148]: info: Loading plugin "alsa_controller"... May 13 15:26:26 volumio sudo[14175]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:26 volumio sudo[14177]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:26 volumio sudo[14188]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 13 15:26:26 volumio sudo[14175]: pam_unix(sudo:session): session closed for user root May 13 15:26:26 volumio sudo[14177]: pam_unix(sudo:session): session closed for user root May 13 15:26:26 volumio sudo[14188]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:26 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:26:26 volumio volumio[14148]: info: Loading plugin "wizard"... May 13 15:26:26 volumio volumio[14148]: info: Loading plugin "networkfs"... May 13 15:26:26 volumio volumio[14148]: info: Cannot mount NAS NAS at system boot, trial number 1 ,retrying in 5 seconds May 13 15:26:26 volumio volumio[14148]: info: Starting Udev Watcher for removable devices May 13 15:26:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 15:26:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. May 13 15:26:26 volumio systemd[1]: Stopped go-librespot Daemon. May 13 15:26:26 volumio systemd[1]: Started go-librespot Daemon. May 13 15:26:26 volumio go-librespot[14224]: Librespot-go daemon starting... May 13 15:26:26 volumio go-librespot[14224]: time="2025-05-13T15:26:26-04:00" level=info msg="generated new device id: 3c5b40d29f61a1b7036a0e0b6877d355f22460d5" May 13 15:26:26 volumio volumio[14148]: info: Ignoring mount for partition: BOOT May 13 15:26:26 volumio volumio[14148]: info: Ignoring mount for partition: volumio May 13 15:26:26 volumio volumio[14148]: info: Ignoring mount for partition: volumio_data May 13 15:26:26 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:26:26 volumio volumio[14148]: info: Loading plugin "volumio_command_line_client"... May 13 15:26:26 volumio go-librespot[14224]: time="2025-05-13T15:26:26-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 13 15:26:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 15:26:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 15:26:26 volumio volumio[14148]: info: Loading plugin "upnp"... May 13 15:26:26 volumio volumio[14148]: info: [1747164386633] Starting Upmpd Daemon May 13 15:26:26 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:26:26 volumio volumio[14148]: info: Loading plugin "my_music"... May 13 15:26:26 volumio volumio[14148]: info: Loading plugin "mpd"... May 13 15:26:26 volumio wpa_supplicant[948]: wlan0: Trying to associate with 3c:f0:83:37:4c:a1 (SSID='FamilyNet' freq=2412 MHz) May 13 15:26:26 volumio volumio[14148]: info: Loading plugin "upnp_browser"... May 13 15:26:26 volumio sudo[14188]: pam_unix(sudo:session): session closed for user root May 13 15:26:27 volumio volumio[14148]: info: Loading plugin "alarm-clock"... May 13 15:26:27 volumio volumio[14148]: info: Loading plugin "airplay_emulation"... May 13 15:26:27 volumio volumio[14148]: info: Starting Shairport Sync May 13 15:26:27 volumio volumio[14148]: info: Loading plugin "last_100"... May 13 15:26:27 volumio volumio[14148]: info: Loading plugin "webradio"... May 13 15:26:27 volumio wpa_supplicant[948]: wlan0: Associated with 3c:f0:83:37:4c:a1 May 13 15:26:27 volumio wpa_supplicant[948]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 May 13 15:26:27 volumio wpa_supplicant[948]: wlan0: WPA: Key negotiation completed with 3c:f0:83:37:4c:a1 [PTK=CCMP GTK=CCMP] May 13 15:26:27 volumio wpa_supplicant[948]: wlan0: CTRL-EVENT-CONNECTED - Connection to 3c:f0:83:37:4c:a1 completed [id=0 id_str=] May 13 15:26:27 volumio dhcpcd[1034]: wlan0: carrier acquired May 13 15:26:27 volumio dhcpcd[1034]: wlan0: IAID d3:20:40:59 May 13 15:26:27 volumio dhcpcd[1034]: wlan0: probing address 192.168.1.5/24 May 13 15:26:27 volumio volumio[14148]: info: Loading plugin "i2s_dacs"... May 13 15:26:27 volumio volumio[14148]: info: I2S DAC not set, start Auto-detection May 13 15:26:27 volumio volumio[14148]: info: Loading plugin "volumiodiscovery"... May 13 15:26:27 volumio volumio[14148]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 13 15:26:27 volumio node[14148]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 13 15:26:27 volumio volumio[14148]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:26:27 volumio node[14148]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:26:27 volumio volumio[14148]: *** WARNING *** For more information see May 13 15:26:27 volumio node[14148]: *** WARNING *** For more information see May 13 15:26:27 volumio volumio[14148]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 13 15:26:27 volumio node[14148]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 13 15:26:27 volumio volumio[14148]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:26:27 volumio node[14148]: *** WARNING *** Please fix your application to use the native API of Avahi! May 13 15:26:27 volumio volumio[14148]: *** WARNING *** For more information see May 13 15:26:27 volumio node[14148]: *** WARNING *** For more information see May 13 15:26:27 volumio volumio[14148]: info: Applying required configuration parameters for plugin volumiodiscovery May 13 15:26:27 volumio volumio[14148]: info: Discovery: Started advertising with name: Volumio May 13 15:26:27 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 13 15:26:27 volumio volumio[14148]: info: Loading plugin "spop"... May 13 15:26:27 volumio volumio[14148]: info: Loading plugin "squeezelite_mc"... May 13 15:26:28 volumio dhcpcd[1034]: wlan0: soliciting an IPv6 router May 13 15:26:28 volumio volumio[14148]: info: Loading plugin "youtube2"... May 13 15:26:28 volumio volumio[14148]: info: Loading plugin "now_playing"... May 13 15:26:29 volumio volumio-remote-updater[534]: [2025-05-13 15:26:29] [connect] Successful connection May 13 15:26:29 volumio volumio[14148]: info: Loading plugin "outputs"... May 13 15:26:29 volumio volumio[14148]: info: Loading plugin "albumart"... May 13 15:26:29 volumio volumio[14148]: info: Plugin example_plugin is not enabled May 13 15:26:29 volumio volumio[14148]: info: Loading plugin "inputs"... May 13 15:26:29 volumio volumio[14148]: info: Loading plugin "updater_comm"... May 13 15:26:29 volumio volumio[14148]: info: Plugin mpdemulation is not enabled May 13 15:26:29 volumio volumio[14148]: info: Loading plugin "rest_api"... May 13 15:26:29 volumio volumio[14148]: info: Loading plugin "websocket"... May 13 15:26:29 volumio volumio[14148]: info: Starting Socket.io Server version 2.3.0 May 13 15:26:29 volumio volumio[14148]: info: Loading plugin "lms"... May 13 15:26:29 volumio volumio[14148]: info: Loading i18n strings for locale en May 13 15:26:29 volumio volumio[14148]: Updating browse sources language May 13 15:26:29 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:29 volumio volumio[14148]: Forking 3 albumart workers May 13 15:26:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. May 13 15:26:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. May 13 15:26:29 volumio systemd[1]: Stopped go-librespot Daemon. May 13 15:26:29 volumio systemd[1]: Started go-librespot Daemon. May 13 15:26:29 volumio go-librespot[14248]: Librespot-go daemon starting... May 13 15:26:29 volumio go-librespot[14248]: time="2025-05-13T15:26:29-04:00" level=info msg="generated new device id: 2ffe4b191fe41459d807b1d0628155bc17787fc8" May 13 15:26:29 volumio go-librespot[14248]: time="2025-05-13T15:26:29-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 13 15:26:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 15:26:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 15:26:29 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:26:29 volumio volumio[14148]: info: CoreCommandRouter::initPlayerControls May 13 15:26:29 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:29 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:29 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:29 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:29 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:29 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:29 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:29 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:29 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:26:29 volumio volumio[14148]: Express server listening on port 3000 May 13 15:26:29 volumio volumio[14148]: [Metrics] WebUI: 4s 958.40ms May 13 15:26:29 volumio volumio[14148]: info: CoreStateMachine::resetVolumioState May 13 15:26:29 volumio volumio[14148]: info: CoreStateMachine::getcurrentVolume May 13 15:26:29 volumio volumio[14148]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:26:29 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:30 volumio volumio[14148]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' May 13 15:26:30 volumio volumio[14148]: info: Completed loading Core Plugins May 13 15:26:30 volumio volumio[14148]: info: Preparing to generate the ALSA configuration file May 13 15:26:30 volumio volumio[14148]: info: Volumio Network Manager: Network status updated: 0 May 13 15:26:30 volumio volumio-remote-updater[534]: [2025-05-13 15:26:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1747164389 101 May 13 15:26:30 volumio volumio[14148]: 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 May 13 15:26:30 volumio volumio[14148]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 2 May 13 15:26:30 volumio volumio[14148]: info: Reloading queue from file May 13 15:26:30 volumio volumio[14148]: info: Asound.conf file unchanged, so no further update is needed May 13 15:26:30 volumio volumio[14148]: info: Output device has changed, restarting MPD May 13 15:26:30 volumio volumio[14148]: info: Output device has changed, restarting Shairport Sync May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:30 volumio sudo[14287]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 13 15:26:30 volumio sudo[14285]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 13 15:26:30 volumio volumio[14148]: info: ___________ START PLUGINS ___________ May 13 15:26:30 volumio volumio[14148]: info: ControllerMpd::onStart: Initializing MPD May 13 15:26:30 volumio volumio[14148]: info: Creating MPD Configuration file May 13 15:26:30 volumio sudo[14287]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:30 volumio sudo[14285]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:30 volumio systemd[1]: Stopping Music Player Daemon... May 13 15:26:30 volumio sudo[14285]: pam_unix(sudo:session): session closed for user root May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:26:30 volumio volumio[14148]: info: [1747164390401] CoreMusicLibrary::Adding element Media Servers May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:30 volumio sudo[14301]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 13 15:26:30 volumio sudo[14306]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:30 volumio sudo[14301]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:30 volumio systemd[1]: mpd.service: Succeeded. May 13 15:26:30 volumio systemd[1]: Stopped Music Player Daemon. May 13 15:26:30 volumio sudo[14306]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:30 volumio systemd[1]: Starting Music Player Daemon... May 13 15:26:30 volumio sudo[14301]: pam_unix(sudo:session): session closed for user root May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:26:30 volumio volumio[14148]: info: [1747164390582] CoreMusicLibrary::Adding element Last_100 May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:26:30 volumio volumio[14148]: info: [1747164390585] CoreMusicLibrary::Adding element Webradio May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:26:30 volumio volumio[14148]: info: Initializing BBC Radios May 13 15:26:30 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM May 13 15:26:30 volumio systemd[1]: mpd.service: Succeeded. May 13 15:26:30 volumio systemd[1]: Stopped Music Player Daemon. May 13 15:26:30 volumio systemd[1]: Starting Music Player Daemon... May 13 15:26:30 volumio volumio[14148]: Starting albumart workers May 13 15:26:30 volumio volumio[14148]: Starting albumart workers May 13 15:26:30 volumio sudo[14329]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 13 15:26:30 volumio sudo[14329]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 13 15:26:30 volumio volumio[14148]: Starting albumart workers May 13 15:26:30 volumio volumio[14148]: info: Creating Spotify config file May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:30 volumio sudo[14329]: pam_unix(sudo:session): session closed for user root May 13 15:26:30 volumio volumio[14148]: info: [squeezelite_mc] Starting proxy server... May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 13 15:26:30 volumio volumio[14148]: info: [1747164390773] CoreMusicLibrary::Adding element YouTube2 May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 13 15:26:30 volumio volumio[14148]: Cannot find translation for source YouTube2 May 13 15:26:30 volumio volumio[14148]: info: [now-playing-config] Config is up to date. May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 13 15:26:30 volumio volumio[14148]: info: Discovery: Getting this device information May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::volumioGetState May 13 15:26:30 volumio volumio[14148]: info: CorePlayQueue::getTrack 0 May 13 15:26:30 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 13 15:26:30 volumio volumio[14148]: info: Volumio Calling Home May 13 15:26:30 volumio sudo[14348]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver May 13 15:26:30 volumio volumio[14148]: info: [squeezelite_mc] Proxy server started on port 44003 May 13 15:26:30 volumio volumio[14148]: info: [now-playing-app] App is listening on port 4004. May 13 15:26:30 volumio sudo[14348]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:31 volumio volumio[14148]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:26:31 volumio volumio[14148]: info: CoreStateMachine::setRepeat false single undefined May 13 15:26:31 volumio volumio[14148]: info: CoreStateMachine::pushState May 13 15:26:31 volumio volumio[14148]: info: CorePlayQueue::getTrack 0 May 13 15:26:31 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:26:31 volumio volumio[14148]: info: CoreCommandRouter::volumioPushState May 13 15:26:31 volumio volumio[14148]: info: CoreStateMachine::setRandom undefined May 13 15:26:31 volumio volumio[14148]: info: CoreStateMachine::pushState May 13 15:26:31 volumio volumio[14148]: info: CorePlayQueue::getTrack 0 May 13 15:26:31 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:26:31 volumio volumio[14148]: info: CoreCommandRouter::volumioPushState May 13 15:26:31 volumio systemd[1]: Starting Logitech Media Server Daemon... May 13 15:26:31 volumio volumio[14148]: info: Setting Device type: Tinkerboard May 13 15:26:31 volumio systemd[1]: Started Logitech Media Server Daemon. May 13 15:26:31 volumio sudo[14348]: pam_unix(sudo:session): session closed for user root May 13 15:26:31 volumio systemd[14360]: logitechmediaserver.service: Failed to execute command: No such file or directory May 13 15:26:31 volumio systemd[14360]: logitechmediaserver.service: Failed at step EXEC spawning /usr/sbin/squeezeboxserver: No such file or directory May 13 15:26:31 volumio systemd[1]: logitechmediaserver.service: Main process exited, code=exited, status=203/EXEC May 13 15:26:31 volumio systemd[1]: logitechmediaserver.service: Failed with result 'exit-code'. May 13 15:26:31 volumio volumio[14148]: info: VolumeController:: Volume=100 Mute =false May 13 15:26:31 volumio volumio[14148]: info: CoreStateMachine::pushState May 13 15:26:31 volumio volumio[14148]: info: CorePlayQueue::getTrack 0 May 13 15:26:31 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 13 15:26:31 volumio volumio[14148]: info: CoreCommandRouter::volumioPushState May 13 15:26:31 volumio volumio[14148]: info: CoreStateMachine::updateTrackBlock May 13 15:26:31 volumio volumio[14148]: info: CorePlayQueue::getTrackBlock May 13 15:26:31 volumio volumio[14148]: info: CoreCommandRouter::volumioRetrievevolume May 13 15:26:31 volumio volumio[14148]: Unhandled rejection Error: No sockets available, cannot start. May 13 15:26:31 volumio volumio[14148]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) May 13 15:26:31 volumio volumio[14148]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) May 13 15:26:31 volumio volumio[14148]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 May 13 15:26:31 volumio volumio[14148]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) May 13 15:26:31 volumio volumio[14148]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) May 13 15:26:31 volumio volumio[14148]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) May 13 15:26:31 volumio volumio[14148]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) May 13 15:26:31 volumio volumio[14148]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) May 13 15:26:31 volumio volumio[14148]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) May 13 15:26:31 volumio volumio[14148]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) May 13 15:26:31 volumio volumio[14148]: at HashMap. (/volumio/app/pluginmanager.js:496:31) May 13 15:26:31 volumio volumio[14148]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) May 13 15:26:31 volumio volumio[14148]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) May 13 15:26:31 volumio volumio[14148]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) May 13 15:26:31 volumio volumio[14148]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) May 13 15:26:31 volumio volumio[14148]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 13 15:26:31 volumio volumio[14148]: info: logitechmediaserver started May 13 15:26:31 volumio volumio[14148]: info: MPD Permissions set May 13 15:26:31 volumio volumio[14148]: info: MPD Permissions set May 13 15:26:31 volumio volumio[14148]: info: Spotify config file written May 13 15:26:31 volumio volumio[14148]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 13 15:26:31 volumio volumio[14148]: info: VolumeController:: Volume=100 Mute =false May 13 15:26:31 volumio volumio[14148]: info: CoreStateMachine::pushState May 13 15:26:31 volumio volumio[14148]: info: CorePlayQueue::getTrack 0 May 13 15:26:31 volumio volumio[14148]: info: CoreCommandRouter::volumioPushState May 13 15:26:31 volumio volumio[14148]: info: [squeezelite_mc] Server discovery started May 13 15:26:31 volumio volumio[14148]: info: [squeezelite_mc] Player finder started May 13 15:26:31 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:31 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:31 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 13 15:26:31 volumio volumio[14148]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 13 15:26:31 volumio volumio[14148]: info: [squeezelite_mc] Executing aplay -D hw:0 --nonblock -f MPEG /dev/zero 2>&1 || true May 13 15:26:31 volumio sudo[14384]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 13 15:26:31 volumio volumio[14148]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 15:26:31 volumio sudo[14384]: pam_unix(sudo:session): session opened for user root by (uid=0) May 13 15:26:31 volumio volumio[14148]: Error: send ENETUNREACH 255.255.255.255:3483 May 13 15:26:31 volumio volumio[14148]: at doSend (dgram.js:714:16) May 13 15:26:31 volumio volumio[14148]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:452:18) May 13 15:26:31 volumio volumio[14148]: at afterDns (dgram.js:660:5) May 13 15:26:31 volumio volumio[14148]: at processTicksAndRejections (internal/process/task_queues.js:83:21) { May 13 15:26:31 volumio volumio[14148]: errno: -101, May 13 15:26:31 volumio volumio[14148]: code: 'ENETUNREACH', May 13 15:26:31 volumio volumio[14148]: syscall: 'send', May 13 15:26:31 volumio volumio[14148]: address: '255.255.255.255', May 13 15:26:31 volumio volumio[14148]: port: 3483 May 13 15:26:31 volumio volumio[14148]: } May 13 15:26:31 volumio volumio[14148]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 13 15:26:31 volumio systemd[1]: Stopped go-librespot Daemon. May 13 15:26:31 volumio systemd[1]: Started go-librespot Daemon. May 13 15:26:31 volumio go-librespot[14402]: Librespot-go daemon starting... May 13 15:26:31 volumio sudo[14384]: pam_unix(sudo:session): session closed for user root May 13 15:26:31 volumio go-librespot[14402]: time="2025-05-13T15:26:31-04:00" level=info msg="generated new device id: 5c6dcec3e319919518a8117d1e2de6663d48f3b5" May 13 15:26:31 volumio go-librespot[14402]: time="2025-05-13T15:26:31-04:00" level=fatal msg="failed running zeroconf" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 13 15:26:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE May 13 15:26:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 13 15:26:31 volumio dhcpcd[1034]: wlan0: using static address 192.168.1.5/24 May 13 15:26:31 volumio dhcpcd[1034]: wlan0: adding route to 192.168.1.0/24 May 13 15:26:31 volumio avahi-daemon[539]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.5. May 13 15:26:31 volumio dhcpcd[1034]: wlan0: adding default route via 192.168.1.1 May 13 15:26:31 volumio avahi-daemon[539]: New relevant interface wlan0.IPv4 for mDNS. May 13 15:26:31 volumio avahi-daemon[539]: Registering new address record for 192.168.1.5 on wlan0.IPv4. May 13 15:26:31 volumio sudo[14438]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-13 15:25 May 13 15:26:32 volumio sudo[14438]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 09:53:51 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="53825f995260683aee752aed6b29f24e"