Jul 17 20:04:00 volumio-pi5-beta go-librespot[17704]: time="2025-07-17T20:04:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 17 20:04:00 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 20:04:00 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 20:04:00 volumio-pi5-beta volumio-remote-updater[938]: [2025-07-17 20:04:00] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jul 17 20:04:00 volumio-pi5-beta volumio-remote-updater[938]: [2025-07-17 20:04:00] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jul 17 20:04:00 volumio-pi5-beta systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jul 17 20:04:00 volumio-pi5-beta dbus-daemon[894]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.259' (uid=0 pid=17726 comm="timedatectl show --property=NTPSynchronized --valu") Jul 17 20:04:00 volumio-pi5-beta systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jul 17 20:04:00 volumio-pi5-beta systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jul 17 20:04:00 volumio-pi5-beta systemd[1]: volumio.service: Failed with result 'exit-code'. Jul 17 20:04:00 volumio-pi5-beta systemd[1]: volumio.service: Consumed 12.629s CPU time. Jul 17 20:04:00 volumio-pi5-beta systemd[1]: Started dynamicswap.service - dynamicswap service. Jul 17 20:04:00 volumio-pi5-beta systemd[1]: dynamicswap.service: Deactivated successfully. Jul 17 20:04:00 volumio-pi5-beta systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8. Jul 17 20:04:00 volumio-pi5-beta dbus-daemon[894]: [system] Successfully activated service 'org.freedesktop.timedate1' Jul 17 20:04:00 volumio-pi5-beta setdatetime-helper.sh[17725]: Time is already synchronized. Jul 17 20:04:00 volumio-pi5-beta systemd[1]: Started dynamicswap.service - dynamicswap service. Jul 17 20:04:00 volumio-pi5-beta systemd[1]: Stopped volumio.service - Volumio Backend Module. Jul 17 20:04:00 volumio-pi5-beta systemd[1]: volumio.service: Consumed 12.629s CPU time. Jul 17 20:04:00 volumio-pi5-beta systemd[1]: Started volumio.service - Volumio Backend Module. Jul 17 20:04:00 volumio-pi5-beta systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jul 17 20:04:00 volumio-pi5-beta systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jul 17 20:04:00 volumio-pi5-beta systemd[1]: Started systemd-timedated.service - Time & Date Service. Jul 17 20:04:00 volumio-pi5-beta systemd[1]: dynamicswap.service: Deactivated successfully. Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: ------------------------------------------- Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: ----- Volumio3 ---- Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: ------------------------------------------- Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: ----- System startup ---- Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: ------------------------------------------- Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: MYVOLUMIO Environment detected Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Plugin folders cleanup Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Scanning into folder /volumio/app/plugins/ Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Scanning category audio_interface Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Scanning category miscellanea Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Scanning category music_service Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Scanning category plugins.json Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Scanning category system_controller Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Scanning category user_interface Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Scanning into folder /data/plugins/ Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Scanning category audio_interface Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Scanning category music_service Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Scanning category system_controller Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Scanning category user_interface Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Plugin folders cleanup completed Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: ------------------------------------------- Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: ----- Core plugins startup ---- Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: ------------------------------------------- Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Loading plugins from folder /volumio/app/plugins/ Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Adding plugin upnp to MyMusic Plugins Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Adding plugin airplay_emulation to MyMusic Plugins Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Adding plugin upnp_browser to MyMusic Plugins Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Loading plugins from folder /data/plugins/ Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Loading plugin "system"... Jul 17 20:04:01 volumio-pi5-beta volumio[17743]: info: Loading plugin "appearance"... Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Loading plugin "network"... Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Refreshing Cached IP Addresses Jul 17 20:04:02 volumio-pi5-beta sudo[17771]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 17 20:04:02 volumio-pi5-beta sudo[17771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Loading plugin "services"... Jul 17 20:04:02 volumio-pi5-beta sudo[17773]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 17 20:04:02 volumio-pi5-beta sudo[17773]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Loading plugin "alsa_controller"... Jul 17 20:04:02 volumio-pi5-beta sudo[17771]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:02 volumio-pi5-beta sudo[17773]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Loading plugin "wizard"... Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Loading plugin "networkfs"... Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Cannot mount NAS FLAC at system boot, trial number 1 ,retrying in 5 seconds Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Cannot mount NAS DSD at system boot, trial number 1 ,retrying in 5 seconds Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Cannot mount NAS Now_That's_What_I_Call_Music! at system boot, trial number 1 ,retrying in 5 seconds Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Starting Udev Watcher for removable devices Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Ignoring mount for partition: boot Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Ignoring mount for partition: volumio Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Ignoring mount for partition: volumio_data Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Loading plugin "volumio_command_line_client"... Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Plugin upnp is not enabled Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Loading plugin "my_music"... Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Loading plugin "mpd"... Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Plugin upnp_browser is not enabled Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Loading plugin "alarm-clock"... Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Plugin airplay_emulation is not enabled Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Loading plugin "last_100"... Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Loading plugin "webradio"... Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Loading plugin "i2s_dacs"... Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: I2S DAC not set, start Auto-detection Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Loading plugin "volumiodiscovery"... Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: *** WARNING *** For more information see Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: *** WARNING *** For more information see Jul 17 20:04:02 volumio-pi5-beta node[17743]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 17 20:04:02 volumio-pi5-beta node[17743]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 17 20:04:02 volumio-pi5-beta node[17743]: *** WARNING *** For more information see Jul 17 20:04:02 volumio-pi5-beta node[17743]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 17 20:04:02 volumio-pi5-beta node[17743]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 17 20:04:02 volumio-pi5-beta node[17743]: *** WARNING *** For more information see Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Applying required configuration parameters for plugin volumiodiscovery Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Discovery: Started advertising with name: Volumio-Pi5-beta Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 17 20:04:02 volumio-pi5-beta volumio[17743]: info: Loading plugin "spop"... Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Loading plugin "now_playing"... Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Loading plugin "outputs"... Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Loading plugin "albumart"... Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Plugin example_plugin is not enabled Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Loading plugin "inputs"... Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Loading plugin "updater_comm"... Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Plugin mpdemulation is not enabled Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Loading plugin "rest_api"... Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Loading plugin "websocket"... Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Starting Socket.io Server version 1.7.4 Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Loading plugin "fusiondsp"... Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Applying required configuration parameters for plugin fusiondsp Jul 17 20:04:03 volumio-pi5-beta volumio[17800]: Forking 3 albumart workers Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Loading plugin "backup_restore"... Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Applying required configuration parameters for plugin backup_restore Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Loading plugin "Systeminfo"... Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Loading plugin "peppymeterbasic"... Jul 17 20:04:03 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jul 17 20:04:03 volumio-pi5-beta systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 17 20:04:03 volumio-pi5-beta systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 17 20:04:03 volumio-pi5-beta go-librespot[17840]: go-librespot daemon starting... Jul 17 20:04:03 volumio-pi5-beta go-librespot[17841]: time="2025-07-17T20:04:03+07:00" level=info msg="running go-librespot 0.2.0" Jul 17 20:04:03 volumio-pi5-beta go-librespot[17841]: time="2025-07-17T20:04:03+07:00" level=debug msg="app state loaded" Jul 17 20:04:03 volumio-pi5-beta go-librespot[17841]: time="2025-07-17T20:04:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 20:04:03 volumio-pi5-beta volumio[17743]: info: Loading plugin "touch_display"... Jul 17 20:04:04 volumio-pi5-beta volumio[17810]: Starting albumart workers Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Applying required configuration parameters for plugin touch_display Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Loading i18n strings for locale en Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Plugin peppymeterbasic has duplicated i18n key APPLY. It is ignored. Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Plugin peppymeterbasic has duplicated i18n key SAVE. It is ignored. Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: Updating browse sources language Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 17 20:04:04 volumio-pi5-beta volumio[17812]: Starting albumart workers Jul 17 20:04:04 volumio-pi5-beta volumio[17811]: Starting albumart workers Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::initPlayerControls Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: Express server listening on port 3000 Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: [Metrics] WebUI: 2s 896.26ms Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreStateMachine::resetVolumioState Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreStateMachine::getcurrentVolume Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioRetrievevolume Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreStateMachine::pushState Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CorePlayQueue::getTrack 0 Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioPushState Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Volumio Network Manager: Network status updated: 1 Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Reloading queue from file Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'has') Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreStateMachine::setRepeat null single undefined Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreStateMachine::pushState Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CorePlayQueue::getTrack 0 Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioPushState Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreStateMachine::setRandom null Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreStateMachine::pushState Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CorePlayQueue::getTrack 0 Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioPushState Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Listing playlists Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioGetQueue Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreStateMachine::getQueue Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CorePlayQueue::getQueue Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioGetVisibleSources Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioGetState Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CorePlayQueue::getTrack 0 Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CALLMETHOD: user_interface now_playing getPluginInfo undefined Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: now_playing , getPluginInfo Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'has') Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Listing playlists Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioGetQueue Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreStateMachine::getQueue Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CorePlayQueue::getQueue Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioGetVisibleSources Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioGetState Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CorePlayQueue::getTrack 0 Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Setting Device type: Raspberry PI Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Completed loading Core Plugins Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Preparing to generate the ALSA configuration file Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d04171 Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Reading ALSA contributions from plugins. Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Asound.conf file unchanged, so no further update is needed Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Output device has changed, restarting MPD Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: ___________ START PLUGINS ___________ Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: ControllerMpd::onStart: Initializing MPD Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Creating MPD Configuration file Jul 17 20:04:04 volumio-pi5-beta sudo[17879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 17 20:04:04 volumio-pi5-beta sudo[17879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:04 volumio-pi5-beta sudo[17881]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 17 20:04:04 volumio-pi5-beta sudo[17881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:04 volumio-pi5-beta sudo[17879]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: [1752757444695] CoreMusicLibrary::Adding element Last_100 Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: [1752757444698] CoreMusicLibrary::Adding element Webradio Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 17 20:04:04 volumio-pi5-beta sudo[17887]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 17 20:04:04 volumio-pi5-beta sudo[17887]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Initializing BBC Radios Jul 17 20:04:04 volumio-pi5-beta sudo[17884]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 17 20:04:04 volumio-pi5-beta sudo[17884]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:04 volumio-pi5-beta sudo[17884]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:04 volumio-pi5-beta systemd[1]: Stopping mpd.service - Music Player Daemon... Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Creating Spotify config file Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:04 volumio-pi5-beta systemd[1]: mpd.service: Deactivated successfully. Jul 17 20:04:04 volumio-pi5-beta systemd[1]: Stopped mpd.service - Music Player Daemon. Jul 17 20:04:04 volumio-pi5-beta systemd[1]: mpd.service: Consumed 1.170s CPU time. Jul 17 20:04:04 volumio-pi5-beta systemd[1]: mpd.socket: Deactivated successfully. Jul 17 20:04:04 volumio-pi5-beta systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jul 17 20:04:04 volumio-pi5-beta systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jul 17 20:04:04 volumio-pi5-beta systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jul 17 20:04:04 volumio-pi5-beta systemd[1]: Starting mpd.service - Music Player Daemon... Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: [now-playing] ConfigUpdater: config is up to date. Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Loading i18n strings for locale en Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Plugin peppymeterbasic has duplicated i18n key APPLY. It is ignored. Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Plugin peppymeterbasic has duplicated i18n key SAVE. It is ignored. Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Jul 17 20:04:04 volumio-pi5-beta sudo[17904]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:04 volumio-pi5-beta sudo[17904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: FusionDsp - mixtype--------------------- None Jul 17 20:04:04 volumio-pi5-beta sudo[17904]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Loading i18n strings for locale en Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Plugin peppymeterbasic has duplicated i18n key APPLY. It is ignored. Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Plugin peppymeterbasic has duplicated i18n key SAVE. It is ignored. Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Volumio Calling Home Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: Preparing to generate the ALSA configuration file Jul 17 20:04:04 volumio-pi5-beta sudo[17911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Jul 17 20:04:04 volumio-pi5-beta sudo[17911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:04 volumio-pi5-beta sudo[17913]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Jul 17 20:04:04 volumio-pi5-beta sudo[17913]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:04 volumio-pi5-beta sudo[17915]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jul 17 20:04:04 volumio-pi5-beta sudo[17915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:04 volumio-pi5-beta systemd[1]: Reloading. Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: [now-playing] Fetching API key... Jul 17 20:04:04 volumio-pi5-beta volumio[17743]: info: [now-playing] App is listening on port 4004. Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: Reading ALSA contributions from plugins. Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: touch_display: Backlight interface detected. Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: MPD Permissions set Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: MPD Permissions set Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: Spotify config file written Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta sudo[17922]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jul 17 20:04:05 volumio-pi5-beta sudo[17922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: No need to fix Spotify hosts Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Jul 17 20:04:05 volumio-pi5-beta sudo[17952]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/11-0045/brightness Jul 17 20:04:05 volumio-pi5-beta sudo[17952]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:05 volumio-pi5-beta sudo[17952]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: touch_display: File permissions for backlight brightness control set. Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: Asound.conf file unchanged, so no further update is needed Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: Output device has changed, restarting MPD Jul 17 20:04:05 volumio-pi5-beta sudo[17954]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Jul 17 20:04:05 volumio-pi5-beta sudo[17954]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:05 volumio-pi5-beta sudo[17957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Jul 17 20:04:05 volumio-pi5-beta sudo[17957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:05 volumio-pi5-beta sudo[17954]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:05 volumio-pi5-beta sudo[17957]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: Preparing to generate the ALSA configuration file Jul 17 20:04:05 volumio-pi5-beta sudo[17960]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 17 20:04:05 volumio-pi5-beta sudo[17960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:05 volumio-pi5-beta sudo[17963]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: Reading ALSA contributions from plugins. Jul 17 20:04:05 volumio-pi5-beta sudo[17960]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:05 volumio-pi5-beta sudo[17963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: MPD Permissions set Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: Asound.conf file unchanged, so no further update is needed Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: Output device has changed, restarting MPD Jul 17 20:04:05 volumio-pi5-beta sudo[17974]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 17 20:04:05 volumio-pi5-beta sudo[17974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:05 volumio-pi5-beta sudo[17974]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta sudo[17976]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 17 20:04:05 volumio-pi5-beta sudo[17976]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: MPD Permissions set Jul 17 20:04:05 volumio-pi5-beta systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jul 17 20:04:05 volumio-pi5-beta systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jul 17 20:04:05 volumio-pi5-beta volumio-remote-updater[938]: [2025-07-17 20:04:05] [connect] Successful connection Jul 17 20:04:05 volumio-pi5-beta volumio-remote-updater[938]: [2025-07-17 20:04:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1752757445 101 Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3 Jul 17 20:04:05 volumio-pi5-beta sudo[17915]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:05 volumio-pi5-beta volumio[17743]: info: touch_display: systemctl daemon-reload succeeded. Jul 17 20:04:05 volumio-pi5-beta mpd[17906]: 2025-07-17T20:04:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 17 20:04:05 volumio-pi5-beta systemd[1]: Reloading. Jul 17 20:04:05 volumio-pi5-beta sudo[17988]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Jul 17 20:04:05 volumio-pi5-beta sudo[17988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:06 volumio-pi5-beta systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jul 17 20:04:06 volumio-pi5-beta systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jul 17 20:04:06 volumio-pi5-beta sudo[17913]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:06 volumio-pi5-beta systemd[1]: Started mpd.service - Music Player Daemon. Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: touch_display: systemctl disable getty@tty1.service succeeded. Jul 17 20:04:06 volumio-pi5-beta sudo[17887]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:06 volumio-pi5-beta sudo[17881]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:06 volumio-pi5-beta systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jul 17 20:04:06 volumio-pi5-beta systemd[1]: Stopping mpd.service - Music Player Daemon... Jul 17 20:04:06 volumio-pi5-beta sudo[17988]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:06 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jul 17 20:04:06 volumio-pi5-beta systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 17 20:04:06 volumio-pi5-beta sudo[17911]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: error: MPD error: The expression evaluated to a falsy value: Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: assert.ok(self.idling) Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: error: The expression evaluated to a falsy value: Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: assert.ok(self.idling) Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: touch_display: systemctl stop getty@tty1.service succeeded. Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: touch_display: Volumio Kiosk started. Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioGetState Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: CorePlayQueue::getTrack 0 Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: Completed starting Core Plugins Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: ------------------------------------------- Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: ----- MyVolumio plugins startup ---- Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: ------------------------------------------- Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: [MyVolumio PluginManager] Fetching plans data.... Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: MPD running with PID17906 Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: ,establishing connection Jul 17 20:04:06 volumio-pi5-beta systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: error: MPD error: Error: read ECONNRESET Jul 17 20:04:06 volumio-pi5-beta sudo[17922]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:06 volumio-pi5-beta go-librespot[18012]: go-librespot daemon starting... Jul 17 20:04:06 volumio-pi5-beta go-librespot[18015]: time="2025-07-17T20:04:06+07:00" level=info msg="running go-librespot 0.2.0" Jul 17 20:04:06 volumio-pi5-beta go-librespot[18015]: time="2025-07-17T20:04:06+07:00" level=debug msg="app state loaded" Jul 17 20:04:06 volumio-pi5-beta go-librespot[18015]: time="2025-07-17T20:04:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: touch_display: X display number found: 0 Jul 17 20:04:06 volumio-pi5-beta systemd[1]: mpd.service: Deactivated successfully. Jul 17 20:04:06 volumio-pi5-beta systemd[1]: Stopped mpd.service - Music Player Daemon. Jul 17 20:04:06 volumio-pi5-beta systemd[1]: mpd.service: Consumed 1.023s CPU time. Jul 17 20:04:06 volumio-pi5-beta systemd[1]: mpd.socket: Deactivated successfully. Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: error: MPD error: Error: read ECONNRESET Jul 17 20:04:06 volumio-pi5-beta systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jul 17 20:04:06 volumio-pi5-beta systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jul 17 20:04:06 volumio-pi5-beta systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jul 17 20:04:06 volumio-pi5-beta systemd[1]: Starting mpd.service - Music Player Daemon... Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jul 17 20:04:06 volumio-pi5-beta sudo[18022]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: touch_display: X display number found: 0 Jul 17 20:04:06 volumio-pi5-beta sudo[18022]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jul 17 20:04:06 volumio-pi5-beta sudo[18022]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioGetState Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: CorePlayQueue::getTrack 0 Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: touch_display: Setting screensaver timeout to 0 seconds. Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: camilladsp service started and running in background, instance 1 Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: FusionDsp loaded Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: error: FusionDsp - Socket connection not established Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: FusionDsp - Reporting Fusion DSP Enabled Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: Adding Signal Path Element [object Object] Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: Adding fusiondspeq DSP Signal Path Element Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: FusionDsp - ---- installed callbackRead Jul 17 20:04:06 volumio-pi5-beta volumio[17743]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jul 17 20:04:06 volumio-pi5-beta sudo[18047]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jul 17 20:04:06 volumio-pi5-beta sudo[18047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jul 17 20:04:06 volumio-pi5-beta sudo[18047]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:07 volumio-pi5-beta volumio[17743]: info: Cannot mount NAS FLAC at system boot, trial number 2 ,retrying in 5 seconds Jul 17 20:04:07 volumio-pi5-beta volumio[17743]: info: Cannot mount NAS DSD at system boot, trial number 2 ,retrying in 5 seconds Jul 17 20:04:07 volumio-pi5-beta volumio[17743]: info: Cannot mount NAS Now_That's_What_I_Call_Music! at system boot, trial number 2 ,retrying in 5 seconds Jul 17 20:04:07 volumio-pi5-beta mpd[18028]: 2025-07-17T20:04:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 17 20:04:07 volumio-pi5-beta systemd[1]: Started mpd.service - Music Player Daemon. Jul 17 20:04:07 volumio-pi5-beta sudo[17963]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:07 volumio-pi5-beta sudo[17976]: pam_unix(sudo:session): session closed for user root Jul 17 20:04:07 volumio-pi5-beta volumio[17743]: error: MPD error: The expression evaluated to a falsy value: Jul 17 20:04:07 volumio-pi5-beta volumio[17743]: assert.ok(self.idling) Jul 17 20:04:07 volumio-pi5-beta volumio[17743]: error: The expression evaluated to a falsy value: Jul 17 20:04:07 volumio-pi5-beta volumio[17743]: assert.ok(self.idling) Jul 17 20:04:07 volumio-pi5-beta volumio[17743]: error: updateQueue error: null Jul 17 20:04:09 volumio-pi5-beta volumio[17743]: info: go-librespot daemon successfully initialized Jul 17 20:04:11 volumio-pi5-beta volumio[17743]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jul 17 20:04:11 volumio-pi5-beta volumio[17743]: error: MPD error: The expression evaluated to a falsy value: Jul 17 20:04:11 volumio-pi5-beta volumio[17743]: assert.ok(self.idling) Jul 17 20:04:11 volumio-pi5-beta volumio[17743]: error: The expression evaluated to a falsy value: Jul 17 20:04:11 volumio-pi5-beta volumio[17743]: assert.ok(self.idling) Jul 17 20:04:11 volumio-pi5-beta volumio[17743]: error: updateQueue error: null Jul 17 20:04:12 volumio-pi5-beta volumio[17743]: info: Cannot mount NAS FLAC at system boot, trial number 3 ,retrying in 5 seconds Jul 17 20:04:12 volumio-pi5-beta volumio[17743]: info: Cannot mount NAS DSD at system boot, trial number 3 ,retrying in 5 seconds Jul 17 20:04:12 volumio-pi5-beta volumio[17743]: info: Cannot mount NAS Now_That's_What_I_Call_Music! at system boot, trial number 3 ,retrying in 5 seconds Jul 17 20:04:12 volumio-pi5-beta volumio[17743]: info: Initializing connection to go-librespot Websocket Jul 17 20:04:13 volumio-pi5-beta volumio[17743]: Cannot compose Albumart path Jul 17 20:04:15 volumio-pi5-beta volumio[17743]: error: [now-playing] Error fetching https://openweathermap.org: TypeError: fetch failed Jul 17 20:04:15 volumio-pi5-beta volumio[17743]: at Object.fetch (node:internal/deps/undici/undici:11576:11) Jul 17 20:04:15 volumio-pi5-beta volumio[17743]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Jul 17 20:04:15 volumio-pi5-beta volumio[17743]: at async fetchPage (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:25:26) Jul 17 20:04:15 volumio-pi5-beta volumio[17743]: at async doGet (/data/plugins/user_interface/now_playing/dist/lib/api/openweathermap/index.js:118:22) Jul 17 20:04:15 volumio-pi5-beta volumio[17743]: error: [now-playing] Caught error in callback of WeatherAPI.#getFetchPromise(): fetch failed Jul 17 20:04:17 volumio-pi5-beta volumio[17743]: info: Cannot mount NAS FLAC at system boot, trial number 4 ,retrying in 5 seconds Jul 17 20:04:17 volumio-pi5-beta volumio[17743]: info: Cannot mount NAS DSD at system boot, trial number 4 ,retrying in 5 seconds Jul 17 20:04:17 volumio-pi5-beta volumio[17743]: info: Cannot mount NAS Now_That's_What_I_Call_Music! at system boot, trial number 4 ,retrying in 5 seconds Jul 17 20:04:18 volumio-pi5-beta go-librespot[18015]: time="2025-07-17T20:04:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 17 20:04:18 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 20:04:18 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 20:04:21 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jul 17 20:04:21 volumio-pi5-beta systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 17 20:04:21 volumio-pi5-beta systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 17 20:04:21 volumio-pi5-beta go-librespot[18068]: go-librespot daemon starting... Jul 17 20:04:21 volumio-pi5-beta go-librespot[18069]: time="2025-07-17T20:04:21+07:00" level=info msg="running go-librespot 0.2.0" Jul 17 20:04:21 volumio-pi5-beta go-librespot[18069]: time="2025-07-17T20:04:21+07:00" level=debug msg="app state loaded" Jul 17 20:04:21 volumio-pi5-beta go-librespot[18069]: time="2025-07-17T20:04:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 20:04:22 volumio-pi5-beta volumio[17743]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Jul 17 20:04:22 volumio-pi5-beta volumio[17743]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Jul 17 20:04:22 volumio-pi5-beta volumio[17743]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Jul 17 20:04:25 volumio-pi5-beta volumio[17743]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.016&uuid=0dce9dcb198b6e2457fb372a9a45702e" http://updates.volumio.org/downloader-v1/track-device Jul 17 20:04:25 volumio-pi5-beta volumio[17743]: % Total % Received % Xferd Average Speed Time Time Time Current Jul 17 20:04:25 volumio-pi5-beta volumio[17743]: Dload Upload Total Spent Left Speed Jul 17 20:04:25 volumio-pi5-beta volumio[17743]: [922B blob data] Jul 17 20:04:25 volumio-pi5-beta volumio[17743]: retrying in 5 seconds, trial 0 Jul 17 20:04:25 volumio-pi5-beta volumio[17743]: info: Volumio Calling Home Jul 17 20:04:26 volumio-pi5-beta volumio[17743]: error: MyVolumio Plugin failed to start in a timely fashion Jul 17 20:04:26 volumio-pi5-beta volumio[17743]: [Metrics] CommandRouter: 24s 940.89ms Jul 17 20:04:26 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumiosetStartupVolume Jul 17 20:04:26 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 17 20:04:26 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 17 20:04:26 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::Close All Modals sent Jul 17 20:04:26 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::Close All Modals sent Jul 17 20:04:27 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jul 17 20:04:27 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 17 20:04:27 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jul 17 20:04:27 volumio-pi5-beta volumio[17743]: info: Discovery: adding b618054a-77cc-4fd1-9d3c-a2ed08019b17 Jul 17 20:04:27 volumio-pi5-beta volumio[17743]: info: Discovery: Found device Volumio-Pi4-beta Jul 17 20:04:27 volumio-pi5-beta volumio[17743]: info: Discovery: Connecting to remote: 10.10.60.49 Jul 17 20:04:27 volumio-pi5-beta volumio[17743]: info: Discovery: adding 3596b0a4-195e-4543-bae9-801dc1c2afce Jul 17 20:04:27 volumio-pi5-beta volumio[17743]: info: Discovery: Found device Volumio-Pi5-beta Jul 17 20:04:27 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioGetState Jul 17 20:04:27 volumio-pi5-beta volumio[17743]: info: CorePlayQueue::getTrack 0 Jul 17 20:04:27 volumio-pi5-beta volumio[17743]: info: Discovery: Connected to remote: 10.10.60.49 Jul 17 20:04:30 volumio-pi5-beta go-librespot[18069]: time="2025-07-17T20:04:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 17 20:04:30 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 20:04:30 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 20:04:30 volumio-pi5-beta systemd[1]: systemd-timedated.service: Deactivated successfully. Jul 17 20:04:33 volumio-pi5-beta volumio[17743]: info: BOOT COMPLETED Jul 17 20:04:33 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jul 17 20:04:33 volumio-pi5-beta systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 17 20:04:33 volumio-pi5-beta systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 17 20:04:33 volumio-pi5-beta go-librespot[18114]: go-librespot daemon starting... Jul 17 20:04:33 volumio-pi5-beta go-librespot[18115]: time="2025-07-17T20:04:33+07:00" level=info msg="running go-librespot 0.2.0" Jul 17 20:04:33 volumio-pi5-beta go-librespot[18115]: time="2025-07-17T20:04:33+07:00" level=debug msg="app state loaded" Jul 17 20:04:33 volumio-pi5-beta go-librespot[18115]: time="2025-07-17T20:04:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 20:04:34 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 17 20:04:34 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 17 20:04:34 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 17 20:04:39 volumio-pi5-beta volumio[17743]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo ENOTFOUND oauth-performer.prod.vlmapi.io Jul 17 20:04:39 volumio-pi5-beta volumio[17743]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Jul 17 20:04:39 volumio-pi5-beta volumio[17743]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jul 17 20:04:39 volumio-pi5-beta volumio[17743]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jul 17 20:04:46 volumio-pi5-beta go-librespot[18115]: time="2025-07-17T20:04:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 17 20:04:46 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 20:04:46 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 20:04:46 volumio-pi5-beta volumio[17743]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.016&uuid=0dce9dcb198b6e2457fb372a9a45702e" http://updates.volumio.org/downloader-v1/track-device Jul 17 20:04:46 volumio-pi5-beta volumio[17743]: % Total % Received % Xferd Average Speed Time Time Time Current Jul 17 20:04:46 volumio-pi5-beta volumio[17743]: Dload Upload Total Spent Left Speed Jul 17 20:04:46 volumio-pi5-beta volumio[17743]: [1001B blob data] Jul 17 20:04:46 volumio-pi5-beta volumio[17743]: retrying in 5 seconds, trial 1 Jul 17 20:04:46 volumio-pi5-beta volumio[17743]: info: Volumio Calling Home Jul 17 20:04:49 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jul 17 20:04:49 volumio-pi5-beta systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 17 20:04:49 volumio-pi5-beta systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 17 20:04:49 volumio-pi5-beta go-librespot[18144]: go-librespot daemon starting... Jul 17 20:04:49 volumio-pi5-beta go-librespot[18145]: time="2025-07-17T20:04:49+07:00" level=info msg="running go-librespot 0.2.0" Jul 17 20:04:49 volumio-pi5-beta go-librespot[18145]: time="2025-07-17T20:04:49+07:00" level=debug msg="app state loaded" Jul 17 20:04:49 volumio-pi5-beta go-librespot[18145]: time="2025-07-17T20:04:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 20:04:52 volumio-pi5-beta volumio[17743]: info: Discovery: this is already registered, 3596b0a4-195e-4543-bae9-801dc1c2afce Jul 17 20:04:52 volumio-pi5-beta volumio[17743]: info: Discovery: Found device Volumio-Pi5-beta Jul 17 20:04:52 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioGetState Jul 17 20:04:52 volumio-pi5-beta volumio[17743]: info: CorePlayQueue::getTrack 0 Jul 17 20:05:09 volumio-pi5-beta go-librespot[18145]: time="2025-07-17T20:05:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 17 20:05:09 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 20:05:09 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 20:05:09 volumio-pi5-beta systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Jul 17 20:05:09 volumio-pi5-beta dbus-daemon[894]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.268' (uid=0 pid=18183 comm="timedatectl show --property=NTPSynchronized --valu") Jul 17 20:05:09 volumio-pi5-beta systemd[1]: Starting systemd-timedated.service - Time & Date Service... Jul 17 20:05:09 volumio-pi5-beta dbus-daemon[894]: [system] Successfully activated service 'org.freedesktop.timedate1' Jul 17 20:05:09 volumio-pi5-beta systemd[1]: Started systemd-timedated.service - Time & Date Service. Jul 17 20:05:09 volumio-pi5-beta setdatetime-helper.sh[18182]: Time is already synchronized. Jul 17 20:05:09 volumio-pi5-beta systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Jul 17 20:05:09 volumio-pi5-beta systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Jul 17 20:05:12 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jul 17 20:05:12 volumio-pi5-beta systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jul 17 20:05:12 volumio-pi5-beta systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jul 17 20:05:12 volumio-pi5-beta go-librespot[18200]: go-librespot daemon starting... Jul 17 20:05:12 volumio-pi5-beta go-librespot[18201]: time="2025-07-17T20:05:12+07:00" level=info msg="running go-librespot 0.2.0" Jul 17 20:05:12 volumio-pi5-beta go-librespot[18201]: time="2025-07-17T20:05:12+07:00" level=debug msg="app state loaded" Jul 17 20:05:12 volumio-pi5-beta go-librespot[18201]: time="2025-07-17T20:05:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 17 20:05:14 volumio-pi5-beta volumio[17743]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.016&uuid=0dce9dcb198b6e2457fb372a9a45702e" http://updates.volumio.org/downloader-v1/track-device Jul 17 20:05:14 volumio-pi5-beta volumio[17743]: % Total % Received % Xferd Average Speed Time Time Time Current Jul 17 20:05:14 volumio-pi5-beta volumio[17743]: Dload Upload Total Spent Left Speed Jul 17 20:05:14 volumio-pi5-beta volumio[17743]: [1.4K blob data] Jul 17 20:05:14 volumio-pi5-beta volumio[17743]: retrying in 5 seconds, trial 2 Jul 17 20:05:14 volumio-pi5-beta volumio[17743]: info: Volumio Calling Home Jul 17 20:05:18 volumio-pi5-beta volumio[17743]: error: FusionDsp - Reload WebSocket error: [object Object] Jul 17 20:05:18 volumio-pi5-beta go-librespot[18201]: time="2025-07-17T20:05:18+07:00" level=debug msg="new websocket client" Jul 17 20:05:18 volumio-pi5-beta volumio[17743]: info: Connection to go-librespot Websocket established Jul 17 20:05:21 volumio-pi5-beta volumio[17743]: info: Getting Spotify volume Jul 17 20:05:31 volumio-pi5-beta volumio[17743]: verbose: New Socket.io Connection to 10.10.60.50:3000 from 10.10.60.49 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jul 17 20:05:31 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Jul 17 20:05:31 volumio-pi5-beta volumio[17743]: info: CoreCommandRouter::volumioGetState Jul 17 20:05:31 volumio-pi5-beta volumio[17743]: info: CorePlayQueue::getTrack 0 Jul 17 20:05:39 volumio-pi5-beta systemd[1]: systemd-timedated.service: Deactivated successfully. Jul 17 20:05:40 volumio-pi5-beta go-librespot[18201]: time="2025-07-17T20:05:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jul 17 20:05:40 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jul 17 20:05:40 volumio-pi5-beta systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jul 17 20:05:40 volumio-pi5-beta volumio[17743]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 17 20:05:40 volumio-pi5-beta volumio[17743]: Error: socket hang up Jul 17 20:05:40 volumio-pi5-beta volumio[17743]: at connResetException (node:internal/errors:720:14) Jul 17 20:05:40 volumio-pi5-beta volumio[17743]: at Socket.socketOnEnd (node:_http_client:519:23) Jul 17 20:05:40 volumio-pi5-beta volumio[17743]: at Socket.emit (node:events:526:35) Jul 17 20:05:40 volumio-pi5-beta volumio[17743]: at endReadableNT (node:internal/streams/readable:1376:12) Jul 17 20:05:40 volumio-pi5-beta volumio[17743]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jul 17 20:05:40 volumio-pi5-beta volumio[17743]: code: 'ECONNRESET', Jul 17 20:05:40 volumio-pi5-beta volumio[17743]: response: undefined Jul 17 20:05:40 volumio-pi5-beta volumio[17743]: } Jul 17 20:05:40 volumio-pi5-beta volumio[17743]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 17 20:05:40 volumio-pi5-beta sudo[18257]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-07-17 20:04' Jul 17 20:05:40 volumio-pi5-beta sudo[18257]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="30967a3eaa5e867c9c73ed66f5e07b238b646dd7" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="c82d2341a3a7e284141656a9703a39c694911dfd" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Jul 12 07:39:31 UTC 2025" VOLUMIO_VERSION="4.016" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5b26578fd35198fc4430a2f6138ca1e3"