Mar 04 16:21:23 volumiorrr ntpd[1111]: CLOCK: time stepped by 1449427.543857 Mar 04 16:21:23 volumiorrr ntpd[1111]: CLOCK: time changed from 2026-02-15 to 2026-03-04 Mar 04 16:21:23 volumiorrr ntpd[1111]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Mar 04 16:21:24 volumiorrr volumio[1336]: info: Loading plugin "network"... Mar 04 16:21:24 volumiorrr volumio[1336]: info: Refreshing Cached IP Addresses Mar 04 16:21:24 volumiorrr sudo[1434]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 16:21:24 volumiorrr sudo[1434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:24 volumiorrr sudo[1432]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 16:21:24 volumiorrr sudo[1432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:24 volumiorrr sudo[1434]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:24 volumiorrr sudo[1432]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:24 volumiorrr sudo[1443]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 04 16:21:24 volumiorrr volumio[1336]: info: Loading plugin "services"... Mar 04 16:21:24 volumiorrr sudo[1443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:24 volumiorrr volumio[1336]: info: Loading plugin "volumio5onboarding"... Mar 04 16:21:24 volumiorrr volumio[1336]: info: Loading plugin "alsa_controller"... Mar 04 16:21:24 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 16:21:24 volumiorrr volumio[1336]: info: Loading plugin "wizard"... Mar 04 16:21:24 volumiorrr volumio[1336]: info: Loading plugin "networkfs"... Mar 04 16:21:24 volumiorrr volumio[1336]: info: Starting Udev Watcher for removable devices Mar 04 16:21:24 volumiorrr volumio[1336]: info: Ignoring mount for partition: boot Mar 04 16:21:24 volumiorrr volumio[1336]: info: Ignoring mount for partition: volumio Mar 04 16:21:24 volumiorrr volumio[1336]: info: Ignoring mount for partition: volumio_data Mar 04 16:21:24 volumiorrr volumio[1336]: info: Mounting Device Elements Mar 04 16:21:25 volumiorrr sudo[1473]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/Elements -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 04 16:21:25 volumiorrr sudo[1473]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:26 volumiorrr sudo[1473]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:26 volumiorrr ntfs-3g[1476]: Version 2022.10.3 integrated FUSE 28 Mar 04 16:21:26 volumiorrr ntfs-3g[1476]: Mounted /dev/sda1 (Read-Write, label "Elements", NTFS 3.1) Mar 04 16:21:26 volumiorrr ntfs-3g[1476]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Mar 04 16:21:26 volumiorrr ntfs-3g[1476]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda1,blkdev,blksize=4096 Mar 04 16:21:26 volumiorrr ntfs-3g[1476]: Global ownership and permissions enforced, configuration type 7 Mar 04 16:21:26 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 16:21:26 volumiorrr volumio[1336]: info: Loading plugin "volumio_command_line_client"... Mar 04 16:21:26 volumiorrr volumio[1336]: info: Loading plugin "upnp"... Mar 04 16:21:26 volumiorrr volumio[1336]: info: [1772637686656] Starting Upmpd Daemon Mar 04 16:21:26 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 16:21:26 volumiorrr volumio[1336]: info: Loading plugin "my_music"... Mar 04 16:21:26 volumiorrr volumio[1336]: info: Loading plugin "mpd"... Mar 04 16:21:26 volumiorrr systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Mar 04 16:21:26 volumiorrr systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Mar 04 16:21:26 volumiorrr systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Mar 04 16:21:26 volumiorrr systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Mar 04 16:21:26 volumiorrr systemd[1]: e2scrub_all.service: Deactivated successfully. Mar 04 16:21:26 volumiorrr systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Mar 04 16:21:26 volumiorrr volumio-remote-updater[816]: [2026-03-04 16:21:26] [connect] Successful connection Mar 04 16:21:27 volumiorrr systemd[1]: dpkg-db-backup.service: Deactivated successfully. Mar 04 16:21:27 volumiorrr systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Mar 04 16:21:27 volumiorrr sudo[1443]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:27 volumiorrr volumio[1336]: info: Loading plugin "upnp_browser"... Mar 04 16:21:28 volumiorrr volumio[1336]: info: Starting UPNP Browser Mar 04 16:21:28 volumiorrr volumio[1336]: info: Loading plugin "alarm-clock"... Mar 04 16:21:28 volumiorrr volumio[1336]: info: Loading plugin "airplay_emulation"... Mar 04 16:21:28 volumiorrr volumio[1336]: info: Starting Shairport Sync Mar 04 16:21:28 volumiorrr volumio[1336]: info: Loading plugin "last_100"... Mar 04 16:21:28 volumiorrr volumio[1336]: info: Loading plugin "webradio"... Mar 04 16:21:29 volumiorrr volumio[1336]: info: Loading plugin "i2s_dacs"... Mar 04 16:21:29 volumiorrr volumio[1336]: info: I2S DAC not set, start Auto-detection Mar 04 16:21:29 volumiorrr volumio[1336]: info: Loading plugin "volumiodiscovery"... Mar 04 16:21:29 volumiorrr volumio[1336]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 16:21:29 volumiorrr volumio[1336]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 16:21:29 volumiorrr volumio[1336]: *** WARNING *** For more information see Mar 04 16:21:29 volumiorrr volumio[1336]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 16:21:29 volumiorrr volumio[1336]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 16:21:29 volumiorrr node[1336]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 16:21:29 volumiorrr volumio[1336]: *** WARNING *** For more information see Mar 04 16:21:29 volumiorrr node[1336]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 16:21:29 volumiorrr node[1336]: *** WARNING *** For more information see Mar 04 16:21:29 volumiorrr node[1336]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 16:21:29 volumiorrr node[1336]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 16:21:29 volumiorrr node[1336]: *** WARNING *** For more information see Mar 04 16:21:29 volumiorrr volumio[1336]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 04 16:21:29 volumiorrr volumio[1336]: info: Discovery: Started advertising with name: VolumioRRR Mar 04 16:21:29 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 16:21:29 volumiorrr volumio[1336]: info: Loading plugin "calmradio"... Mar 04 16:21:30 volumiorrr systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Mar 04 16:21:31 volumiorrr systemd[1]: systemd-fsckd.service: Deactivated successfully. Mar 04 16:21:32 volumiorrr systemd[1]: setdatetime-helper.service: Deactivated successfully. Mar 04 16:21:32 volumiorrr systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Mar 04 16:21:32 volumiorrr volumio[1336]: info: Loading plugin "ytmusic"... Mar 04 16:21:34 volumiorrr volumio[1336]: info: Plugin now_playing is not enabled Mar 04 16:21:34 volumiorrr volumio[1336]: info: Loading plugin "outputs"... Mar 04 16:21:34 volumiorrr volumio[1336]: info: Loading plugin "albumart"... Mar 04 16:21:34 volumiorrr volumio[1336]: info: Plugin example_plugin is not enabled Mar 04 16:21:34 volumiorrr volumio[1336]: info: Loading plugin "inputs"... Mar 04 16:21:34 volumiorrr volumio[1336]: info: Loading plugin "updater_comm"... Mar 04 16:21:34 volumiorrr volumio[1336]: info: Plugin mpdemulation is not enabled Mar 04 16:21:34 volumiorrr volumio[1336]: info: Loading plugin "rest_api"... Mar 04 16:21:34 volumiorrr volumio[1336]: info: Loading plugin "websocket"... Mar 04 16:21:34 volumiorrr volumio[1336]: info: Starting Socket.io Server version 1.7.4 Mar 04 16:21:34 volumiorrr volumio[1336]: info: Loading plugin "fusiondsp"... Mar 04 16:21:35 volumiorrr volumio[1520]: Forking 3 albumart workers Mar 04 16:21:35 volumiorrr systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Mar 04 16:21:35 volumiorrr systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 04 16:21:35 volumiorrr systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 04 16:21:35 volumiorrr upmpdcli[1547]: Could not open config: /tmp/upmpdcli.conf Mar 04 16:21:35 volumiorrr systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Mar 04 16:21:35 volumiorrr systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Mar 04 16:21:37 volumiorrr systemd[1]: systemd-hostnamed.service: Deactivated successfully. Mar 04 16:21:37 volumiorrr volumio[1336]: info: Applying required configuration parameters for plugin fusiondsp Mar 04 16:21:38 volumiorrr volumio[1336]: info: Loading plugin "motherearthradio"... Mar 04 16:21:38 volumiorrr volumio[1336]: info: Loading plugin "peppymeterbasic"... Mar 04 16:21:39 volumiorrr volumio[1546]: Starting albumart workers Mar 04 16:21:39 volumiorrr volumio[1545]: Starting albumart workers Mar 04 16:21:40 volumiorrr volumio[1544]: Starting albumart workers Mar 04 16:21:41 volumiorrr volumio[1336]: info: Plugin peppyspectrum is not enabled Mar 04 16:21:41 volumiorrr volumio[1336]: info: Loading plugin "touch_display"... Mar 04 16:21:41 volumiorrr volumio-remote-updater[816]: [2026-03-04 16:21:41] [connect] Successful connection Mar 04 16:21:42 volumiorrr volumio[1336]: info: Applying required configuration parameters for plugin touch_display Mar 04 16:21:43 volumiorrr volumio[1336]: info: Loading i18n strings for locale es Mar 04 16:21:43 volumiorrr volumio[1336]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Mar 04 16:21:43 volumiorrr volumio[1336]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Mar 04 16:21:43 volumiorrr volumio[1336]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Mar 04 16:21:43 volumiorrr volumio[1336]: Updating browse sources language Mar 04 16:21:43 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 16:21:44 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 16:21:44 volumiorrr volumio[1336]: info: CoreCommandRouter::initPlayerControls Mar 04 16:21:44 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:44 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:44 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:44 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:44 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:44 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:44 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:44 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:44 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 16:21:44 volumiorrr volumio[1336]: Express server listening on port 3000 Mar 04 16:21:44 volumiorrr volumio[1336]: [Metrics] WebUI: 25s 359.55ms Mar 04 16:21:44 volumiorrr volumio[1336]: info: CoreStateMachine::resetVolumioState Mar 04 16:21:44 volumiorrr volumio[1336]: info: CoreStateMachine::getcurrentVolume Mar 04 16:21:44 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 16:21:44 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 16:21:44 volumiorrr sudo[1603]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 16:21:44 volumiorrr sudo[1603]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:44 volumiorrr sudo[1601]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 16:21:44 volumiorrr sudo[1601]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:44 volumiorrr sudo[1601]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:44 volumiorrr sudo[1603]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:44 volumiorrr volumio[1336]: info: Volumio Network Manager: Network status updated: 1 Mar 04 16:21:45 volumiorrr volumio[1336]: info: VolumeController:: Volume=0 Mute =false Mar 04 16:21:45 volumiorrr volumio[1336]: info: CoreStateMachine::pushState Mar 04 16:21:45 volumiorrr volumio[1336]: info: CorePlayQueue::getTrack 0 Mar 04 16:21:45 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 16:21:45 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioPushState Mar 04 16:21:45 volumiorrr volumio[1336]: info: CoreStateMachine::updateTrackBlock Mar 04 16:21:45 volumiorrr volumio[1336]: info: CorePlayQueue::getTrackBlock Mar 04 16:21:45 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 16:21:45 volumiorrr volumio-remote-updater[816]: [2026-03-04 16:21:45] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772637701 101 Mar 04 16:21:45 volumiorrr volumio[1336]: 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: 1 Mar 04 16:21:45 volumiorrr volumio[1336]: info: Reloading queue from file Mar 04 16:21:45 volumiorrr volumio[1336]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 04 16:21:45 volumiorrr volumio[1336]: info: Setting Device type: Raspberry PI Mar 04 16:21:45 volumiorrr volumio[1336]: info: CoreStateMachine::setRepeat null single undefined Mar 04 16:21:45 volumiorrr volumio[1336]: info: CoreStateMachine::pushState Mar 04 16:21:45 volumiorrr volumio[1336]: info: CorePlayQueue::getTrack 0 Mar 04 16:21:45 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 16:21:45 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioPushState Mar 04 16:21:45 volumiorrr volumio[1336]: info: CoreStateMachine::setRandom null Mar 04 16:21:45 volumiorrr volumio[1336]: info: CoreStateMachine::pushState Mar 04 16:21:45 volumiorrr volumio[1336]: info: CorePlayQueue::getTrack 0 Mar 04 16:21:45 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioPushState Mar 04 16:21:45 volumiorrr volumio[1336]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Mar 04 16:21:45 volumiorrr volumio[1336]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03115 Mar 04 16:21:45 volumiorrr volumio[1336]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Mar 04 16:21:45 volumiorrr volumio[1336]: info: VolumeController:: Volume=0 Mute =false Mar 04 16:21:45 volumiorrr volumio[1336]: info: CoreStateMachine::pushState Mar 04 16:21:45 volumiorrr volumio[1336]: info: CorePlayQueue::getTrack 0 Mar 04 16:21:45 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioPushState Mar 04 16:21:45 volumiorrr sudo[1632]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 04 16:21:45 volumiorrr sudo[1632]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:46 volumiorrr volumio[1336]: info: Completed loading Core Plugins Mar 04 16:21:46 volumiorrr volumio[1336]: info: Preparing to generate the ALSA configuration file Mar 04 16:21:46 volumiorrr volumio[1336]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Mar 04 16:21:46 volumiorrr volumio[1336]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Mar 04 16:21:46 volumiorrr volumio[1336]: info: Reading ALSA contributions from plugins. Mar 04 16:21:46 volumiorrr volumio[1336]: info: Asound.conf file written Mar 04 16:21:46 volumiorrr sudo[1637]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 04 16:21:46 volumiorrr sudo[1637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:46 volumiorrr sudo[1637]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:46 volumiorrr volumio[1336]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 04 16:21:46 volumiorrr volumio[1336]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Mar 04 16:21:46 volumiorrr volumio[1336]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Mar 04 16:21:46 volumiorrr volumio[1336]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 Mar 04 16:21:46 volumiorrr volumio[1336]: info: Output device has changed, restarting MPD Mar 04 16:21:46 volumiorrr volumio[1336]: info: Output device has changed, restarting Shairport Sync Mar 04 16:21:46 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:46 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 16:21:46 volumiorrr sudo[1643]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 16:21:46 volumiorrr sudo[1643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:46 volumiorrr sudo[1645]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 16:21:46 volumiorrr sudo[1645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:46 volumiorrr sudo[1643]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:46 volumiorrr volumio[1336]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 16:21:46 volumiorrr volumio[1336]: info: ___________ START PLUGINS ___________ Mar 04 16:21:46 volumiorrr volumio[1336]: info: ControllerMpd::onStart: Initializing MPD Mar 04 16:21:46 volumiorrr volumio[1336]: info: Creating MPD Configuration file Mar 04 16:21:46 volumiorrr sudo[1653]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Mar 04 16:21:46 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 16:21:46 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 16:21:46 volumiorrr volumio[1336]: info: [1772637706993] CoreMusicLibrary::Adding element Media Servers Mar 04 16:21:46 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 16:21:47 volumiorrr sudo[1653]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:47 volumiorrr systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 16:21:47 volumiorrr systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 16:21:47 volumiorrr volumio[1336]: info: UPNP Browser: Client initialized successfully Mar 04 16:21:47 volumiorrr sudo[1655]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 16:21:47 volumiorrr sudo[1655]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:47 volumiorrr sudo[1658]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 16:21:47 volumiorrr sudo[1658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:47 volumiorrr sudo[1655]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:47 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:47 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 16:21:47 volumiorrr sudo[1659]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 16:21:47 volumiorrr sudo[1659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 16:21:47 volumiorrr sudo[1665]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Mar 04 16:21:47 volumiorrr sudo[1659]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:47 volumiorrr systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 04 16:21:47 volumiorrr volumio[1336]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 16:21:47 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:47 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 16:21:47 volumiorrr systemd[1]: mpd.service: Deactivated successfully. Mar 04 16:21:47 volumiorrr systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 16:21:47 volumiorrr systemd[1]: mpd.socket: Deactivated successfully. Mar 04 16:21:47 volumiorrr systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 16:21:47 volumiorrr systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 16:21:47 volumiorrr systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 16:21:47 volumiorrr systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 16:21:47 volumiorrr sudo[1653]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:47 volumiorrr volumio[1336]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 16:21:47 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 16:21:47 volumiorrr volumio[1336]: info: [1772637707384] CoreMusicLibrary::Adding element Last_100 Mar 04 16:21:47 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 16:21:47 volumiorrr sudo[1673]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 16:21:47 volumiorrr sudo[1673]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 16:21:47 volumiorrr sudo[1676]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Mar 04 16:21:47 volumiorrr sudo[1673]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:47 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 16:21:47 volumiorrr volumio[1336]: info: [1772637707431] CoreMusicLibrary::Adding element Webradio Mar 04 16:21:47 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 16:21:47 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 16:21:47 volumiorrr volumio[1336]: info: Initializing BBC Radios Mar 04 16:21:47 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 16:21:47 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 16:21:47 volumiorrr volumio[1336]: info: Adding Calm Radio to Browse Sources Mar 04 16:21:47 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 16:21:47 volumiorrr volumio[1336]: info: [1772637707703] CoreMusicLibrary::Adding element Calm Radio Mar 04 16:21:47 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 16:21:47 volumiorrr volumio[1336]: Cannot find translation for source Calm Radio Mar 04 16:21:47 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 16:21:47 volumiorrr volumio[1336]: info: [1772637707777] CoreMusicLibrary::Adding element YouTube Music Mar 04 16:21:47 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 16:21:47 volumiorrr volumio[1336]: Cannot find translation for source Calm Radio Mar 04 16:21:47 volumiorrr volumio[1336]: Cannot find translation for source YouTube Music Mar 04 16:21:48 volumiorrr volumio[1336]: info: FusionDsp - CamillaDSP binary found. Mar 04 16:21:48 volumiorrr volumio[1336]: info: Loading i18n strings for locale es Mar 04 16:21:48 volumiorrr volumio[1336]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Mar 04 16:21:48 volumiorrr volumio[1336]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Mar 04 16:21:48 volumiorrr volumio[1336]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Mar 04 16:21:48 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Mar 04 16:21:48 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:48 volumiorrr volumio[1336]: info: FusionDsp - mixtype--------------------- Hardware Mar 04 16:21:48 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 16:21:48 volumiorrr volumio[1336]: info: [1772637708083] CoreMusicLibrary::Adding element Mother Earth Radio Mar 04 16:21:48 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 16:21:48 volumiorrr volumio[1336]: Cannot find translation for source Calm Radio Mar 04 16:21:48 volumiorrr volumio[1336]: Cannot find translation for source YouTube Music Mar 04 16:21:48 volumiorrr volumio[1336]: Cannot find translation for source Mother Earth Radio Mar 04 16:21:48 volumiorrr volumio[1336]: info: [MER] Plugin started (SSE mode) Mar 04 16:21:48 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Mar 04 16:21:48 volumiorrr volumio[1336]: info: Loading i18n strings for locale es Mar 04 16:21:48 volumiorrr volumio[1336]: info: Plugin peppymeterbasic has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Mar 04 16:21:48 volumiorrr volumio[1336]: info: Plugin peppymeterbasic has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Mar 04 16:21:48 volumiorrr volumio[1336]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Mar 04 16:21:48 volumiorrr sudo[1697]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/modprobe snd_aloop index=7 pcm_substreams=2 Mar 04 16:21:48 volumiorrr sudo[1697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:48 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 16:21:48 volumiorrr volumio[1336]: info: Volumio Calling Home Mar 04 16:21:48 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:21:48.430+01:00 level=INFO msg="running volumio5-device-gateway" version=30d1950e+CHANGES buildDate=2026-01-29T13:10:08Z Mar 04 16:21:48 volumiorrr sudo[1697]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:48 volumiorrr sudo[1701]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Mar 04 16:21:48 volumiorrr sudo[1701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:48 volumiorrr sudo[1701]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:48 volumiorrr volumio[1336]: info: Preparing to generate the ALSA configuration file Mar 04 16:21:48 volumiorrr sudo[1717]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Mar 04 16:21:48 volumiorrr sudo[1717]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:48 volumiorrr sudo[1719]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Mar 04 16:21:48 volumiorrr sudo[1719]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:48 volumiorrr sudo[1722]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Mar 04 16:21:48 volumiorrr sudo[1722]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:49 volumiorrr systemd[1]: Reloading. Mar 04 16:21:50 volumiorrr systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Mar 04 16:21:50 volumiorrr sudo[1722]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:50 volumiorrr sudo[1717]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:50 volumiorrr systemd[1]: Reloading. Mar 04 16:21:50 volumiorrr volumio[1336]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 04 16:21:51 volumiorrr volumio[1336]: info: camilladsp service started and running in background, instance 1 Mar 04 16:21:51 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:51 volumiorrr volumio[1336]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 384000 768000 <-AAAAAAAAAAAAA Mar 04 16:21:51 volumiorrr volumio[1336]: info: FusionDsp loaded Mar 04 16:21:51 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 16:21:51 volumiorrr volumio[1336]: info: FusionDsp - --[object Object] Mar 04 16:21:51 volumiorrr volumio[1336]: error: FusionDsp - Socket connection not established Mar 04 16:21:51 volumiorrr volumio[1336]: info: FusionDsp - Reporting Fusion DSP Enabled Mar 04 16:21:51 volumiorrr volumio[1336]: info: Adding Signal Path Element [object Object] Mar 04 16:21:51 volumiorrr volumio[1336]: info: Adding fusiondspeq DSP Signal Path Element Mar 04 16:21:51 volumiorrr volumio[1336]: info: FusionDsp - ---- installed callbackRead (debounced 200ms) Mar 04 16:21:51 volumiorrr volumio[1336]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Mar 04 16:21:51 volumiorrr volumio[1336]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Mar 04 16:21:51 volumiorrr volumio[1336]: info: Reading ALSA contributions from plugins. Mar 04 16:21:51 volumiorrr volumio[1336]: info: touch_display: No backlight interface detected. Mar 04 16:21:51 volumiorrr sudo[1771]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Mar 04 16:21:51 volumiorrr sudo[1771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:51 volumiorrr volumio[1336]: info: touch_display: systemctl daemon-reload succeeded. Mar 04 16:21:51 volumiorrr systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 4. Mar 04 16:21:52 volumiorrr sudo[1719]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:52 volumiorrr volumio[1336]: info: touch_display: systemctl stop getty@tty1.service succeeded. Mar 04 16:21:52 volumiorrr systemd[1]: Starting fusiondsp.service - FusionDsp Daemon... Mar 04 16:21:52 volumiorrr systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 04 16:21:52 volumiorrr systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 04 16:21:52 volumiorrr sudo[1777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Mar 04 16:21:52 volumiorrr sudo[1777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:52 volumiorrr sudo[1632]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:52 volumiorrr volumio[1336]: info: snd_dummy loaded Mar 04 16:21:52 volumiorrr volumio[1336]: info: MPD Permissions set Mar 04 16:21:52 volumiorrr systemd[1]: Started volumio-kiosk.service - Volumio Kiosk. Mar 04 16:21:52 volumiorrr sudo[1777]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:52 volumiorrr volumio[1336]: info: MPD Permissions set Mar 04 16:21:52 volumiorrr sudo[1784]: 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 04 16:21:52 volumiorrr sudo[1784]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:52 volumiorrr volumio[1336]: 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: 3 Mar 04 16:21:52 volumiorrr sudo[1784]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:52 volumiorrr volumio[1336]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Mar 04 16:21:52 volumiorrr volumio[1336]: info: touch_display: Volumio Kiosk started. Mar 04 16:21:52 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioGetState Mar 04 16:21:52 volumiorrr volumio[1336]: info: CorePlayQueue::getTrack 0 Mar 04 16:21:52 volumiorrr volumio[1336]: info: Upmpdcli Daemon Started Mar 04 16:21:52 volumiorrr volumio[1336]: info: touch_display: systemctl disable getty@tty1.service succeeded. Mar 04 16:21:52 volumiorrr volumio[1336]: info: Volumio called home Mar 04 16:21:52 volumiorrr volumio[1336]: 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: 3 Mar 04 16:21:52 volumiorrr volumio[1336]: info: Received Get System Info Mar 04 16:21:52 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 16:21:52 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 16:21:52 volumiorrr volumio[1336]: info: Discovery: Getting this device information Mar 04 16:21:52 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioGetState Mar 04 16:21:52 volumiorrr volumio[1336]: info: CorePlayQueue::getTrack 0 Mar 04 16:21:52 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 16:21:52 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:21:52.646+01:00 level=INFO msg="system info for 73d725daa7614c091eadbb18f1799fa6" deviceName=VolumioRRR deviceVariant=volumio deviceModel= softwareVersion=4.096 Mar 04 16:21:53 volumiorrr startx[1823]: X.Org X Server 1.21.1.7 Mar 04 16:21:53 volumiorrr startx[1823]: X Protocol Version 11, Revision 0 Mar 04 16:21:53 volumiorrr startx[1823]: Current Operating System: Linux volumiorrr 6.12.47-v7l+ #1904 SMP Mon Sep 15 13:08:10 BST 2025 armv7l Mar 04 16:21:53 volumiorrr startx[1823]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 cgroup_disable=memory numa_policy=interleave nvme.max_host_mem_size_mb=0 snd_bcm2835.enable_hdmi=0 video=HDMI-A-1:1920x1080M@60D,margin_left=48,margin_right=48,margin_top=48,margin_bottom=48 numa=fake=1 system_heap.max_order=0 smsc95xx.macaddr=88:A2:9E:4E:67:07 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=UUID=7e9efb31-d81e-40e6-b369-17d6be2a2543 imgfile=/volumio_current.sqsh bootpart=UUID=41F4-3F60 datapart=UUID=d86abd49-9ab6-4e7d-8df3-6405c27b7066 uuidconfig=cmdline.txt rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Mar 04 16:21:53 volumiorrr startx[1823]: xorg-server 2:21.1.7-3+rpt3+deb12u11 (https://www.debian.org/support) Mar 04 16:21:53 volumiorrr startx[1823]: Current version of pixman: 0.44.0 Mar 04 16:21:53 volumiorrr startx[1823]: Before reporting problems, check http://wiki.x.org Mar 04 16:21:53 volumiorrr startx[1823]: to make sure that you have the latest version. Mar 04 16:21:53 volumiorrr startx[1823]: Markers: (--) probed, (**) from config file, (==) default setting, Mar 04 16:21:53 volumiorrr startx[1823]: (++) from command line, (!!) notice, (II) informational, Mar 04 16:21:53 volumiorrr startx[1823]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Mar 04 16:21:53 volumiorrr startx[1823]: (==) Log file: "/var/log/Xorg.0.log", Time: Wed Mar 4 16:21:53 2026 Mar 04 16:21:53 volumiorrr startx[1823]: (==) Using config directory: "/etc/X11/xorg.conf.d" Mar 04 16:21:53 volumiorrr startx[1823]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Mar 04 16:21:53 volumiorrr volumio[1336]: info: touch_display: IframeKeyboardBridge extension installed successfully Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:53 volumiorrr volumio[1336]: info: Received Get System Info Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 16:21:53 volumiorrr volumio[1336]: info: Discovery: Getting this device information Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioGetState Mar 04 16:21:53 volumiorrr volumio[1336]: info: CorePlayQueue::getTrack 0 Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 16:21:53 volumiorrr volumio[1336]: info: touch_display: X display number found: 0 Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 04 16:21:53 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 04 16:21:53 volumiorrr volumio[1336]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Mar 04 16:21:53 volumiorrr volumio[1336]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Mar 04 16:21:53 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:21:53.843+01:00 level=INFO msg="enabling local network discovery" Mar 04 16:21:53 volumiorrr sudo[1843]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Mar 04 16:21:53 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:21:53.937+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 04 16:21:53 volumiorrr sudo[1843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:53 volumiorrr sudo[1840]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Mar 04 16:21:53 volumiorrr sudo[1840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:53 volumiorrr volumio[1336]: info: touch_display: X display number found: 0 Mar 04 16:21:53 volumiorrr volumio[1336]: info: Starting Shairport Sync Mar 04 16:21:53 volumiorrr sudo[1843]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:54 volumiorrr volumio[1336]: info: Starting Shairport Sync Mar 04 16:21:54 volumiorrr sudo[1840]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:54 volumiorrr sudo[1850]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 16:21:54 volumiorrr sudo[1850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:54 volumiorrr volumio[1336]: info: Starting Shairport Sync Mar 04 16:21:54 volumiorrr sudo[1852]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 16:21:54 volumiorrr systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 16:21:54 volumiorrr sudo[1852]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:54 volumiorrr volumio[1336]: info: Received Get System Info Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 16:21:54 volumiorrr volumio[1336]: info: Discovery: Getting this device information Mar 04 16:21:54 volumiorrr systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 16:21:54 volumiorrr systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 16:21:54 volumiorrr systemd[1]: shairport-sync.service: Consumed 1.647s CPU time. Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioGetState Mar 04 16:21:54 volumiorrr volumio[1336]: info: CorePlayQueue::getTrack 0 Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 16:21:54 volumiorrr volumio[1336]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Mar 04 16:21:54 volumiorrr systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 16:21:54 volumiorrr sudo[1850]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:54 volumiorrr volumio[1336]: info: Asound.conf file unchanged, so no further update is needed Mar 04 16:21:54 volumiorrr volumio[1336]: info: Output device has changed, restarting MPD Mar 04 16:21:54 volumiorrr sudo[1871]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 16:21:54 volumiorrr sudo[1871]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:54 volumiorrr sudo[1871]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:54 volumiorrr systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 16:21:54 volumiorrr systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 16:21:54 volumiorrr systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 16:21:54 volumiorrr systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 16:21:54 volumiorrr sudo[1855]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 16:21:54 volumiorrr sudo[1855]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:54 volumiorrr sudo[1852]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:54 volumiorrr volumio[1336]: info: Output device has changed, restarting Shairport Sync Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 16:21:54 volumiorrr systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 16:21:54 volumiorrr systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 16:21:54 volumiorrr systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 16:21:54 volumiorrr sudo[1876]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 16:21:54 volumiorrr sudo[1876]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:54 volumiorrr volumio[1336]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 16:21:54 volumiorrr volumio[1336]: info: Preparing to generate the ALSA configuration file Mar 04 16:21:54 volumiorrr systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 16:21:54 volumiorrr sudo[1855]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:54 volumiorrr systemd[1]: mpd.service: Deactivated successfully. Mar 04 16:21:54 volumiorrr volumio-remote-updater[816]: Test mode disabled Mar 04 16:21:54 volumiorrr volumio-remote-updater[816]: Alpha mode disabled Mar 04 16:21:54 volumiorrr volumio-remote-updater[816]: Alpha legacy test mode disabled Mar 04 16:21:54 volumiorrr systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 16:21:54 volumiorrr systemd[1]: mpd.service: Consumed 2.502s CPU time. Mar 04 16:21:54 volumiorrr systemd[1]: mpd.socket: Deactivated successfully. Mar 04 16:21:54 volumiorrr systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 16:21:54 volumiorrr systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 16:21:54 volumiorrr volumio[1336]: info: Shairport-Sync Started Mar 04 16:21:54 volumiorrr volumio[1336]: Error adding Membership: Error: addMembership EINVAL Mar 04 16:21:54 volumiorrr volumio[1336]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Mar 04 16:21:54 volumiorrr volumio[1336]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Mar 04 16:21:54 volumiorrr volumio[1336]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf Mar 04 16:21:54 volumiorrr volumio[1336]: info: Reading ALSA contributions from plugins. Mar 04 16:21:54 volumiorrr volumio[1336]: error: Upnp client error: Error: read ECONNRESET Mar 04 16:21:54 volumiorrr volumio[1336]: info: MPD Permissions set Mar 04 16:21:54 volumiorrr volumio[1336]: info: Shairport-Sync Started Mar 04 16:21:54 volumiorrr volumio[1336]: info: Shairport-Sync Started Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:54 volumiorrr systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 16:21:54 volumiorrr systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:54 volumiorrr volumio[1336]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 04 16:21:54 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:21:54.725+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 04 16:21:54 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:21:54.726+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 04 16:21:54 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:21:54.726+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 04 16:21:54 volumiorrr volumio[1336]: info: Starting Shairport Sync Mar 04 16:21:54 volumiorrr volumio[1336]: info: Asound.conf file unchanged, so no further update is needed Mar 04 16:21:54 volumiorrr volumio[1336]: info: Output device has changed, restarting MPD Mar 04 16:21:54 volumiorrr sudo[1918]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 16:21:54 volumiorrr sudo[1918]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 16:21:54 volumiorrr sudo[1924]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Mar 04 16:21:54 volumiorrr sudo[1918]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:54 volumiorrr volumio[1336]: info: Output device has changed, restarting Shairport Sync Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:54 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 16:21:54 volumiorrr sudo[1922]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 16:21:54 volumiorrr sudo[1922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:54 volumiorrr sudo[1922]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:54 volumiorrr sudo[1920]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 16:21:54 volumiorrr sudo[1920]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:55 volumiorrr sudo[1925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 16:21:55 volumiorrr sudo[1925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:55 volumiorrr volumio[1336]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 16:21:55 volumiorrr systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 16:21:55 volumiorrr systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 16:21:55 volumiorrr systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 16:21:55 volumiorrr volumio[1336]: info: MPD Permissions set Mar 04 16:21:55 volumiorrr systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 16:21:55 volumiorrr systemd[1]: mpd.service: Deactivated successfully. Mar 04 16:21:55 volumiorrr systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 16:21:55 volumiorrr systemd[1]: mpd.socket: Deactivated successfully. Mar 04 16:21:55 volumiorrr systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 16:21:55 volumiorrr systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 16:21:55 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:55 volumiorrr sudo[1920]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:55 volumiorrr systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 16:21:55 volumiorrr systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 16:21:55 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:55 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:55 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:55 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:55 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:55 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:55 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:55 volumiorrr sudo[1965]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 16:21:55 volumiorrr sudo[1965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 16:21:55 volumiorrr sudo[1973]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Mar 04 16:21:55 volumiorrr sudo[1965]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:55 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 16:21:55 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:21:55 volumiorrr volumio[1336]: info: Shairport-Sync Started Mar 04 16:21:55 volumiorrr volumio[1336]: info: Starting Shairport Sync Mar 04 16:21:55 volumiorrr sudo[1977]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 16:21:55 volumiorrr sudo[1977]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 16:21:56 volumiorrr systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 16:21:56 volumiorrr systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 16:21:56 volumiorrr systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 16:21:56 volumiorrr systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 16:21:56 volumiorrr sudo[1977]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:56 volumiorrr volumio[1336]: info: Shairport-Sync Started Mar 04 16:21:57 volumiorrr systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Mar 04 16:21:57 volumiorrr sudo[1771]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:57 volumiorrr volumio[1995]: Error processing line 1 of /usr/lib/python3/dist-packages/distutils-precedence.pth: Mar 04 16:21:57 volumiorrr volumio[1995]: Traceback (most recent call last): Mar 04 16:21:57 volumiorrr volumio[1995]: File "", line 192, in addpackage Mar 04 16:21:57 volumiorrr volumio[1995]: File "", line 1, in Mar 04 16:21:57 volumiorrr volumio[1995]: AttributeError: module '_distutils_hack' has no attribute 'add_shim' Mar 04 16:21:57 volumiorrr volumio[1995]: Remainder of file ignored Mar 04 16:21:57 volumiorrr systemd[1]: fusiondsp.service: Deactivated successfully. Mar 04 16:21:57 volumiorrr mpd[1974]: 2026-03-04T16:21:57 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 16:21:58 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioGetState Mar 04 16:21:58 volumiorrr volumio[1336]: info: CorePlayQueue::getTrack 0 Mar 04 16:21:58 volumiorrr systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 16:21:58 volumiorrr sudo[1925]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:58 volumiorrr sudo[1658]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:58 volumiorrr sudo[1876]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:58 volumiorrr sudo[1645]: pam_unix(sudo:session): session closed for user root Mar 04 16:21:58 volumiorrr volumio[1336]: error: MPD error: The expression evaluated to a falsy value: Mar 04 16:21:58 volumiorrr volumio[1336]: assert.ok(self.idling) Mar 04 16:21:58 volumiorrr volumio[1336]: error: The expression evaluated to a falsy value: Mar 04 16:21:58 volumiorrr volumio[1336]: assert.ok(self.idling) Mar 04 16:21:58 volumiorrr volumio[1336]: info: Completed starting Core Plugins Mar 04 16:21:58 volumiorrr volumio[1336]: info: ------------------------------------------- Mar 04 16:21:58 volumiorrr volumio[1336]: info: ----- MyVolumio plugins startup ---- Mar 04 16:21:58 volumiorrr volumio[1336]: info: ------------------------------------------- Mar 04 16:21:58 volumiorrr volumio[1336]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 04 16:21:58 volumiorrr volumio[1336]: error: MPD error: The expression evaluated to a falsy value: Mar 04 16:21:58 volumiorrr volumio[1336]: assert.ok(self.idling) Mar 04 16:21:58 volumiorrr volumio[1336]: error: The expression evaluated to a falsy value: Mar 04 16:21:58 volumiorrr volumio[1336]: assert.ok(self.idling) Mar 04 16:21:58 volumiorrr volumio[1336]: error: MPD error: The expression evaluated to a falsy value: Mar 04 16:21:58 volumiorrr volumio[1336]: assert.ok(self.idling) Mar 04 16:21:58 volumiorrr volumio[1336]: error: The expression evaluated to a falsy value: Mar 04 16:21:58 volumiorrr volumio[1336]: assert.ok(self.idling) Mar 04 16:21:58 volumiorrr volumio[1336]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 04 16:21:58 volumiorrr volumio[1336]: error: updateQueue error: null Mar 04 16:21:58 volumiorrr volumio[1336]: info: MPD running with PID1974 Mar 04 16:21:58 volumiorrr volumio[1336]: ,establishing connection Mar 04 16:21:58 volumiorrr volumio[1336]: error: updateQueue error: null Mar 04 16:21:59 volumiorrr systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 1. Mar 04 16:21:59 volumiorrr systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Mar 04 16:21:59 volumiorrr systemd[1]: Starting fusiondsp.service - FusionDsp Daemon... Mar 04 16:22:04 volumiorrr systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Mar 04 16:22:05 volumiorrr volumio[2097]: Error processing line 1 of /usr/lib/python3/dist-packages/distutils-precedence.pth: Mar 04 16:22:05 volumiorrr volumio[2097]: Traceback (most recent call last): Mar 04 16:22:05 volumiorrr volumio[2097]: File "", line 192, in addpackage Mar 04 16:22:05 volumiorrr volumio[2097]: File "", line 1, in Mar 04 16:22:05 volumiorrr volumio[2097]: AttributeError: module '_distutils_hack' has no attribute 'add_shim' Mar 04 16:22:05 volumiorrr volumio[2097]: Remainder of file ignored Mar 04 16:22:05 volumiorrr systemd[1]: fusiondsp.service: Deactivated successfully. Mar 04 16:22:07 volumiorrr systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 2. Mar 04 16:22:07 volumiorrr systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Mar 04 16:22:07 volumiorrr systemd[1]: Starting fusiondsp.service - FusionDsp Daemon... Mar 04 16:22:12 volumiorrr systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Mar 04 16:22:12 volumiorrr volumio[2158]: Error processing line 1 of /usr/lib/python3/dist-packages/distutils-precedence.pth: Mar 04 16:22:12 volumiorrr volumio[2158]: Traceback (most recent call last): Mar 04 16:22:12 volumiorrr volumio[2158]: File "", line 192, in addpackage Mar 04 16:22:12 volumiorrr volumio[2158]: File "", line 1, in Mar 04 16:22:12 volumiorrr volumio[2158]: AttributeError: module '_distutils_hack' has no attribute 'add_shim' Mar 04 16:22:12 volumiorrr volumio[2158]: Remainder of file ignored Mar 04 16:22:12 volumiorrr systemd[1]: fusiondsp.service: Deactivated successfully. Mar 04 16:22:14 volumiorrr systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 3. Mar 04 16:22:14 volumiorrr systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Mar 04 16:22:14 volumiorrr systemd[1]: Starting fusiondsp.service - FusionDsp Daemon... Mar 04 16:22:17 volumiorrr volumio[1336]: verbose: New Socket.io Connection to 192.168.0.21 from 192.168.0.13 UA: Mozilla/5.0 (Linux; Android 16; SM-A165F Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.120 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Mar 04 16:22:19 volumiorrr upmpdcli[2237]: writing RSA key Mar 04 16:22:19 volumiorrr systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Mar 04 16:22:19 volumiorrr volumio[2255]: Error processing line 1 of /usr/lib/python3/dist-packages/distutils-precedence.pth: Mar 04 16:22:19 volumiorrr volumio[2255]: Traceback (most recent call last): Mar 04 16:22:19 volumiorrr volumio[2255]: File "", line 192, in addpackage Mar 04 16:22:19 volumiorrr volumio[2255]: File "", line 1, in Mar 04 16:22:19 volumiorrr volumio[2255]: AttributeError: module '_distutils_hack' has no attribute 'add_shim' Mar 04 16:22:19 volumiorrr volumio[2255]: Remainder of file ignored Mar 04 16:22:19 volumiorrr systemd[1]: fusiondsp.service: Deactivated successfully. Mar 04 16:22:21 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 16:22:21 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 16:22:21 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 04 16:22:21 volumiorrr volumio[1336]: error: MyVolumio Plugin failed to start in a timely fashion Mar 04 16:22:21 volumiorrr volumio[1336]: [Metrics] CommandRouter: 61s 392.54ms Mar 04 16:22:21 volumiorrr volumio[1336]: info: CoreCommandRouter::volumiosetStartupVolume Mar 04 16:22:21 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 16:22:21 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 16:22:21 volumiorrr volumio[1336]: info: CoreCommandRouter::Close All Modals sent Mar 04 16:22:21 volumiorrr volumio[1336]: info: CoreCommandRouter::Close All Modals sent Mar 04 16:22:21 volumiorrr systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 4. Mar 04 16:22:21 volumiorrr systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Mar 04 16:22:21 volumiorrr systemd[1]: Starting fusiondsp.service - FusionDsp Daemon... Mar 04 16:22:21 volumiorrr volumio[1336]: verbose: New Socket.io Connection to 192.168.0.21 from 192.168.0.13 UA: Mozilla/5.0 (Linux; Android 16; SM-A165F Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/145.0.7632.120 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Mar 04 16:22:22 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:22.457+01:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.0.13:38792 Mar 04 16:22:22 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:22.474+01:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.0.13:38792 @ 0x1401410" latency=121.732033ms platform=PLATFORM_ANDROID version=5.260120.0 Mar 04 16:22:22 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:22.475+01:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.0.13:38792 @ 0x1401410" latency=121.863104ms timeout=10s Mar 04 16:22:22 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:22.475+01:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.0.13:38792 @ 0x1401410" Mar 04 16:22:22 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 04 16:22:22 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 04 16:22:22 volumiorrr volumio[1336]: info: Received Get System Info Mar 04 16:22:22 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 16:22:22 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 16:22:22 volumiorrr volumio[1336]: info: Discovery: Getting this device information Mar 04 16:22:22 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioGetState Mar 04 16:22:22 volumiorrr volumio[1336]: info: CorePlayQueue::getTrack 0 Mar 04 16:22:22 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 16:22:22 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:22.968+01:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.0.13:38792 @ 0x1401410" name=VolumioRRR Mar 04 16:22:22 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 04 16:22:22 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 04 16:22:22 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:22.971+01:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.0.13:38792 @ 0x1401410" language=es Mar 04 16:22:23 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 04 16:22:23 volumiorrr volumio[1336]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Mar 04 16:22:23 volumiorrr volumio[1336]: info: FusionDsp - ---- read samplerate from file: 44100 Mar 04 16:22:23 volumiorrr volumio[1336]: info: camilladsp stopping service pid 1766... Mar 04 16:22:23 volumiorrr volumio[1336]: grep: /proc/1766/cmdline: binary file matches Mar 04 16:22:23 volumiorrr volumio[1336]: grep: /proc/1766/cmdline: binary file matches Mar 04 16:22:23 volumiorrr volumio[1336]: grep: /proc/1766/cmdline: binary file matches Mar 04 16:22:23 volumiorrr volumio[1336]: info: camilladsp service terminated, instance 1 Mar 04 16:22:23 volumiorrr volumio[1336]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 04 16:22:23 volumiorrr volumio[1336]: info: camilladsp service started and running in background, instance 1 Mar 04 16:22:24 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:24.402+01:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.0.13:38792 @ 0x1401410" latency=120.994677ms platform=PLATFORM_ANDROID version=5.260120.0 Mar 04 16:22:24 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:24.402+01:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.0.13:38792 @ 0x1401410" latency=120.588537ms timeout=10s Mar 04 16:22:24 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:24.402+01:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.0.13:38792 @ 0x1401410" Mar 04 16:22:26 volumiorrr systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Mar 04 16:22:27 volumiorrr volumio[2316]: Error processing line 1 of /usr/lib/python3/dist-packages/distutils-precedence.pth: Mar 04 16:22:27 volumiorrr volumio[2316]: Traceback (most recent call last): Mar 04 16:22:27 volumiorrr volumio[2316]: File "", line 192, in addpackage Mar 04 16:22:27 volumiorrr volumio[2316]: File "", line 1, in Mar 04 16:22:27 volumiorrr volumio[2316]: AttributeError: module '_distutils_hack' has no attribute 'add_shim' Mar 04 16:22:27 volumiorrr volumio[2316]: Remainder of file ignored Mar 04 16:22:27 volumiorrr systemd[1]: fusiondsp.service: Deactivated successfully. Mar 04 16:22:27 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Mar 04 16:22:27 volumiorrr volumio[1336]: info: Received Get System Info Mar 04 16:22:27 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 16:22:27 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:27.256+01:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.0.13:38792 @ 0x1401410" timezone=Europe/Madrid Mar 04 16:22:27 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 16:22:27 volumiorrr volumio[1336]: info: Discovery: Getting this device information Mar 04 16:22:27 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioGetState Mar 04 16:22:27 volumiorrr volumio[1336]: info: CorePlayQueue::getTrack 0 Mar 04 16:22:27 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 16:22:27 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:27.259+01:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.0.13:38792 @ 0x1401410" available=true connected=true macAddress=88:a2:9e:4e:67:07 ip4Address=192.168.0.21/24 ip6Address= Mar 04 16:22:27 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:27.260+01:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.0.13:38792 @ 0x1401410" name=VolumioRRR Mar 04 16:22:27 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:27.261+01:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.0.13:38792 @ 0x1401410" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 04 16:22:27 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:27.261+01:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.0.13:38792 @ 0x1401410" language=es Mar 04 16:22:27 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:27.261+01:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.0.13:38792 @ 0x1401410" setupComplete=true Mar 04 16:22:27 volumiorrr volumio[1336]: info: camilladsp respawn in 100 ms (attempt 1/10) Mar 04 16:22:28 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Mar 04 16:22:28 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:28.114+01:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.0.13:38792 @ 0x1401410" timezone=Europe/Madrid Mar 04 16:22:28 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:28.115+01:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.0.13:38792 @ 0x1401410" available=true connected=true macAddress=88:a2:9e:4e:67:07 ip4Address=192.168.0.21/24 ip6Address= Mar 04 16:22:28 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:28.116+01:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.0.13:38792 @ 0x1401410" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 04 16:22:28 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:28.116+01:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.0.13:38792 @ 0x1401410" setupComplete=true Mar 04 16:22:28 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Mar 04 16:22:28 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 04 16:22:28 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 16:22:28 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 04 16:22:28 volumiorrr volumio[1336]: amixer -c 0 info | grep "bcm2835 ALSA" Mar 04 16:22:28 volumiorrr volumio[1336]: amixer -c 1 info | grep "bcm2835 Headphones" Mar 04 16:22:28 volumiorrr volumio[1336]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Mar 04 16:22:28 volumiorrr volumio[1336]: amixer -c 2 info | grep "vc4-hdmi-0" Mar 04 16:22:28 volumiorrr volumio[1336]: Card sysdefault:2 'vc4hdmi0'/'vc4-hdmi-0' Mar 04 16:22:28 volumiorrr volumio[1336]: amixer -c 3 info | grep "vc4-hdmi-1" Mar 04 16:22:28 volumiorrr volumio[1336]: Card sysdefault:3 'vc4hdmi1'/'vc4-hdmi-1' Mar 04 16:22:29 volumiorrr volumio[1336]: info: BOOT COMPLETED Mar 04 16:22:29 volumiorrr systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 5. Mar 04 16:22:29 volumiorrr systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Mar 04 16:22:29 volumiorrr systemd[1]: Starting fusiondsp.service - FusionDsp Daemon... Mar 04 16:22:32 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:32.475+01:00 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.0.13:38792 @ 0x1401410" latency=121.863104ms timeout=10s error="failed to get output devices: could not get extended output devices: context deadline exceeded" Mar 04 16:22:32 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Mar 04 16:22:32 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 04 16:22:32 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 16:22:32 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 04 16:22:32 volumiorrr volumio[1336]: amixer -c 0 info | grep "bcm2835 ALSA" Mar 04 16:22:32 volumiorrr volumio[1336]: amixer -c 1 info | grep "bcm2835 Headphones" Mar 04 16:22:33 volumiorrr volumio[1336]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Mar 04 16:22:33 volumiorrr volumio[1336]: amixer -c 2 info | grep "vc4-hdmi-0" Mar 04 16:22:33 volumiorrr volumio[1336]: Card sysdefault:2 'vc4hdmi0'/'vc4-hdmi-0' Mar 04 16:22:33 volumiorrr volumio[1336]: amixer -c 3 info | grep "vc4-hdmi-1" Mar 04 16:22:33 volumiorrr volumio[1336]: Card sysdefault:3 'vc4hdmi1'/'vc4-hdmi-1' Mar 04 16:22:33 volumiorrr volumio[1336]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 7 Mar 04 16:22:33 volumiorrr volumio[1336]: /bin/sh: 1: /usr/local/bin/alsacap: not found Mar 04 16:22:33 volumiorrr volumio[1336]: {"cmd":"/usr/local/bin/alsacap -C 7","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 7\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Mar 04 16:22:33 volumiorrr volumio[1336]: amixer -c 7 info | grep "Loopback" Mar 04 16:22:33 volumiorrr volumio[1336]: Card sysdefault:7 'Loopback'/'Loopback 1' Mar 04 16:22:33 volumiorrr volumio[1336]: Mixer name : 'Loopback Mixer' Mar 04 16:22:33 volumiorrr volumio[1336]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Mar 04 16:22:33 volumiorrr volumio[1336]: /bin/sh: 1: /usr/local/bin/alsacap: not found Mar 04 16:22:33 volumiorrr volumio[1336]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Mar 04 16:22:33 volumiorrr volumio[1336]: amixer -c 5 info | grep "SKYLARK UAC2 HIFI DAC" Mar 04 16:22:33 volumiorrr volumio[1336]: Card sysdefault:5 'DAC'/'InnoMaker SKYLARK UAC2 HIFI DAC at usb-0000:01:00.0-1.4, high speed' Mar 04 16:22:33 volumiorrr volumio[1336]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Mar 04 16:22:33 volumiorrr volumio[1336]: /bin/sh: 1: /usr/local/bin/alsacap: not found Mar 04 16:22:33 volumiorrr volumio[1336]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Mar 04 16:22:33 volumiorrr volumio[1336]: amixer -c 5 info | grep "SKYLARK UAC2 HIFI DAC" Mar 04 16:22:33 volumiorrr volumio[1336]: Card sysdefault:5 'DAC'/'InnoMaker SKYLARK UAC2 HIFI DAC at usb-0000:01:00.0-1.4, high speed' Mar 04 16:22:33 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:33.559+01:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.0.13:38792 @ 0x1401410" selectedOutputId=5 Mar 04 16:22:34 volumiorrr volumio5-onboarding[1664]: time=2026-03-04T16:22:34.403+01:00 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.0.13:38792 @ 0x1401410" latency=120.588537ms timeout=10s error="failed to get system info: could not get system info: context deadline exceeded" Mar 04 16:22:34 volumiorrr systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Mar 04 16:22:34 volumiorrr volumio[2391]: Error processing line 1 of /usr/lib/python3/dist-packages/distutils-precedence.pth: Mar 04 16:22:34 volumiorrr volumio[2391]: Traceback (most recent call last): Mar 04 16:22:34 volumiorrr volumio[2391]: File "", line 192, in addpackage Mar 04 16:22:34 volumiorrr volumio[2391]: File "", line 1, in Mar 04 16:22:34 volumiorrr volumio[2391]: AttributeError: module '_distutils_hack' has no attribute 'add_shim' Mar 04 16:22:34 volumiorrr volumio[2391]: Remainder of file ignored Mar 04 16:22:34 volumiorrr systemd[1]: fusiondsp.service: Deactivated successfully. Mar 04 16:22:36 volumiorrr systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 6. Mar 04 16:22:36 volumiorrr systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Mar 04 16:22:37 volumiorrr systemd[1]: Starting fusiondsp.service - FusionDsp Daemon... Mar 04 16:22:41 volumiorrr volumio[1336]: Cannot compose Albumart path Mar 04 16:22:42 volumiorrr systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Mar 04 16:22:42 volumiorrr volumio[2409]: Error processing line 1 of /usr/lib/python3/dist-packages/distutils-precedence.pth: Mar 04 16:22:42 volumiorrr volumio[2409]: Traceback (most recent call last): Mar 04 16:22:42 volumiorrr volumio[2409]: File "", line 192, in addpackage Mar 04 16:22:42 volumiorrr volumio[2409]: File "", line 1, in Mar 04 16:22:42 volumiorrr volumio[2409]: AttributeError: module '_distutils_hack' has no attribute 'add_shim' Mar 04 16:22:42 volumiorrr volumio[2409]: Remainder of file ignored Mar 04 16:22:42 volumiorrr systemd[1]: fusiondsp.service: Deactivated successfully. Mar 04 16:22:42 volumiorrr volumio[1336]: Cannot compose Albumart path Mar 04 16:22:43 volumiorrr volumio[1336]: info: Received Get System Info Mar 04 16:22:43 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 16:22:43 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 16:22:43 volumiorrr volumio[1336]: info: Discovery: Getting this device information Mar 04 16:22:43 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioGetState Mar 04 16:22:43 volumiorrr volumio[1336]: info: CorePlayQueue::getTrack 0 Mar 04 16:22:43 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 16:22:43 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 16:22:43 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 16:22:43 volumiorrr volumio[1336]: info: Discovery: Getting this device information Mar 04 16:22:43 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioGetState Mar 04 16:22:43 volumiorrr volumio[1336]: info: CorePlayQueue::getTrack 0 Mar 04 16:22:43 volumiorrr volumio[1336]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 16:22:43 volumiorrr volumio[1336]: info: Discovery: adding 164bb849-0ca4-4f50-9d2f-7836e8d32aab Mar 04 16:22:43 volumiorrr volumio[1336]: info: Discovery: Found device VolumioRRR Mar 04 16:22:43 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioGetState Mar 04 16:22:43 volumiorrr volumio[1336]: info: CorePlayQueue::getTrack 0 Mar 04 16:22:43 volumiorrr volumio[1336]: info: Discovery: this is already registered, 164bb849-0ca4-4f50-9d2f-7836e8d32aab Mar 04 16:22:43 volumiorrr volumio[1336]: info: Discovery: Found device VolumioRRR Mar 04 16:22:43 volumiorrr volumio[1336]: info: CoreCommandRouter::volumioGetState Mar 04 16:22:43 volumiorrr volumio[1336]: info: CorePlayQueue::getTrack 0 Mar 04 16:22:43 volumiorrr volumio[1336]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 7 Mar 04 16:22:43 volumiorrr volumio[1336]: /bin/sh: 1: /usr/local/bin/alsacap: not found Mar 04 16:22:43 volumiorrr volumio[1336]: {"cmd":"/usr/local/bin/alsacap -C 7","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 7\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Mar 04 16:22:43 volumiorrr volumio[1336]: amixer -c 7 info | grep "Loopback" Mar 04 16:22:43 volumiorrr volumio[1336]: Card sysdefault:7 'Loopback'/'Loopback 1' Mar 04 16:22:43 volumiorrr volumio[1336]: Mixer name : 'Loopback Mixer' Mar 04 16:22:43 volumiorrr volumio[1336]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Mar 04 16:22:43 volumiorrr volumio[1336]: /bin/sh: 1: /usr/local/bin/alsacap: not found Mar 04 16:22:43 volumiorrr volumio[1336]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Mar 04 16:22:43 volumiorrr volumio[1336]: amixer -c 5 info | grep "SKYLARK UAC2 HIFI DAC" Mar 04 16:22:43 volumiorrr volumio[1336]: Card sysdefault:5 'DAC'/'InnoMaker SKYLARK UAC2 HIFI DAC at usb-0000:01:00.0-1.4, high speed' Mar 04 16:22:43 volumiorrr volumio[1336]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Mar 04 16:22:43 volumiorrr volumio[1336]: /bin/sh: 1: /usr/local/bin/alsacap: not found Mar 04 16:22:43 volumiorrr volumio[1336]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Mar 04 16:22:43 volumiorrr volumio[1336]: amixer -c 5 info | grep "SKYLARK UAC2 HIFI DAC" Mar 04 16:22:43 volumiorrr volumio[1336]: Card sysdefault:5 'DAC'/'InnoMaker SKYLARK UAC2 HIFI DAC at usb-0000:01:00.0-1.4, high speed' Mar 04 16:22:43 volumiorrr volumio[1336]: info: camilladsp respawn in 200 ms (attempt 2/10) Mar 04 16:22:43 volumiorrr volumio[1336]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 16:22:44 volumiorrr volumio[1336]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Mar 04 16:22:44 volumiorrr volumio[1336]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Mar 04 16:22:44 volumiorrr volumio[1336]: at new NodeError (node:internal/errors:405:5) Mar 04 16:22:44 volumiorrr volumio[1336]: at assert (node:internal/assert:14:11) Mar 04 16:22:44 volumiorrr volumio[1336]: at internalConnectMultiple (node:net:1118:3) Mar 04 16:22:44 volumiorrr volumio[1336]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Mar 04 16:22:44 volumiorrr volumio[1336]: at listOnTimeout (node:internal/timers:575:11) Mar 04 16:22:44 volumiorrr volumio[1336]: at process.processTimers (node:internal/timers:514:7) { Mar 04 16:22:44 volumiorrr volumio[1336]: code: 'ERR_INTERNAL_ASSERTION' Mar 04 16:22:44 volumiorrr volumio[1336]: } Mar 04 16:22:44 volumiorrr volumio[1336]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 16:22:44 volumiorrr systemd[1]: fusiondsp.service: Scheduled restart job, restart counter is at 7. Mar 04 16:22:44 volumiorrr systemd[1]: Stopped fusiondsp.service - FusionDsp Daemon. Mar 04 16:22:44 volumiorrr systemd[1]: Starting fusiondsp.service - FusionDsp Daemon... Mar 04 16:22:47 volumiorrr sudo[2451]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 16:21' Mar 04 16:22:47 volumiorrr sudo[2451]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"