Dec 08 07:38:38 volumio ntpd[906]: CLOCK: time stepped by 252.173143 Dec 08 07:38:38 volumio ntpd[906]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Dec 08 07:38:39 volumio volumio[1219]: info: ------------------------------------------- Dec 08 07:38:39 volumio volumio[1219]: info: ----- Volumio3 ---- Dec 08 07:38:39 volumio volumio[1219]: info: ------------------------------------------- Dec 08 07:38:39 volumio volumio[1219]: info: ----- System startup ---- Dec 08 07:38:39 volumio volumio[1219]: info: ------------------------------------------- Dec 08 07:38:39 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully. Dec 08 07:38:41 volumio volumio[1219]: info: MYVOLUMIO Environment detected Dec 08 07:38:41 volumio volumio[1219]: info: Plugin folders cleanup Dec 08 07:38:41 volumio volumio[1219]: info: Scanning into folder /volumio/app/plugins/ Dec 08 07:38:41 volumio volumio[1219]: info: Scanning category audio_interface Dec 08 07:38:41 volumio volumio[1219]: info: Scanning category miscellanea Dec 08 07:38:41 volumio volumio[1219]: info: Scanning category music_service Dec 08 07:38:41 volumio volumio[1219]: info: Scanning category plugins.json Dec 08 07:38:41 volumio volumio[1219]: info: Scanning category system_controller Dec 08 07:38:41 volumio volumio[1219]: info: Scanning category user_interface Dec 08 07:38:41 volumio volumio[1219]: info: Scanning into folder /data/plugins/ Dec 08 07:38:41 volumio volumio[1219]: info: Plugin folders cleanup completed Dec 08 07:38:41 volumio volumio[1219]: info: ------------------------------------------- Dec 08 07:38:41 volumio volumio[1219]: info: ----- Core plugins startup ---- Dec 08 07:38:41 volumio volumio[1219]: info: ------------------------------------------- Dec 08 07:38:41 volumio volumio[1219]: info: Loading plugins from folder /volumio/app/plugins/ Dec 08 07:38:41 volumio volumio[1219]: info: Adding plugin upnp to MyMusic Plugins Dec 08 07:38:41 volumio volumio[1219]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 08 07:38:41 volumio volumio[1219]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 08 07:38:41 volumio volumio[1219]: info: Loading plugins from folder /data/plugins/ Dec 08 07:38:41 volumio volumio[1219]: info: Loading plugin "system"... Dec 08 07:38:41 volumio volumio[1219]: info: Loading plugin "appearance"... Dec 08 07:38:41 volumio dhcpcd[667]: timed out Dec 08 07:38:41 volumio sh[648]: timed out Dec 08 07:38:41 volumio dhcpcd[667]: dhcpcd exited Dec 08 07:38:41 volumio sh[648]: dhcpcd exited Dec 08 07:38:41 volumio sh[576]: ifup: failed to bring up eth0 Dec 08 07:38:41 volumio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Dec 08 07:38:41 volumio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Dec 08 07:38:43 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Dec 08 07:38:43 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 08 07:38:43 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 08 07:38:43 volumio upmpdcli[1286]: Could not open config: /tmp/upmpdcli.conf Dec 08 07:38:43 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Dec 08 07:38:43 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Dec 08 07:38:43 volumio volumio[1219]: info: Loading plugin "network"... Dec 08 07:38:43 volumio volumio[1219]: info: Refreshing Cached IP Addresses Dec 08 07:38:44 volumio volumio[1219]: info: Loading plugin "services"... Dec 08 07:38:44 volumio volumio[1219]: info: Loading plugin "alsa_controller"... Dec 08 07:38:44 volumio sudo[1290]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 08 07:38:44 volumio sudo[1290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 07:38:44 volumio sudo[1288]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 08 07:38:44 volumio sudo[1288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 07:38:44 volumio sudo[1288]: pam_unix(sudo:session): session closed for user root Dec 08 07:38:44 volumio sudo[1290]: pam_unix(sudo:session): session closed for user root Dec 08 07:38:44 volumio sudo[1297]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 08 07:38:44 volumio sudo[1297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 07:38:44 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 08 07:38:44 volumio volumio[1219]: info: Loading plugin "wizard"... Dec 08 07:38:44 volumio volumio[1219]: info: Loading plugin "networkfs"... Dec 08 07:38:44 volumio volumio[1219]: info: Starting Udev Watcher for removable devices Dec 08 07:38:44 volumio volumio[1219]: info: Ignoring mount for partition: boot Dec 08 07:38:44 volumio volumio[1219]: info: Ignoring mount for partition: volumio Dec 08 07:38:44 volumio volumio[1219]: info: Ignoring mount for partition: volumio_data Dec 08 07:38:44 volumio volumio[1219]: info: Mounting Device MUSIC Dec 08 07:38:44 volumio sudo[1329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/MUSIC -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Dec 08 07:38:44 volumio sudo[1329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 07:38:45 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully. Dec 08 07:38:45 volumio volumio-remote-updater[683]: [2025-12-08 07:38:45] [connect] Successful connection Dec 08 07:38:46 volumio ntfs-3g[1335]: Version 2022.10.3 integrated FUSE 28 Dec 08 07:38:46 volumio ntfs-3g[1335]: Mounted /dev/sda1 (Read-Write, label "MUSIC", NTFS 3.1) Dec 08 07:38:46 volumio ntfs-3g[1335]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Dec 08 07:38:46 volumio ntfs-3g[1335]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda1,blkdev,blksize=4096 Dec 08 07:38:46 volumio ntfs-3g[1335]: Global ownership and permissions enforced, configuration type 7 Dec 08 07:38:46 volumio sudo[1329]: pam_unix(sudo:session): session closed for user root Dec 08 07:38:46 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 08 07:38:46 volumio volumio[1219]: info: Loading plugin "volumio_command_line_client"... Dec 08 07:38:46 volumio volumio[1219]: info: Loading plugin "upnp"... Dec 08 07:38:46 volumio volumio[1219]: info: [1765139926632] Starting Upmpd Daemon Dec 08 07:38:46 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 08 07:38:46 volumio volumio[1219]: info: Loading plugin "my_music"... Dec 08 07:38:46 volumio volumio[1219]: info: Loading plugin "mpd"... Dec 08 07:38:47 volumio volumio[1219]: info: Loading plugin "upnp_browser"... Dec 08 07:38:47 volumio sudo[1297]: pam_unix(sudo:session): session closed for user root Dec 08 07:38:49 volumio volumio[1219]: info: Starting UPNP Browser Dec 08 07:38:49 volumio volumio[1219]: info: Loading plugin "alarm-clock"... Dec 08 07:38:49 volumio volumio[1219]: info: Loading plugin "airplay_emulation"... Dec 08 07:38:50 volumio volumio[1219]: info: Starting Shairport Sync Dec 08 07:38:50 volumio volumio[1219]: info: Loading plugin "last_100"... Dec 08 07:38:50 volumio volumio[1219]: info: Loading plugin "webradio"... Dec 08 07:38:50 volumio volumio[1219]: info: Loading plugin "i2s_dacs"... Dec 08 07:38:50 volumio volumio[1219]: info: Loading plugin "volumiodiscovery"... Dec 08 07:38:50 volumio volumio[1219]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 08 07:38:50 volumio volumio[1219]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 08 07:38:50 volumio volumio[1219]: *** WARNING *** For more information see Dec 08 07:38:50 volumio volumio[1219]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 08 07:38:50 volumio volumio[1219]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 08 07:38:50 volumio volumio[1219]: *** WARNING *** For more information see Dec 08 07:38:50 volumio node[1219]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 08 07:38:50 volumio node[1219]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 08 07:38:50 volumio node[1219]: *** WARNING *** For more information see Dec 08 07:38:50 volumio node[1219]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 08 07:38:50 volumio node[1219]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 08 07:38:50 volumio node[1219]: *** WARNING *** For more information see Dec 08 07:38:50 volumio volumio[1219]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 08 07:38:50 volumio volumio[1219]: info: Discovery: Started advertising with name: Volumio Dec 08 07:38:50 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 08 07:38:50 volumio volumio[1219]: info: Loading plugin "outputs"... Dec 08 07:38:50 volumio volumio[1219]: info: Loading plugin "albumart"... Dec 08 07:38:50 volumio volumio[1219]: info: Plugin example_plugin is not enabled Dec 08 07:38:50 volumio volumio[1219]: info: Loading plugin "inputs"... Dec 08 07:38:50 volumio volumio[1219]: info: Loading plugin "updater_comm"... Dec 08 07:38:50 volumio volumio[1219]: info: Plugin mpdemulation is not enabled Dec 08 07:38:50 volumio volumio[1219]: info: Loading plugin "rest_api"... Dec 08 07:38:50 volumio volumio[1219]: info: Loading plugin "websocket"... Dec 08 07:38:50 volumio volumio[1219]: info: Starting Socket.io Server version 1.7.4 Dec 08 07:38:50 volumio volumio[1219]: info: Loading i18n strings for locale en Dec 08 07:38:50 volumio volumio[1219]: Updating browse sources language Dec 08 07:38:50 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 07:38:51 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Dec 08 07:38:52 volumio volumio[1339]: Forking 3 albumart workers Dec 08 07:38:52 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 08 07:38:52 volumio volumio[1219]: info: CoreCommandRouter::initPlayerControls Dec 08 07:38:52 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:38:52 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:38:52 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:38:52 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:38:52 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:38:52 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:38:52 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:38:52 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:38:52 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 08 07:38:52 volumio volumio[1219]: Express server listening on port 3000 Dec 08 07:38:52 volumio volumio[1219]: [Metrics] WebUI: 14s 997.17ms Dec 08 07:38:53 volumio volumio[1219]: info: CoreStateMachine::resetVolumioState Dec 08 07:38:53 volumio volumio[1219]: info: CoreStateMachine::getcurrentVolume Dec 08 07:38:53 volumio volumio[1219]: info: CoreCommandRouter::volumioRetrievevolume Dec 08 07:38:53 volumio volumio[1219]: info: Cannot read play queue from file Dec 08 07:38:53 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Dec 08 07:38:53 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Dec 08 07:38:53 volumio systemd[1]: setdatetime-helper.service: Consumed 1.420s CPU time. Dec 08 07:38:53 volumio volumio[1219]: info: Volumio Network Manager: Network status updated: 2 Dec 08 07:38:54 volumio volumio[1219]: verbose: New Socket.io Connection to 192.168.20.76 from 192.168.20.42 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 1 Dec 08 07:38:55 volumio volumio[1219]: verbose: New Socket.io Connection to 192.168.20.76 from 192.168.20.42 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 2 Dec 08 07:38:55 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 07:38:55 volumio volumio[1219]: verbose: New Socket.io Connection to 192.168.20.76 from 192.168.20.42 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 3 Dec 08 07:38:55 volumio volumio[1219]: info: VolumeController:: Volume=100 Mute =false Dec 08 07:38:55 volumio volumio[1219]: info: CoreStateMachine::pushState Dec 08 07:38:55 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 08 07:38:55 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 08 07:38:55 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Dec 08 07:38:55 volumio volumio[1219]: info: CoreStateMachine::updateTrackBlock Dec 08 07:38:55 volumio volumio[1219]: info: CorePlayQueue::getTrackBlock Dec 08 07:38:55 volumio volumio[1219]: info: CoreCommandRouter::volumioRetrievevolume Dec 08 07:38:55 volumio volumio[1219]: info: CoreStateMachine::setRepeat null single undefined Dec 08 07:38:55 volumio volumio[1219]: info: CoreStateMachine::pushState Dec 08 07:38:55 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 08 07:38:55 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Dec 08 07:38:55 volumio volumio[1219]: info: CoreStateMachine::setRandom null Dec 08 07:38:55 volumio volumio[1219]: info: CoreStateMachine::pushState Dec 08 07:38:55 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 08 07:38:55 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Dec 08 07:38:55 volumio volumio[1219]: info: Setting Device type: Raspberry PI Dec 08 07:38:56 volumio volumio[1219]: verbose: New Socket.io Connection to 192.168.20.76 from 192.168.20.42 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 4 Dec 08 07:38:56 volumio volumio[1219]: info: Completed loading Core Plugins Dec 08 07:38:56 volumio volumio[1219]: info: Preparing to generate the ALSA configuration file Dec 08 07:38:56 volumio volumio[1219]: verbose: New Socket.io Connection to 192.168.20.76 from 192.168.20.42 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 5 Dec 08 07:38:57 volumio sudo[1435]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 08 07:38:57 volumio sudo[1435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 07:38:57 volumio sudo[1435]: pam_unix(sudo:session): session closed for user root Dec 08 07:38:57 volumio volumio[1219]: verbose: New Socket.io Connection to 192.168.20.76:3000 from 192.168.20.131 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 08 07:38:57 volumio sudo[1437]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 08 07:38:57 volumio sudo[1437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 07:38:57 volumio sudo[1437]: pam_unix(sudo:session): session closed for user root Dec 08 07:38:57 volumio volumio[1219]: info: VolumeController:: Volume=100 Mute =false Dec 08 07:38:57 volumio volumio[1219]: info: CoreStateMachine::pushState Dec 08 07:38:57 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 08 07:38:57 volumio volumio[1219]: info: CoreCommandRouter::volumioPushState Dec 08 07:38:57 volumio volumio[1219]: info: Discovery: adding 6c804ec2-719c-4d50-88fb-1b9356767d3c Dec 08 07:38:57 volumio volumio[1219]: info: Discovery: Found device Volumio Dec 08 07:38:57 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 08 07:38:57 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 08 07:38:57 volumio volumio[1219]: info: Discovery: this is already registered, 6c804ec2-719c-4d50-88fb-1b9356767d3c Dec 08 07:38:57 volumio volumio[1219]: info: Discovery: Found device Volumio Dec 08 07:38:57 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 08 07:38:57 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 08 07:38:58 volumio volumio[1219]: info: Discovery: adding 037319cd-11df-4ab3-8d6a-511f1c72395e Dec 08 07:38:58 volumio volumio[1219]: info: Discovery: Found device Volumiobr Dec 08 07:38:58 volumio volumio[1219]: info: Discovery: Connecting to remote: 192.168.20.131 Dec 08 07:38:58 volumio volumio[1219]: verbose: New Socket.io Connection to 192.168.20.76:3000 from 192.168.20.131 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 08 07:38:58 volumio volumio[1219]: info: Asound.conf file unchanged, so no further update is needed Dec 08 07:38:58 volumio volumio[1219]: info: Output device has changed, restarting MPD Dec 08 07:38:58 volumio volumio[1219]: info: Output device has changed, restarting Shairport Sync Dec 08 07:38:58 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:38:58 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 07:38:58 volumio sudo[1444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 08 07:38:58 volumio sudo[1444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 07:38:58 volumio sudo[1442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 08 07:38:58 volumio sudo[1442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 07:38:58 volumio sudo[1442]: pam_unix(sudo:session): session closed for user root Dec 08 07:38:59 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Dec 08 07:38:59 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Dec 08 07:38:59 volumio volumio[1219]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 08 07:38:59 volumio volumio[1219]: info: ___________ START PLUGINS ___________ Dec 08 07:38:59 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Dec 08 07:38:59 volumio volumio[1219]: info: ControllerMpd::onStart: Initializing MPD Dec 08 07:38:59 volumio volumio[1219]: info: Creating MPD Configuration file Dec 08 07:38:59 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 08 07:38:59 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 08 07:38:59 volumio upmpdcli[1451]: :3:../libupnpp/upnpplib.cxx:273::LibUPnP: Using IPV4 192.168.20.76 port 49152 IPV6 port 49152 Dec 08 07:38:59 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 08 07:38:59 volumio volumio[1219]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 08 07:38:59 volumio volumio[1219]: info: [1765139939220] CoreMusicLibrary::Adding element Media Servers Dec 08 07:38:59 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 07:38:59 volumio volumio[1219]: info: UPNP Browser: Client initialized successfully Dec 08 07:38:59 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:38:59 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 07:38:59 volumio volumio[1219]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 08 07:38:59 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:38:59 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 07:38:59 volumio sudo[1455]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 08 07:38:59 volumio sudo[1455]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 08 07:38:59 volumio sudo[1474]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 08 07:38:59 volumio sudo[1455]: pam_unix(sudo:session): session closed for user root Dec 08 07:38:59 volumio sudo[1467]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 08 07:38:59 volumio sudo[1454]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 08 07:38:59 volumio sudo[1454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 07:38:59 volumio sudo[1454]: pam_unix(sudo:session): session closed for user root Dec 08 07:38:59 volumio sudo[1467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 07:38:59 volumio volumio[1219]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 08 07:38:59 volumio volumio[1219]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 08 07:38:59 volumio volumio[1219]: info: [1765139939687] CoreMusicLibrary::Adding element Last_100 Dec 08 07:38:59 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 07:38:59 volumio volumio[1219]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 08 07:38:59 volumio volumio[1219]: info: [1765139939739] CoreMusicLibrary::Adding element Webradio Dec 08 07:38:59 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 07:38:59 volumio systemd[1]: mpd.service: Deactivated successfully. Dec 08 07:38:59 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 08 07:38:59 volumio systemd[1]: mpd.socket: Deactivated successfully. Dec 08 07:38:59 volumio upmpdcli[1451]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Connection reset by peer Dec 08 07:38:59 volumio upmpdcli[1451]: :2:../src/main.cxx:728::MPD connection failed Dec 08 07:38:59 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 08 07:38:59 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 08 07:38:59 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 08 07:38:59 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 08 07:38:59 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Dec 08 07:38:59 volumio volumio[1219]: info: Initializing BBC Radios Dec 08 07:39:00 volumio sudo[1481]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 08 07:39:00 volumio sudo[1481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 08 07:39:00 volumio sudo[1492]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Dec 08 07:39:00 volumio sudo[1481]: pam_unix(sudo:session): session closed for user root Dec 08 07:39:00 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 08 07:39:00 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 07:39:00 volumio volumio[1219]: info: Volumio Calling Home Dec 08 07:39:00 volumio volumio-remote-updater[683]: [2025-12-08 07:39:00] [connect] Successful connection Dec 08 07:39:01 volumio volumio[1365]: Starting albumart workers Dec 08 07:39:03 volumio upmpdcli[1451]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Dec 08 07:39:03 volumio upmpdcli[1451]: :2:../src/main.cxx:728::MPD connection failed Dec 08 07:39:04 volumio volumio[1375]: Starting albumart workers Dec 08 07:39:04 volumio volumio[1366]: Starting albumart workers Dec 08 07:39:07 volumio volumio[1219]: info: MPD Permissions set Dec 08 07:39:07 volumio volumio[1219]: info: MPD Permissions set Dec 08 07:39:07 volumio mpd[1493]: 2025-12-08T07:39:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 08 07:39:08 volumio systemd[1]: Started mpd.service - Music Player Daemon. Dec 08 07:39:08 volumio sudo[1444]: pam_unix(sudo:session): session closed for user root Dec 08 07:39:08 volumio sudo[1467]: pam_unix(sudo:session): session closed for user root Dec 08 07:39:08 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 08 07:39:08 volumio sudo[1521]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 08 07:39:08 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 08 07:39:08 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 08 07:39:08 volumio sudo[1521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 07:39:08 volumio sudo[1521]: pam_unix(sudo:session): session closed for user root Dec 08 07:39:09 volumio volumio[1219]: info: Volumio called home Dec 08 07:39:09 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:09 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:09 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:09 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:09 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:09 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:09 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:09 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:10 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 07:39:10 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:10 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:10 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:10 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:10 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:10 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:10 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:10 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:10 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:10 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 07:39:10 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:11 volumio volumio[1219]: verbose: New Socket.io Connection to 192.168.20.76 from 192.168.20.42 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 8 Dec 08 07:39:11 volumio volumio[1219]: info: Upmpdcli Daemon Started Dec 08 07:39:11 volumio volumio[1219]: info: Completed starting Core Plugins Dec 08 07:39:11 volumio volumio[1219]: info: ------------------------------------------- Dec 08 07:39:11 volumio volumio[1219]: info: ----- MyVolumio plugins startup ---- Dec 08 07:39:11 volumio volumio[1219]: info: ------------------------------------------- Dec 08 07:39:11 volumio volumio[1219]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 08 07:39:11 volumio volumio[1219]: verbose: New Socket.io Connection to 192.168.20.76 from 192.168.20.42 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 9 Dec 08 07:39:11 volumio volumio[1219]: error: MPD error: The expression evaluated to a falsy value: Dec 08 07:39:11 volumio volumio[1219]: assert.ok(self.idling) Dec 08 07:39:11 volumio volumio[1219]: error: The expression evaluated to a falsy value: Dec 08 07:39:11 volumio volumio[1219]: assert.ok(self.idling) Dec 08 07:39:12 volumio volumio[1219]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Dec 08 07:39:12 volumio volumio[1219]: info: MPD running with PID1493 Dec 08 07:39:12 volumio volumio[1219]: ,establishing connection Dec 08 07:39:12 volumio volumio[1219]: info: Starting Shairport Sync Dec 08 07:39:12 volumio volumio[1219]: info: Starting Shairport Sync Dec 08 07:39:12 volumio volumio[1219]: info: Starting Shairport Sync Dec 08 07:39:12 volumio sudo[1559]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 08 07:39:12 volumio sudo[1559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 07:39:12 volumio volumio[1219]: error: updateQueue error: null Dec 08 07:39:12 volumio volumio[1219]: verbose: New Socket.io Connection to 192.168.20.76 from 192.168.20.42 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 11 Dec 08 07:39:12 volumio sudo[1561]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 08 07:39:12 volumio sudo[1561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 07:39:12 volumio sudo[1563]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 08 07:39:12 volumio sudo[1563]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 07:39:12 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 08 07:39:12 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 08 07:39:12 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 08 07:39:12 volumio systemd[1]: shairport-sync.service: Consumed 1.596s CPU time. Dec 08 07:39:12 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 08 07:39:12 volumio sudo[1559]: pam_unix(sudo:session): session closed for user root Dec 08 07:39:13 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 08 07:39:13 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 08 07:39:13 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 08 07:39:13 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 08 07:39:13 volumio sudo[1563]: pam_unix(sudo:session): session closed for user root Dec 08 07:39:13 volumio sudo[1561]: pam_unix(sudo:session): session closed for user root Dec 08 07:39:13 volumio volumio[1219]: info: Discovery: Connected to remote: 192.168.20.131 Dec 08 07:39:13 volumio volumio[1219]: error: updateQueue error: null Dec 08 07:39:13 volumio volumio[1219]: info: Shairport-Sync Started Dec 08 07:39:13 volumio volumio[1219]: Error adding Membership: Error: addMembership EINVAL Dec 08 07:39:13 volumio volumio[1219]: info: Shairport-Sync Started Dec 08 07:39:13 volumio volumio[1219]: info: Shairport-Sync Started Dec 08 07:39:14 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 08 07:39:14 volumio sudo[1597]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 08 07:39:14 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 08 07:39:14 volumio sudo[1597]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 07:39:14 volumio sudo[1599]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 08 07:39:14 volumio sudo[1599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 08 07:39:14 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 08 07:39:14 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 08 07:39:14 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 08 07:39:14 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 08 07:39:14 volumio sudo[1597]: pam_unix(sudo:session): session closed for user root Dec 08 07:39:14 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 08 07:39:14 volumio mpd_monitor.sh[1603]: MPD Monitor Service: Starting MPD Monitor Service Dec 08 07:39:14 volumio sudo[1599]: pam_unix(sudo:session): session closed for user root Dec 08 07:39:14 volumio volumio[1219]: info: Successfully started MPD Monitor Dec 08 07:39:14 volumio volumio[1219]: info: Successfully started MPD Monitor Dec 08 07:39:15 volumio volumio-remote-updater[683]: [2025-12-08 07:39:15] [connect] Successful connection Dec 08 07:39:15 volumio volumio-remote-updater[683]: [2025-12-08 07:39:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765139955 101 Dec 08 07:39:15 volumio volumio[1219]: 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: 12 Dec 08 07:39:17 volumio volumio[1219]: verbose: New Socket.io Connection to 192.168.20.76 from 192.168.20.42 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:145.0) Gecko/20100101 Firefox/145.0 Engine version: 3 Transport: polling Total Clients: 13 Dec 08 07:39:17 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 08 07:39:17 volumio volumio[1219]: info: CoreCommandRouter::volumioGetVisibleSources Dec 08 07:39:17 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 08 07:39:17 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 08 07:39:17 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 08 07:39:17 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 08 07:39:17 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 08 07:39:17 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 08 07:39:17 volumio volumio[1219]: info: CoreCommandRouter::volumioGetQueue Dec 08 07:39:17 volumio volumio[1219]: info: CoreStateMachine::getQueue Dec 08 07:39:17 volumio volumio[1219]: info: CorePlayQueue::getQueue Dec 08 07:39:17 volumio volumio[1219]: info: Listing playlists Dec 08 07:39:17 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 08 07:39:17 volumio volumio[1219]: info: Received Get System Info Dec 08 07:39:17 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 08 07:39:17 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 08 07:39:17 volumio volumio[1219]: info: Discovery: Getting this device information Dec 08 07:39:17 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 08 07:39:17 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 08 07:39:17 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 08 07:39:17 volumio volumio[1219]: info: CoreCommandRouter::volumioGetState Dec 08 07:39:17 volumio volumio[1219]: info: CorePlayQueue::getTrack 0 Dec 08 07:39:32 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 08 07:39:32 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 07:39:32 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 08 07:39:32 volumio volumio[1219]: error: MyVolumio Plugin failed to start in a timely fashion Dec 08 07:39:32 volumio volumio[1219]: [Metrics] CommandRouter: 52s 947.29ms Dec 08 07:39:32 volumio volumio[1219]: info: CoreCommandRouter::volumiosetStartupVolume Dec 08 07:39:32 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 08 07:39:32 volumio volumio[1219]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 08 07:39:32 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Dec 08 07:39:32 volumio volumio[1219]: info: CoreCommandRouter::Close All Modals sent Dec 08 07:39:32 volumio volumio[1219]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 08 07:39:32 volumio volumio[1219]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Dec 08 07:39:32 volumio volumio[1219]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Dec 08 07:39:32 volumio volumio[1219]: at new NodeError (node:internal/errors:405:5) Dec 08 07:39:32 volumio volumio[1219]: at assert (node:internal/assert:14:11) Dec 08 07:39:32 volumio volumio[1219]: at internalConnectMultiple (node:net:1118:3) Dec 08 07:39:32 volumio volumio[1219]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Dec 08 07:39:32 volumio volumio[1219]: at listOnTimeout (node:internal/timers:575:11) Dec 08 07:39:32 volumio volumio[1219]: at process.processTimers (node:internal/timers:514:7) { Dec 08 07:39:32 volumio volumio[1219]: code: 'ERR_INTERNAL_ASSERTION' Dec 08 07:39:32 volumio volumio[1219]: } Dec 08 07:39:32 volumio volumio[1219]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 08 07:39:38 volumio sudo[1672]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-08 07:38' Dec 08 07:39:38 volumio sudo[1672]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"