Mar 27 17:13:00 volumiopn volumio[4341]: info: Loading plugin "autostart"... Mar 27 17:13:00 volumiopn volumio[4341]: info: Applying required configuration parameters for plugin autostart Mar 27 17:13:00 volumiopn volumio[4341]: info: AutoStart - onVolumioStart - read config.json Mar 27 17:13:00 volumiopn volumio[4341]: info: Loading plugin "gpio-buttons"... Mar 27 17:13:00 volumiopn volumio[4341]: gpiox_arm32 V2.2.1 Mar 27 17:13:00 volumiopn volumio[4341]: info: gpio-buttons: Initialized Mar 27 17:13:00 volumiopn volumio[4341]: info: Loading plugin "gpio_button_led"... Mar 27 17:13:00 volumiopn volumio[4341]: gpiox_arm32 V2.2.1 Mar 27 17:13:00 volumiopn volumio[4341]: info: Loading plugin "outputs"... Mar 27 17:13:00 volumiopn volumio[4341]: info: Loading plugin "albumart"... Mar 27 17:13:00 volumiopn volumio[4341]: info: Plugin example_plugin is not enabled Mar 27 17:13:00 volumiopn volumio[4341]: info: Loading plugin "inputs"... Mar 27 17:13:00 volumiopn volumio[4341]: info: Loading plugin "updater_comm"... Mar 27 17:13:00 volumiopn volumio[4341]: info: Plugin mpdemulation is not enabled Mar 27 17:13:00 volumiopn volumio[4341]: info: Loading plugin "rest_api"... Mar 27 17:13:00 volumiopn volumio[4341]: info: Loading plugin "websocket"... Mar 27 17:13:00 volumiopn volumio[4341]: info: Starting Socket.io Server version 1.7.4 Mar 27 17:13:00 volumiopn volumio[4341]: info: Loading plugin "rad357pl"... Mar 27 17:13:01 volumiopn volumio[4341]: info: Applying required configuration parameters for plugin rad357pl Mar 27 17:13:01 volumiopn volumio[4341]: info: [1774627981152] [rad357pl] API delay: 5 Mar 27 17:13:01 volumiopn volumio[4341]: info: Loading plugin "gpio_control"... Mar 27 17:13:01 volumiopn volumio[4341]: gpiox_arm32 V2.2.1 Mar 27 17:13:01 volumiopn volumio[4403]: Forking 3 albumart workers Mar 27 17:13:01 volumiopn volumio[4341]: info: Applying required configuration parameters for plugin gpio_control Mar 27 17:13:01 volumiopn volumio[4341]: info: Loading plugin "peppymeterbasic"... Mar 27 17:13:01 volumiopn volumio[4341]: info: Plugin peppyspectrum is not enabled Mar 27 17:13:01 volumiopn volumio[4341]: info: Loading plugin "touch_display"... Mar 27 17:13:01 volumiopn volumio[4341]: info: Applying required configuration parameters for plugin touch_display Mar 27 17:13:01 volumiopn volumio[4341]: info: Loading i18n strings for locale pl Mar 27 17:13:02 volumiopn volumio[4341]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Mar 27 17:13:02 volumiopn volumio[4341]: Updating browse sources language Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::initPlayerControls Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 27 17:13:02 volumiopn volumio[4341]: Express server listening on port 3000 Mar 27 17:13:02 volumiopn volumio[4341]: [Metrics] WebUI: 6s 21.28ms Mar 27 17:13:02 volumiopn volumio[4413]: Starting albumart workers Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreStateMachine::resetVolumioState Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreStateMachine::getcurrentVolume Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::volumioRetrievevolume Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 17:13:02 volumiopn volumio[4414]: Starting albumart workers Mar 27 17:13:02 volumiopn volumio[4341]: info: Volumio Network Manager: Network status updated: 1 Mar 27 17:13:02 volumiopn volumio[4415]: Starting albumart workers Mar 27 17:13:02 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Mar 27 17:13:02 volumiopn volumio[4341]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Mar 27 17:13:02 volumiopn volumio[4341]: info: VolumeController:: Volume=39 Mute =false Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreStateMachine::pushState Mar 27 17:13:02 volumiopn volumio[4341]: info: CorePlayQueue::getTrack 0 Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::volumioPushState Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreStateMachine::updateTrackBlock Mar 27 17:13:02 volumiopn volumio[4341]: info: CorePlayQueue::getTrackBlock Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::volumioRetrievevolume Mar 27 17:13:02 volumiopn volumio[4341]: info: Reloading queue from file Mar 27 17:13:02 volumiopn volumio-remote-updater[743]: [2026-03-27 17:13:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774627979 101 Mar 27 17:13:02 volumiopn volumio[4341]: 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: 2 Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreStateMachine::setRepeat null single undefined Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreStateMachine::pushState Mar 27 17:13:02 volumiopn volumio[4341]: info: CorePlayQueue::getTrack 0 Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::volumioPushState Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreStateMachine::setRandom null Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreStateMachine::pushState Mar 27 17:13:02 volumiopn volumio[4341]: info: CorePlayQueue::getTrack 0 Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::volumioPushState Mar 27 17:13:02 volumiopn volumio[4341]: info: Setting Device type: Raspberry PI Mar 27 17:13:02 volumiopn volumio[4341]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Mar 27 17:13:02 volumiopn volumio[4341]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 Mar 27 17:13:02 volumiopn volumio[4341]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Mar 27 17:13:02 volumiopn volumio[4341]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Mar 27 17:13:02 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Mar 27 17:13:02 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Mar 27 17:13:02 volumiopn volumio[4341]: info: VolumeController:: Volume=39 Mute =false Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreStateMachine::pushState Mar 27 17:13:02 volumiopn volumio[4341]: info: CorePlayQueue::getTrack 0 Mar 27 17:13:02 volumiopn volumio[4341]: info: CoreCommandRouter::volumioPushState Mar 27 17:13:02 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 27 17:13:03 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::volumioGetVisibleSources Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::volumioGetState Mar 27 17:13:03 volumiopn volumio[4341]: info: CorePlayQueue::getTrack 0 Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 27 17:13:03 volumiopn volumio[4341]: info: Received Get System Info Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 27 17:13:03 volumiopn volumio[4341]: info: Discovery: Getting this device information Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::volumioGetState Mar 27 17:13:03 volumiopn volumio[4341]: info: CorePlayQueue::getTrack 0 Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::volumioGetState Mar 27 17:13:03 volumiopn volumio[4341]: info: CorePlayQueue::getTrack 0 Mar 27 17:13:03 volumiopn volumio[4341]: info: Listing playlists Mar 27 17:13:03 volumiopn volumio[4341]: info: Completed loading Core Plugins Mar 27 17:13:03 volumiopn volumio[4341]: info: Preparing to generate the ALSA configuration file Mar 27 17:13:03 volumiopn volumio[4341]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Mar 27 17:13:03 volumiopn volumio[4341]: info: Reading ALSA contributions from plugins. Mar 27 17:13:03 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:03 volumiopn volumio[4341]: info: gpio-buttons: Socket connected to Volumio Mar 27 17:13:03 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:03 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:03 volumiopn volumio[4341]: info: Asound.conf file unchanged, so no further update is needed Mar 27 17:13:03 volumiopn volumio[4341]: info: Output device has changed, restarting MPD Mar 27 17:13:03 volumiopn volumio[4341]: info: Output device has changed, restarting Shairport Sync Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 17:13:03 volumiopn sudo[4479]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 27 17:13:03 volumiopn sudo[4479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:03 volumiopn sudo[4481]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 27 17:13:03 volumiopn sudo[4479]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:03 volumiopn sudo[4481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:03 volumiopn volumio[4341]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 27 17:13:03 volumiopn volumio[4341]: info: ___________ START PLUGINS ___________ Mar 27 17:13:03 volumiopn volumio[4341]: info: ControllerMpd::onStart: Initializing MPD Mar 27 17:13:03 volumiopn volumio[4341]: info: Creating MPD Configuration file Mar 27 17:13:03 volumiopn systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 27 17:13:03 volumiopn sudo[4489]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Mar 27 17:13:03 volumiopn sudo[4489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 17:13:03 volumiopn volumio[4341]: info: [1774627983433] CoreMusicLibrary::Adding element Serwery Mediów Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 17:13:03 volumiopn sudo[4491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 27 17:13:03 volumiopn sudo[4491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:03 volumiopn sudo[4491]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:03 volumiopn systemd[1]: mpd.service: Deactivated successfully. Mar 27 17:13:03 volumiopn sudo[4494]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 27 17:13:03 volumiopn sudo[4494]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:03 volumiopn systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 27 17:13:03 volumiopn volumio[4341]: info: UPNP Browser: Client initialized successfully Mar 27 17:13:03 volumiopn systemd[1]: mpd.service: Consumed 1.759s CPU time. Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 17:13:03 volumiopn systemd[1]: mpd.socket: Deactivated successfully. Mar 27 17:13:03 volumiopn systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 27 17:13:03 volumiopn systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 27 17:13:03 volumiopn volumio[4341]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 17:13:03 volumiopn systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 27 17:13:03 volumiopn systemd[1]: Starting mpd.service - Music Player Daemon... Mar 27 17:13:03 volumiopn systemd[1]: mpd.service: Deactivated successfully. Mar 27 17:13:03 volumiopn systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 27 17:13:03 volumiopn systemd[1]: mpd.socket: Deactivated successfully. Mar 27 17:13:03 volumiopn systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 27 17:13:03 volumiopn systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 27 17:13:03 volumiopn sudo[4489]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:03 volumiopn systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 27 17:13:03 volumiopn volumio[4341]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 27 17:13:03 volumiopn systemd[1]: Starting mpd.service - Music Player Daemon... Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 17:13:03 volumiopn volumio[4341]: info: [1774627983585] CoreMusicLibrary::Adding element Last_100 Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 17:13:03 volumiopn volumio[4341]: info: [1774627983588] CoreMusicLibrary::Adding element Webradio Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 27 17:13:03 volumiopn volumio[4341]: info: Initializing BBC Radios Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 17:13:03 volumiopn volumio[4341]: info: Creating Spotify config file Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:03 volumiopn sudo[4509]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 27 17:13:03 volumiopn sudo[4509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 27 17:13:03 volumiopn sudo[4509]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 17:13:03 volumiopn volumio[4341]: info: [1774627983807] CoreMusicLibrary::Adding element YouTube Music Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 17:13:03 volumiopn volumio[4341]: Cannot find translation for source YouTube Music Mar 27 17:13:03 volumiopn volumio[4341]: info: AutoStart - onStart - waiting for system ready state Mar 27 17:13:03 volumiopn volumio[4341]: info: AutoStart - Polling config: interval=5000ms, maxAttempts=60 Mar 27 17:13:03 volumiopn volumio[4341]: info: AutoStart - Maximum wait time: 300 seconds Mar 27 17:13:03 volumiopn volumio[4341]: info: AutoStart - Startup volume disabled Mar 27 17:13:03 volumiopn volumio[4341]: info: AutoStart - Check #1/60 - VOLUMIO_SYSTEM_STATUS = starting Mar 27 17:13:03 volumiopn volumio[4341]: info: gpio-buttons: Creating GPIO triggers... Mar 27 17:13:03 volumiopn volumio[4341]: info: gpio-buttons: GPIO3 configured: button1 -> shutdown Mar 27 17:13:03 volumiopn volumio[4341]: info: GPIOButtonLED: Starting plugin Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 27 17:13:03 volumiopn volumio[4341]: info: [1774627983820] CoreMusicLibrary::Adding element RADIO 357 Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 27 17:13:03 volumiopn volumio[4341]: Cannot find translation for source YouTube Music Mar 27 17:13:03 volumiopn volumio[4341]: Cannot find translation for source RADIO 357 Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Mar 27 17:13:03 volumiopn volumio[4341]: info: Loading i18n strings for locale pl Mar 27 17:13:03 volumiopn volumio[4341]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Mar 27 17:13:03 volumiopn sudo[4527]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd_aloop index=7 pcm_substreams=2 Mar 27 17:13:03 volumiopn sudo[4527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:03 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 27 17:13:03 volumiopn volumio[4341]: info: Volumio Calling Home Mar 27 17:13:03 volumiopn sudo[4527]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:03 volumiopn sudo[4530]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Mar 27 17:13:03 volumiopn sudo[4530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:03 volumiopn sudo[4530]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:03 volumiopn volumio[4341]: info: gpio-buttons: Started successfully Mar 27 17:13:03 volumiopn volumio[4341]: info: Preparing to generate the ALSA configuration file Mar 27 17:13:03 volumiopn sudo[4537]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Mar 27 17:13:03 volumiopn sudo[4537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:04 volumiopn sudo[4539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Mar 27 17:13:04 volumiopn sudo[4539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:04 volumiopn volumio[4341]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Mar 27 17:13:04 volumiopn volumio[4341]: info: Reading ALSA contributions from plugins. Mar 27 17:13:04 volumiopn volumio[4341]: info: touch_display: No backlight interface detected. Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn volumio[4341]: info: snd_dummy loaded Mar 27 17:13:04 volumiopn volumio[4341]: info: MPD Permissions set Mar 27 17:13:04 volumiopn volumio[4341]: info: MPD Permissions set Mar 27 17:13:04 volumiopn sudo[4541]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Mar 27 17:13:04 volumiopn sudo[4541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn volumio[4341]: info: Spotify config file written Mar 27 17:13:04 volumiopn sudo[4546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/cp -r /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/content.js /data/plugins/user_interface/touch_display/iframe_keyboard_bridge/manifest.json /data/volumiokioskextensions/IframeKeyboardBridge/ Mar 27 17:13:04 volumiopn sudo[4546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:04 volumiopn sudo[4546]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn sudo[4537]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:04 volumiopn sudo[4550]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 27 17:13:04 volumiopn sudo[4550]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn systemd[1]: Reloading. Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn volumio[4341]: info: touch_display: IframeKeyboardBridge extension installed successfully Mar 27 17:13:04 volumiopn volumio[4341]: info: GPIOButtonLED: dtoverlay already correct Mar 27 17:13:04 volumiopn volumio[4341]: info: GPIOButtonLED: LED+ on GPIO 22 Mar 27 17:13:04 volumiopn volumio[4341]: info: GPIOButtonLED: LED- on GPIO 4 Mar 27 17:13:04 volumiopn volumio[4341]: info: GPIOButtonLED: LED polarity = normal Mar 27 17:13:04 volumiopn volumio[4341]: info: GPIOButtonLED: LED blink slow Mar 27 17:13:04 volumiopn volumio[4341]: info: No need to fix Spotify hosts Mar 27 17:13:04 volumiopn volumio[4341]: info: touch_display: systemctl stop getty@tty1.service succeeded. Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn volumio[4341]: info: Starting Shairport Sync Mar 27 17:13:04 volumiopn volumio[4341]: info: Starting Shairport Sync Mar 27 17:13:04 volumiopn volumio[4341]: info: Starting Shairport Sync Mar 27 17:13:04 volumiopn volumio[4341]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Mar 27 17:13:04 volumiopn sudo[4566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 27 17:13:04 volumiopn sudo[4566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:04 volumiopn sudo[4564]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 27 17:13:04 volumiopn sudo[4564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:04 volumiopn sudo[4569]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Mar 27 17:13:04 volumiopn sudo[4567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 27 17:13:04 volumiopn sudo[4567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn sudo[4572]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Mar 27 17:13:04 volumiopn sudo[4572]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:04 volumiopn sudo[4569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:04 volumiopn volumio[4341]: info: Asound.conf file unchanged, so no further update is needed Mar 27 17:13:04 volumiopn volumio[4341]: info: Output device has changed, restarting MPD Mar 27 17:13:04 volumiopn sudo[4569]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:04 volumiopn sudo[4572]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:04 volumiopn volumio[4341]: info: Output device has changed, restarting Shairport Sync Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 17:13:04 volumiopn sudo[4595]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 27 17:13:04 volumiopn sudo[4595]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:04 volumiopn sudo[4595]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:04 volumiopn volumio[4341]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 27 17:13:04 volumiopn sudo[4599]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 27 17:13:04 volumiopn sudo[4599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn volumio[4341]: info: MPD Permissions set Mar 27 17:13:04 volumiopn volumio[4341]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Mar 27 17:13:04 volumiopn volumio[4341]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn volumio[4341]: info: Starting Shairport Sync Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn sudo[4613]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 27 17:13:04 volumiopn sudo[4613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:04 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:05 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:05 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:05 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:05 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:05 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:05 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:05 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:05 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:05 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:05 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:05 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7 Mar 27 17:13:05 volumiopn 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. Mar 27 17:13:05 volumiopn 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. Mar 27 17:13:05 volumiopn sudo[4541]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:05 volumiopn volumio[4341]: info: touch_display: systemctl daemon-reload succeeded. Mar 27 17:13:05 volumiopn systemd[1]: Reloading. Mar 27 17:13:05 volumiopn sudo[4617]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Mar 27 17:13:05 volumiopn sudo[4617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:05 volumiopn mpd[4524]: 2026-03-27T17:13:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 27 17:13:06 volumiopn volumio[4341]: info: GPIOButtonLED: Boot complete - LED solid Mar 27 17:13:06 volumiopn 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. Mar 27 17:13:06 volumiopn 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. Mar 27 17:13:06 volumiopn systemd[1]: Started mpd.service - Music Player Daemon. Mar 27 17:13:06 volumiopn sudo[4539]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:06 volumiopn volumio[4341]: info: touch_display: systemctl disable getty@tty1.service succeeded. Mar 27 17:13:06 volumiopn sudo[4494]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:06 volumiopn sudo[4481]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:06 volumiopn volumio[4341]: error: MPD error: The expression evaluated to a falsy value: Mar 27 17:13:06 volumiopn volumio[4341]: assert.ok(self.idling) Mar 27 17:13:06 volumiopn volumio[4341]: error: The expression evaluated to a falsy value: Mar 27 17:13:06 volumiopn volumio[4341]: assert.ok(self.idling) Mar 27 17:13:06 volumiopn volumio[4341]: info: MPD running with PID4524 Mar 27 17:13:06 volumiopn volumio[4341]: ,establishing connection Mar 27 17:13:06 volumiopn volumio[4341]: error: updateQueue error: null Mar 27 17:13:06 volumiopn volumio[4341]: error: updateQueue error: null Mar 27 17:13:06 volumiopn systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 27 17:13:06 volumiopn systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 27 17:13:06 volumiopn systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 27 17:13:06 volumiopn sudo[4617]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:06 volumiopn volumio[4341]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Mar 27 17:13:06 volumiopn volumio[4341]: info: touch_display: Volumio Kiosk started. Mar 27 17:13:06 volumiopn systemd[1]: shairport-sync.service: Deactivated successfully. Mar 27 17:13:06 volumiopn systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 27 17:13:06 volumiopn systemd[1]: shairport-sync.service: Consumed 2.040s CPU time. Mar 27 17:13:06 volumiopn systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 27 17:13:06 volumiopn systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 27 17:13:06 volumiopn systemd[1]: mpd.service: Deactivated successfully. Mar 27 17:13:06 volumiopn systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 27 17:13:06 volumiopn systemd[1]: mpd.service: Consumed 2.040s CPU time. Mar 27 17:13:06 volumiopn volumio[4341]: info: CoreCommandRouter::volumioGetState Mar 27 17:13:06 volumiopn volumio[4341]: info: CorePlayQueue::getTrack 0 Mar 27 17:13:06 volumiopn volumio[4341]: info: Completed starting Core Plugins Mar 27 17:13:06 volumiopn volumio[4341]: info: ------------------------------------------- Mar 27 17:13:06 volumiopn volumio[4341]: info: ----- MyVolumio plugins startup ---- Mar 27 17:13:06 volumiopn volumio[4341]: info: ------------------------------------------- Mar 27 17:13:06 volumiopn volumio[4341]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 27 17:13:06 volumiopn systemd[1]: mpd.socket: Deactivated successfully. Mar 27 17:13:06 volumiopn systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 27 17:13:06 volumiopn systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 27 17:13:06 volumiopn systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 27 17:13:06 volumiopn systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 27 17:13:06 volumiopn sudo[4550]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:06 volumiopn go-librespot[4644]: go-librespot daemon starting... Mar 27 17:13:06 volumiopn systemd[1]: Starting mpd.service - Music Player Daemon... Mar 27 17:13:06 volumiopn systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 27 17:13:06 volumiopn sudo[4567]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:06 volumiopn sudo[4564]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:06 volumiopn sudo[4566]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:06 volumiopn go-librespot[4645]: time="2026-03-27T17:13:06+01:00" level=info msg="running go-librespot 0.6.2" Mar 27 17:13:06 volumiopn go-librespot[4645]: time="2026-03-27T17:13:06+01:00" level=debug msg="app state loaded" Mar 27 17:13:06 volumiopn sudo[4613]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:06 volumiopn volumio[4341]: info: Shairport-Sync Started Mar 27 17:13:06 volumiopn go-librespot[4645]: time="2026-03-27T17:13:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 27 17:13:06 volumiopn volumio[4341]: Error adding Membership: Error: addMembership EINVAL Mar 27 17:13:06 volumiopn volumio[4341]: info: Shairport-Sync Started Mar 27 17:13:06 volumiopn volumio[4341]: info: Shairport-Sync Started Mar 27 17:13:06 volumiopn volumio[4341]: info: Shairport-Sync Started Mar 27 17:13:06 volumiopn volumio[4341]: info: touch_display: X display number found: 0 Mar 27 17:13:06 volumiopn volumio[4341]: info: touch_display: X display number found: 0 Mar 27 17:13:07 volumiopn sudo[4646]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 27 17:13:07 volumiopn sudo[4646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 27 17:13:07 volumiopn volumio[4341]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Mar 27 17:13:07 volumiopn sudo[4646]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:07 volumiopn volumio[4341]: info: CoreCommandRouter::volumioGetState Mar 27 17:13:07 volumiopn volumio[4341]: info: CorePlayQueue::getTrack 0 Mar 27 17:13:07 volumiopn volumio[4341]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 27 17:13:07 volumiopn volumio[4341]: info: touch_display: X display number found: 0 Mar 27 17:13:08 volumiopn sudo[4694]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 27 17:13:08 volumiopn sudo[4694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:08 volumiopn sudo[4694]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:08 volumiopn sudo[4696]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 27 17:13:08 volumiopn sudo[4696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:08 volumiopn sudo[4696]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:08 volumiopn sudo[4699]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 27 17:13:08 volumiopn sudo[4699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 27 17:13:08 volumiopn sudo[4699]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:08 volumiopn volumio[4341]: info: Upmpdcli Daemon Started Mar 27 17:13:08 volumiopn mpd[4674]: 2026-03-27T17:13:08 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 27 17:13:08 volumiopn systemd[1]: Started mpd.service - Music Player Daemon. Mar 27 17:13:08 volumiopn sudo[4599]: pam_unix(sudo:session): session closed for user root Mar 27 17:13:08 volumiopn volumio[4341]: error: updateQueue error: null Mar 27 17:13:08 volumiopn volumio[4341]: info: AutoStart - Check #2/60 - VOLUMIO_SYSTEM_STATUS = starting Mar 27 17:13:09 volumiopn volumio[4341]: info: go-librespot daemon successfully initialized Mar 27 17:13:11 volumiopn volumio[4341]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 27 17:13:12 volumiopn volumio[4341]: info: Initializing connection to go-librespot Websocket Mar 27 17:13:13 volumiopn volumio[4341]: info: AutoStart - Check #3/60 - VOLUMIO_SYSTEM_STATUS = starting Mar 27 17:13:18 volumiopn systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Mar 27 17:13:18 volumiopn volumio[4341]: info: AutoStart - Check #4/60 - VOLUMIO_SYSTEM_STATUS = starting Mar 27 17:13:23 volumiopn volumio[4341]: info: AutoStart - Check #5/60 - VOLUMIO_SYSTEM_STATUS = starting Mar 27 17:13:24 volumiopn go-librespot[4645]: time="2026-03-27T17:13:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 27 17:13:24 volumiopn systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 27 17:13:24 volumiopn systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 27 17:13:26 volumiopn volumio[4341]: error: MyVolumio Plugin failed to start in a timely fashion Mar 27 17:13:26 volumiopn volumio[4341]: [Metrics] CommandRouter: 30s 248.48ms Mar 27 17:13:26 volumiopn volumio[4341]: info: CoreCommandRouter::volumiosetStartupVolume Mar 27 17:13:26 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 27 17:13:26 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 17:13:26 volumiopn volumio[4341]: info: CoreCommandRouter::Close All Modals sent Mar 27 17:13:26 volumiopn volumio[4341]: info: CoreCommandRouter::Close All Modals sent Mar 27 17:13:27 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 27 17:13:27 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 27 17:13:27 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 27 17:13:28 volumiopn systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 27 17:13:28 volumiopn systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 27 17:13:28 volumiopn systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 27 17:13:28 volumiopn go-librespot[4758]: go-librespot daemon starting... Mar 27 17:13:28 volumiopn go-librespot[4759]: time="2026-03-27T17:13:28+01:00" level=info msg="running go-librespot 0.6.2" Mar 27 17:13:28 volumiopn go-librespot[4759]: time="2026-03-27T17:13:28+01:00" level=debug msg="app state loaded" Mar 27 17:13:28 volumiopn go-librespot[4759]: time="2026-03-27T17:13:28+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 27 17:13:28 volumiopn volumio[4341]: info: AutoStart - Check #6/60 - VOLUMIO_SYSTEM_STATUS = starting Mar 27 17:13:31 volumiopn volumio[4341]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.104&uuid=e7c25e6c3870fe05b078c38d4c5df6fa" http://updates.volumio.org/downloader-v1/track-device Mar 27 17:13:31 volumiopn volumio[4341]: % Total % Received % Xferd Average Speed Time Time Time Current Mar 27 17:13:31 volumiopn volumio[4341]: Dload Upload Total Spent Left Speed Mar 27 17:13:31 volumiopn volumio[4341]: [1.5K blob data] Mar 27 17:13:31 volumiopn volumio[4341]: retrying in 5 seconds, trial 0 Mar 27 17:13:31 volumiopn volumio[4341]: info: Volumio Calling Home Mar 27 17:13:33 volumiopn volumio[4341]: info: BOOT COMPLETED Mar 27 17:13:33 volumiopn volumio[4341]: info: AutoStart - Check #7/60 - VOLUMIO_SYSTEM_STATUS = ready Mar 27 17:13:33 volumiopn volumio[4341]: info: AutoStart - System ready state CONFIRMED after 7 checks Mar 27 17:13:33 volumiopn volumio[4341]: info: AutoStart - Applying additional delay of 5000ms before playback Mar 27 17:13:33 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 27 17:13:33 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 27 17:13:33 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 27 17:13:38 volumiopn volumio[4341]: info: AutoStart - startPlayback called Mar 27 17:13:38 volumiopn volumio[4341]: info: CoreCommandRouter::volumioGetQueue Mar 27 17:13:38 volumiopn volumio[4341]: info: CoreStateMachine::getQueue Mar 27 17:13:38 volumiopn volumio[4341]: info: CorePlayQueue::getQueue Mar 27 17:13:38 volumiopn volumio[4341]: info: AutoStart - Queue has 1 items Mar 27 17:13:38 volumiopn volumio[4341]: info: AutoStart - Playing from position 0 Mar 27 17:13:38 volumiopn volumio[4341]: info: CoreCommandRouter::volumioPlay Mar 27 17:13:38 volumiopn volumio[4341]: info: CoreStateMachine::play index 0 Mar 27 17:13:38 volumiopn volumio[4341]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 27 17:13:38 volumiopn volumio[4341]: info: CoreStateMachine::stop Mar 27 17:13:38 volumiopn volumio[4341]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 27 17:13:38 volumiopn volumio[4341]: info: CoreStateMachine::play index undefined Mar 27 17:13:38 volumiopn volumio[4341]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 27 17:13:38 volumiopn volumio[4341]: info: CorePlayQueue::getTrack 0 Mar 27 17:13:38 volumiopn volumio[4341]: info: CoreStateMachine::startPlaybackTimer Mar 27 17:13:38 volumiopn volumio[4341]: info: CorePlayQueue::getTrack 0 Mar 27 17:13:38 volumiopn volumio[4341]: verbose: ControllerMpd::sendMpdCommand stop Mar 27 17:13:38 volumiopn volumio[4341]: info: sendMpdCommand stop took 1 milliseconds Mar 27 17:13:38 volumiopn volumio[4341]: verbose: ControllerMpd::sendMpdCommand clear Mar 27 17:13:38 volumiopn volumio[4341]: info: Mar 27 17:13:38 volumiopn volumio[4341]: ---------------------------- MPD announces system playlist update Mar 27 17:13:38 volumiopn volumio[4341]: info: Ignoring MPD Status Update Mar 27 17:13:38 volumiopn volumio[4341]: info: sendMpdCommand clear took 2 milliseconds Mar 27 17:13:38 volumiopn volumio[4341]: verbose: ControllerMpd::sendMpdCommand add "http://stream.rcs.revma.com/ye5kghkgcm0uv" Mar 27 17:13:38 volumiopn volumio[4341]: error: updateQueue error: null Mar 27 17:13:38 volumiopn volumio[4341]: info: Mar 27 17:13:38 volumiopn volumio[4341]: ---------------------------- MPD announces system playlist update Mar 27 17:13:38 volumiopn volumio[4341]: info: Ignoring MPD Status Update Mar 27 17:13:38 volumiopn volumio[4341]: info: ------------------------------ 4ms Mar 27 17:13:38 volumiopn volumio[4341]: info: sendMpdCommand add "http://stream.rcs.revma.com/ye5kghkgcm0uv" took 2 milliseconds Mar 27 17:13:38 volumiopn volumio[4341]: verbose: ControllerMpd::sendMpdCommand play Mar 27 17:13:38 volumiopn volumio[4341]: info: ------------------------------ 8ms Mar 27 17:13:38 volumiopn volumio[4341]: info: sendMpdCommand play took 4 milliseconds Mar 27 17:13:38 volumiopn volumio[4341]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 27 17:13:39 volumiopn volumio[4341]: info: Discovery: adding 5fe83176-f09b-4665-9e58-0874d7d6c4be Mar 27 17:13:39 volumiopn volumio[4341]: info: Discovery: Found device VolumioPN Mar 27 17:13:39 volumiopn volumio[4341]: info: CoreCommandRouter::volumioGetState Mar 27 17:13:39 volumiopn volumio[4341]: info: Discovery: this is already registered, 5fe83176-f09b-4665-9e58-0874d7d6c4be Mar 27 17:13:39 volumiopn volumio[4341]: info: Discovery: Found device VolumioPN Mar 27 17:13:39 volumiopn volumio[4341]: info: CoreCommandRouter::volumioGetState Mar 27 17:13:39 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Mar 27 17:13:39 volumiopn volumio[4341]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Mar 27 17:13:46 volumiopn go-librespot[4759]: time="2026-03-27T17:13:46+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 27 17:13:46 volumiopn systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 27 17:13:46 volumiopn systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 27 17:13:49 volumiopn systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 27 17:13:49 volumiopn systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 27 17:13:49 volumiopn systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 27 17:13:49 volumiopn go-librespot[4805]: go-librespot daemon starting... Mar 27 17:13:49 volumiopn go-librespot[4806]: time="2026-03-27T17:13:49+01:00" level=info msg="running go-librespot 0.6.2" Mar 27 17:13:49 volumiopn go-librespot[4806]: time="2026-03-27T17:13:49+01:00" level=debug msg="app state loaded" Mar 27 17:13:49 volumiopn go-librespot[4806]: time="2026-03-27T17:13:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 27 17:13:56 volumiopn volumio[4341]: info: Mar 27 17:13:56 volumiopn volumio[4341]: ---------------------------- MPD announces state update: player Mar 27 17:13:56 volumiopn volumio[4341]: info: ControllerMpd::getState Mar 27 17:13:56 volumiopn volumio[4341]: verbose: ControllerMpd::sendMpdCommand status Mar 27 17:13:56 volumiopn volumio[4341]: info: Mar 27 17:13:56 volumiopn volumio[4341]: ---------------------------- MPD announces state update: player Mar 27 17:13:56 volumiopn volumio[4341]: info: ControllerMpd::getState Mar 27 17:13:56 volumiopn volumio[4341]: verbose: ControllerMpd::sendMpdCommand status Mar 27 17:13:56 volumiopn volumio[4341]: error: MPD returned error for command status: Failed to decode "http://stream.rcs.revma.com/ye5kghkgcm0uv"; Resolving timed out after 10260 milliseconds: Timeout was reached Mar 27 17:13:56 volumiopn volumio[4341]: verbose: ControllerMpd::sendMpdCommand clearerror Mar 27 17:13:56 volumiopn volumio[4341]: info: sendMpdCommand status took 8 milliseconds Mar 27 17:13:56 volumiopn volumio[4341]: verbose: ControllerMpd::parseState Mar 27 17:13:56 volumiopn volumio[4341]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 17:13:56 volumiopn volumio[4341]: error: MPD returned error for command status: Failed to decode "http://stream.rcs.revma.com/ye5kghkgcm0uv"; Resolving timed out after 10260 milliseconds: Timeout was reached Mar 27 17:13:56 volumiopn volumio[4341]: verbose: ControllerMpd::sendMpdCommand clearerror Mar 27 17:13:56 volumiopn volumio[4341]: info: sendMpdCommand status took 19 milliseconds Mar 27 17:13:56 volumiopn volumio[4341]: info: sendMpdCommand clearerror took 15 milliseconds Mar 27 17:13:56 volumiopn volumio[4341]: info: sendMpdCommand playlistinfo took 8 milliseconds Mar 27 17:13:56 volumiopn volumio[4341]: verbose: ControllerMpd::parseState Mar 27 17:13:56 volumiopn volumio[4341]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 27 17:13:56 volumiopn volumio[4341]: verbose: ControllerMpd::parseTrackInfo Mar 27 17:13:56 volumiopn volumio[4341]: info: ControllerMpd::pushState Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreCommandRouter::servicePushState Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreStateMachine::pushState Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreCommandRouter::volumioPushState Mar 27 17:13:56 volumiopn volumio[4341]: info: CorePlayQueue::getTrack 0 Mar 27 17:13:56 volumiopn volumio[4341]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"ye5kghkgcm0uv","artist":null,"album":null,"uri":"http://stream.rcs.revma.com/ye5kghkgcm0uv","trackType":""} Mar 27 17:13:56 volumiopn volumio[4341]: verbose: CURRENT POSITION 0 Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreStateMachine::syncState stateService stop Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreStateMachine::syncState currentStatus stop Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreStateMachine::pushState Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreCommandRouter::volumioPushState Mar 27 17:13:56 volumiopn volumio[4341]: info: No code Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreStateMachine::pushState Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreCommandRouter::volumioPushState Mar 27 17:13:56 volumiopn volumio5-onboarding[1452]: time=2026-03-27T17:13:56.922+01:00 level=WARN msg="received unknown player status" component=volumio status="" Mar 27 17:13:56 volumiopn volumio5-onboarding[1452]: time=2026-03-27T17:13:56.924+01:00 level=WARN msg="received unknown player status" component=volumio status="" Mar 27 17:13:56 volumiopn volumio5-onboarding[1452]: time=2026-03-27T17:13:56.925+01:00 level=WARN msg="received unknown player status" component=volumio status="" Mar 27 17:13:56 volumiopn volumio[4341]: info: ------------------------------ 57ms Mar 27 17:13:56 volumiopn volumio[4341]: info: sendMpdCommand clearerror took 35 milliseconds Mar 27 17:13:56 volumiopn volumio[4341]: info: sendMpdCommand playlistinfo took 34 milliseconds Mar 27 17:13:56 volumiopn volumio[4341]: verbose: ControllerMpd::parseTrackInfo Mar 27 17:13:56 volumiopn volumio[4341]: info: ControllerMpd::pushState Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreCommandRouter::servicePushState Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreStateMachine::pushState Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreCommandRouter::volumioPushState Mar 27 17:13:56 volumiopn volumio[4341]: info: CorePlayQueue::getTrack 0 Mar 27 17:13:56 volumiopn volumio[4341]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"ye5kghkgcm0uv","artist":null,"album":null,"uri":"http://stream.rcs.revma.com/ye5kghkgcm0uv","trackType":""} Mar 27 17:13:56 volumiopn volumio[4341]: verbose: CURRENT POSITION 0 Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreStateMachine::syncState stateService stop Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreStateMachine::syncState currentStatus stop Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreStateMachine::pushState Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreCommandRouter::volumioPushState Mar 27 17:13:56 volumiopn volumio[4341]: info: No code Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreStateMachine::pushState Mar 27 17:13:56 volumiopn volumio[4341]: info: CoreCommandRouter::volumioPushState Mar 27 17:13:56 volumiopn volumio5-onboarding[1452]: time=2026-03-27T17:13:56.955+01:00 level=WARN msg="received unknown player status" component=volumio status="" Mar 27 17:13:56 volumiopn volumio5-onboarding[1452]: time=2026-03-27T17:13:56.956+01:00 level=WARN msg="received unknown player status" component=volumio status="" Mar 27 17:13:56 volumiopn volumio5-onboarding[1452]: time=2026-03-27T17:13:56.958+01:00 level=WARN msg="received unknown player status" component=volumio status="" Mar 27 17:13:56 volumiopn volumio[4341]: info: ------------------------------ 87ms Mar 27 17:13:57 volumiopn volumio[4341]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo ENOTFOUND oauth-performer.prod.vlmapi.io Mar 27 17:14:00 volumiopn volumio[4341]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.104&uuid=e7c25e6c3870fe05b078c38d4c5df6fa" http://updates.volumio.org/downloader-v1/track-device Mar 27 17:14:00 volumiopn volumio[4341]: % Total % Received % Xferd Average Speed Time Time Time Current Mar 27 17:14:00 volumiopn volumio[4341]: Dload Upload Total Spent Left Speed Mar 27 17:14:00 volumiopn volumio[4341]: [1.5K blob data] Mar 27 17:14:00 volumiopn volumio[4341]: retrying in 5 seconds, trial 1 Mar 27 17:14:00 volumiopn volumio[4341]: info: Volumio Calling Home Mar 27 17:14:07 volumiopn go-librespot[4806]: time="2026-03-27T17:14:07+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 27 17:14:07 volumiopn systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 27 17:14:07 volumiopn systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 27 17:14:10 volumiopn systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 27 17:14:10 volumiopn systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 27 17:14:10 volumiopn systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 27 17:14:10 volumiopn go-librespot[4847]: go-librespot daemon starting... Mar 27 17:14:10 volumiopn go-librespot[4848]: time="2026-03-27T17:14:10+01:00" level=info msg="running go-librespot 0.6.2" Mar 27 17:14:10 volumiopn go-librespot[4848]: time="2026-03-27T17:14:10+01:00" level=debug msg="app state loaded" Mar 27 17:14:10 volumiopn go-librespot[4848]: time="2026-03-27T17:14:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 27 17:14:15 volumiopn go-librespot[4848]: time="2026-03-27T17:14:15+01:00" level=debug msg="new websocket client" Mar 27 17:14:15 volumiopn volumio[4341]: info: Connection to go-librespot Websocket established Mar 27 17:14:18 volumiopn volumio[4341]: info: Getting Spotify volume Mar 27 17:14:28 volumiopn volumio[4341]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.104&uuid=e7c25e6c3870fe05b078c38d4c5df6fa" http://updates.volumio.org/downloader-v1/track-device Mar 27 17:14:28 volumiopn volumio[4341]: % Total % Received % Xferd Average Speed Time Time Time Current Mar 27 17:14:28 volumiopn volumio[4341]: Dload Upload Total Spent Left Speed Mar 27 17:14:28 volumiopn volumio[4341]: [1.5K blob data] Mar 27 17:14:28 volumiopn volumio[4341]: retrying in 5 seconds, trial 2 Mar 27 17:14:28 volumiopn volumio[4341]: info: Volumio Calling Home Mar 27 17:14:28 volumiopn go-librespot[4848]: time="2026-03-27T17:14:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 27 17:14:28 volumiopn systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 27 17:14:28 volumiopn volumio[4341]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 27 17:14:28 volumiopn systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 27 17:14:28 volumiopn volumio[4341]: Error: socket hang up Mar 27 17:14:28 volumiopn volumio[4341]: at connResetException (node:internal/errors:720:14) Mar 27 17:14:28 volumiopn volumio[4341]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 27 17:14:28 volumiopn volumio[4341]: at Socket.emit (node:events:526:35) Mar 27 17:14:28 volumiopn volumio[4341]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 27 17:14:28 volumiopn volumio[4341]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 27 17:14:28 volumiopn volumio[4341]: code: 'ECONNRESET', Mar 27 17:14:28 volumiopn volumio[4341]: response: undefined Mar 27 17:14:28 volumiopn volumio[4341]: } Mar 27 17:14:28 volumiopn volumio[4341]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 27 17:14:29 volumiopn sudo[4904]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-27 17:13' Mar 27 17:14:29 volumiopn sudo[4904]: 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="7a00388c05f7c476e375410e75778bd28211ce87" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 13 15:36:25 UTC 2026" VOLUMIO_VERSION="4.104" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="c0a6c64d0b6ca4fe7beeef2e593f362f"