Mar 24 12:22:00 volumio volumio[1256]: info: Loading plugin "upnp_browser"... Mar 24 12:22:02 volumio volumio-remote-updater[718]: [2026-03-24 12:22:02] [connect] Successful connection Mar 24 12:22:02 volumio volumio[1256]: info: Starting UPNP Browser Mar 24 12:22:02 volumio volumio[1256]: info: Loading plugin "alarm-clock"... Mar 24 12:22:03 volumio volumio[1256]: info: Loading plugin "airplay_emulation"... Mar 24 12:22:03 volumio volumio[1256]: info: Starting Shairport Sync Mar 24 12:22:03 volumio volumio[1256]: info: Loading plugin "last_100"... Mar 24 12:22:03 volumio volumio[1256]: info: Loading plugin "webradio"... Mar 24 12:22:03 volumio volumio[1256]: info: Loading plugin "i2s_dacs"... Mar 24 12:22:03 volumio volumio[1256]: info: Loading plugin "volumiodiscovery"... Mar 24 12:22:03 volumio volumio[1256]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 12:22:03 volumio volumio[1256]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 12:22:03 volumio volumio[1256]: *** WARNING *** For more information see Mar 24 12:22:03 volumio volumio[1256]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 12:22:03 volumio volumio[1256]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 12:22:03 volumio volumio[1256]: *** WARNING *** For more information see Mar 24 12:22:03 volumio node[1256]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 12:22:03 volumio node[1256]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 12:22:03 volumio node[1256]: *** WARNING *** For more information see Mar 24 12:22:03 volumio node[1256]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 12:22:03 volumio node[1256]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 12:22:03 volumio node[1256]: *** WARNING *** For more information see Mar 24 12:22:03 volumio volumio[1256]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 24 12:22:03 volumio volumio[1256]: info: Discovery: Started advertising with name: Volumio Mar 24 12:22:03 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 12:22:03 volumio volumio[1256]: info: Loading plugin "outputs"... Mar 24 12:22:03 volumio volumio[1256]: info: Loading plugin "albumart"... Mar 24 12:22:03 volumio volumio[1256]: info: Plugin example_plugin is not enabled Mar 24 12:22:03 volumio volumio[1256]: info: Loading plugin "inputs"... Mar 24 12:22:03 volumio volumio[1256]: info: Loading plugin "updater_comm"... Mar 24 12:22:03 volumio volumio[1256]: info: Plugin mpdemulation is not enabled Mar 24 12:22:03 volumio volumio[1256]: info: Loading plugin "rest_api"... Mar 24 12:22:03 volumio volumio[1256]: info: Loading plugin "websocket"... Mar 24 12:22:03 volumio volumio[1256]: info: Starting Socket.io Server version 1.7.4 Mar 24 12:22:03 volumio volumio[1256]: info: Loading plugin "yandex_music"... Mar 24 12:22:05 volumio volumio[1373]: Forking 3 albumart workers Mar 24 12:22:07 volumio systemd[1]: systemd-fsckd.service: Deactivated successfully. Mar 24 12:22:11 volumio volumio[1256]: info: Applying required configuration parameters for plugin yandex_music Mar 24 12:22:11 volumio volumio[1256]: info: Loading plugin "ir_controller"... Mar 24 12:22:11 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Mar 24 12:22:11 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 24 12:22:11 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 24 12:22:11 volumio upmpdcli[1427]: Could not open config: /tmp/upmpdcli.conf Mar 24 12:22:11 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Mar 24 12:22:11 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Mar 24 12:22:13 volumio volumio[1256]: info: Applying required configuration parameters for plugin ir_controller Mar 24 12:22:13 volumio systemd[1]: systemd-hostnamed.service: Deactivated successfully. Mar 24 12:22:14 volumio volumio[1256]: info: Loading plugin "touch_display"... Mar 24 12:22:15 volumio volumio[1383]: Starting albumart workers Mar 24 12:22:16 volumio volumio[1384]: Starting albumart workers Mar 24 12:22:16 volumio volumio[1385]: Starting albumart workers Mar 24 12:22:16 volumio volumio[1256]: info: Applying required configuration parameters for plugin touch_display Mar 24 12:22:17 volumio volumio[1256]: info: Loading i18n strings for locale ru Mar 24 12:22:17 volumio volumio[1256]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Mar 24 12:22:17 volumio volumio-remote-updater[718]: [2026-03-24 12:22:17] [connect] Successful connection Mar 24 12:22:17 volumio volumio[1256]: error: ir_controller: Fetching language file: Error: i18n file complementing the system language not found. Mar 24 12:22:17 volumio volumio[1256]: Updating browse sources language Mar 24 12:22:17 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 12:22:19 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 12:22:19 volumio volumio[1256]: info: CoreCommandRouter::initPlayerControls Mar 24 12:22:19 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:19 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:19 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:19 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:19 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:19 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:19 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:19 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:19 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 12:22:19 volumio volumio[1256]: Express server listening on port 3000 Mar 24 12:22:19 volumio volumio[1256]: [Metrics] WebUI: 25s 848.08ms Mar 24 12:22:19 volumio volumio[1256]: info: CoreStateMachine::resetVolumioState Mar 24 12:22:19 volumio volumio[1256]: info: CoreStateMachine::getcurrentVolume Mar 24 12:22:19 volumio volumio[1256]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 12:22:19 volumio volumio[1256]: info: CoreStateMachine::pushState Mar 24 12:22:19 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:22:19 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:22:19 volumio volumio[1256]: info: CoreCommandRouter::volumioPushState Mar 24 12:22:20 volumio sudo[1449]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 12:22:20 volumio sudo[1449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:20 volumio sudo[1451]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 12:22:20 volumio sudo[1451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:20 volumio sudo[1451]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:20 volumio sudo[1449]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:20 volumio volumio[1256]: info: Volumio Network Manager: Network status updated: 1 Mar 24 12:22:20 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Mar 24 12:22:21 volumio volumio[1256]: verbose: New Socket.io Connection to 192.168.0.70 from 192.168.0.25 UA: Mozilla/5.0 (Linux; Android 14; RMX3630 Build/UKQ1.230924.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.119 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Mar 24 12:22:21 volumio volumio[1256]: verbose: New Socket.io Connection to 192.168.0.70 from 192.168.0.25 UA: Mozilla/5.0 (Linux; Android 14; RMX3630 Build/UKQ1.230924.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.119 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Mar 24 12:22:21 volumio volumio[1256]: info: Reloading queue from file Mar 24 12:22:21 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 12:22:22 volumio volumio[1256]: info: CoreStateMachine::setRepeat null single undefined Mar 24 12:22:22 volumio volumio[1256]: info: CoreStateMachine::pushState Mar 24 12:22:22 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:22:22 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 12:22:22 volumio volumio[1256]: info: CoreCommandRouter::volumioPushState Mar 24 12:22:22 volumio volumio[1256]: info: CoreStateMachine::setRandom null Mar 24 12:22:22 volumio volumio[1256]: info: CoreStateMachine::pushState Mar 24 12:22:22 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:22:22 volumio volumio[1256]: info: CoreCommandRouter::volumioPushState Mar 24 12:22:22 volumio volumio[1256]: info: Setting Device type: Raspberry PI Mar 24 12:22:22 volumio volumio[1256]: info: Completed loading Core Plugins Mar 24 12:22:22 volumio volumio[1256]: info: Preparing to generate the ALSA configuration file Mar 24 12:22:22 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 12:22:22 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 12:22:22 volumio volumio[1256]: info: Discovery: Getting this device information Mar 24 12:22:22 volumio volumio[1256]: info: CoreCommandRouter::volumioGetState Mar 24 12:22:22 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:22:22 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 12:22:22 volumio volumio[1256]: verbose: New Socket.io Connection to 192.168.0.70 from 192.168.0.25 UA: Mozilla/5.0 (Linux; Android 14; RMX3630 Build/UKQ1.230924.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.119 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Mar 24 12:22:22 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 12:22:22 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 12:22:22 volumio volumio[1256]: info: Discovery: Getting this device information Mar 24 12:22:22 volumio volumio[1256]: info: CoreCommandRouter::volumioGetState Mar 24 12:22:22 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:22:22 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 12:22:22 volumio volumio[1256]: info: Asound.conf file unchanged, so no further update is needed Mar 24 12:22:22 volumio volumio[1256]: info: Output device has changed, restarting MPD Mar 24 12:22:22 volumio sudo[1501]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 24 12:22:22 volumio sudo[1501]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:23 volumio volumio[1256]: info: Output device has changed, restarting Shairport Sync Mar 24 12:22:23 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:23 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 12:22:23 volumio sudo[1506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 12:22:23 volumio sudo[1506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:23 volumio sudo[1503]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 12:22:23 volumio sudo[1503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:23 volumio sudo[1503]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:23 volumio volumio[1256]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 12:22:23 volumio volumio[1256]: info: ___________ START PLUGINS ___________ Mar 24 12:22:23 volumio volumio[1256]: info: ControllerMpd::onStart: Initializing MPD Mar 24 12:22:23 volumio volumio[1256]: info: Creating MPD Configuration file Mar 24 12:22:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 12:22:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 12:22:23 volumio sudo[1516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Mar 24 12:22:23 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 12:22:23 volumio volumio[1256]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 12:22:23 volumio volumio[1256]: info: [1774344143533] CoreMusicLibrary::Adding element Медиа-серверы Mar 24 12:22:23 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 12:22:23 volumio sudo[1516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:23 volumio volumio[1256]: info: UPNP Browser: Client initialized successfully Mar 24 12:22:23 volumio sudo[1519]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 12:22:23 volumio sudo[1519]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:23 volumio sudo[1519]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:23 volumio sudo[1518]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 24 12:22:23 volumio sudo[1518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 24 12:22:23 volumio sudo[1524]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Mar 24 12:22:23 volumio sudo[1518]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:23 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:23 volumio sudo[1521]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 12:22:23 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 12:22:23 volumio sudo[1521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:23 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 12:22:23 volumio sudo[1516]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:23 volumio systemd[1]: mpd.service: Deactivated successfully. Mar 24 12:22:23 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 12:22:23 volumio systemd[1]: mpd.socket: Deactivated successfully. Mar 24 12:22:23 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 12:22:23 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 12:22:23 volumio volumio[1256]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 12:22:23 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:24 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 12:22:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 12:22:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 12:22:24 volumio volumio[1256]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 12:22:24 volumio volumio[1256]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 12:22:24 volumio volumio[1256]: info: [1774344144183] CoreMusicLibrary::Adding element Last_100 Mar 24 12:22:24 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 12:22:24 volumio volumio[1256]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 12:22:24 volumio volumio[1256]: info: [1774344144241] CoreMusicLibrary::Adding element Webradio Mar 24 12:22:24 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 12:22:24 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 12:22:24 volumio sudo[1540]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 24 12:22:24 volumio sudo[1540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 24 12:22:24 volumio sudo[1544]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Mar 24 12:22:24 volumio sudo[1540]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:24 volumio volumio[1256]: info: Initializing BBC Radios Mar 24 12:22:24 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:24.473+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 12:22:24 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 12:22:24 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 12:22:24 volumio volumio[1256]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 12:22:24 volumio volumio[1256]: info: [1774344144748] CoreMusicLibrary::Adding element Яндекс Музыка Mar 24 12:22:24 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 12:22:24 volumio volumio[1256]: Cannot find translation for source Яндекс Музыка Mar 24 12:22:25 volumio volumio[1256]: info: Loading i18n strings for locale ru Mar 24 12:22:25 volumio volumio[1256]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Mar 24 12:22:25 volumio volumio[1256]: error: ir_controller: Fetching language file: Error: i18n file complementing the system language not found. Mar 24 12:22:25 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 12:22:25 volumio volumio[1256]: info: Loading i18n strings for locale ru Mar 24 12:22:25 volumio volumio[1256]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found. Mar 24 12:22:25 volumio volumio[1256]: error: ir_controller: Fetching language file: Error: i18n file complementing the system language not found. Mar 24 12:22:25 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 12:22:25 volumio sudo[1568]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /data/volumiokioskextensions/IframeKeyboardBridge Mar 24 12:22:25 volumio sudo[1568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:25 volumio volumio[1256]: info: Volumio Calling Home Mar 24 12:22:25 volumio sudo[1568]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:25 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Mar 24 12:22:25 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Mar 24 12:22:25 volumio systemd[1]: setdatetime-helper.service: Consumed 1.082s CPU time. Mar 24 12:22:26 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Mar 24 12:22:26 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 24 12:22:26 volumio sudo[1581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R a+rwX /etc/lirc/irexec.lircrc /etc/lirc/lirc_options.conf /etc/lirc/lircd.conf /etc/lirc/lircd.conf.d /etc/lirc/lircmd.conf /etc/lirc/lircrc Mar 24 12:22:26 volumio sudo[1581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:26 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 24 12:22:26 volumio sudo[1501]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:27 volumio sudo[1581]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:27 volumio sudo[1597]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Mar 24 12:22:27 volumio sudo[1595]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Mar 24 12:22:27 volumio sudo[1595]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:27 volumio sudo[1599]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Mar 24 12:22:27 volumio sudo[1599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:27 volumio sudo[1597]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:27 volumio systemd[1]: Reloading. Mar 24 12:22:29 volumio sudo[1599]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:29 volumio systemd[1]: Reloading. Mar 24 12:22:30 volumio sudo[1595]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:32 volumio sudo[1597]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:32 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 12:22:32 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 12:22:32 volumio volumio[1256]: info: Discovery: Getting this device information Mar 24 12:22:32 volumio volumio[1256]: info: CoreCommandRouter::volumioGetState Mar 24 12:22:32 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:22:32 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 12:22:32 volumio volumio[1256]: info: Discovery: adding 1e937346-4e04-46db-ac56-06b57d5fa5a6 Mar 24 12:22:32 volumio volumio[1256]: info: Discovery: Found device Volumio Mar 24 12:22:32 volumio volumio[1256]: info: CoreCommandRouter::volumioGetState Mar 24 12:22:32 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:22:32 volumio volumio[1256]: info: Discovery: this is already registered, 1e937346-4e04-46db-ac56-06b57d5fa5a6 Mar 24 12:22:32 volumio volumio-remote-updater[718]: [2026-03-24 12:22:32] [connect] Successful connection Mar 24 12:22:32 volumio volumio[1256]: info: Discovery: Found device Volumio Mar 24 12:22:32 volumio volumio[1256]: info: CoreCommandRouter::volumioGetState Mar 24 12:22:32 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:22:32 volumio volumio[1256]: info: touch_display: No backlight interface detected. Mar 24 12:22:32 volumio mpd[1545]: 2026-03-24T12:22:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 24 12:22:33 volumio volumio[1256]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Mar 24 12:22:33 volumio systemd[1]: Started mpd.service - Music Player Daemon. Mar 24 12:22:33 volumio sudo[1521]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:33 volumio sudo[1506]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:33 volumio volumio[1256]: info: touch_display: systemctl daemon-reload succeeded. Mar 24 12:22:33 volumio volumio[1256]: info: touch_display: systemctl disable getty@tty1.service succeeded. Mar 24 12:22:33 volumio volumio[1256]: info: touch_display: systemctl stop getty@tty1.service succeeded. Mar 24 12:22:33 volumio volumio[1256]: info: ir_controller: File permissions successfully set on /etc/lirc/*. Mar 24 12:22:33 volumio volumio[1256]: info: MPD Permissions set Mar 24 12:22:33 volumio volumio[1256]: info: MPD Permissions set Mar 24 12:22:33 volumio volumio[1256]: info: Upmpdcli Daemon Started Mar 24 12:22:33 volumio sudo[1654]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Mar 24 12:22:33 volumio sudo[1654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:33 volumio volumio[1256]: 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: 5 Mar 24 12:22:33 volumio systemd[1]: Started volumio-kiosk.service - Volumio Kiosk. Mar 24 12:22:33 volumio sudo[1654]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:34 volumio startx[1684]: X.Org X Server 1.21.1.7 Mar 24 12:22:34 volumio startx[1684]: X Protocol Version 11, Revision 0 Mar 24 12:22:34 volumio startx[1684]: Current Operating System: Linux volumio 6.12.47-v7+ #1904 SMP Mon Sep 15 13:05:52 BST 2025 armv7l Mar 24 12:22:34 volumio startx[1684]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 cgroup_disable=memory snd_bcm2835.enable_hdmi=0 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=14aa58b3-7c1f-46d2-b4f1-3f56bb2e4191 imgfile=/volumio_current.sqsh bootpart=UUID=5149-F647 datapart=UUID=0ee32d5b-7bbc-42b2-916c-34f329fe6377 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 24 12:22:34 volumio startx[1684]: xorg-server 2:21.1.7-3+rpt3+deb12u11 (https://www.debian.org/support) Mar 24 12:22:34 volumio startx[1684]: Current version of pixman: 0.44.0 Mar 24 12:22:34 volumio startx[1684]: Before reporting problems, check http://wiki.x.org Mar 24 12:22:34 volumio startx[1684]: to make sure that you have the latest version. Mar 24 12:22:34 volumio startx[1684]: Markers: (--) probed, (**) from config file, (==) default setting, Mar 24 12:22:34 volumio startx[1684]: (++) from command line, (!!) notice, (II) informational, Mar 24 12:22:34 volumio startx[1684]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Mar 24 12:22:34 volumio startx[1684]: (==) Log file: "/var/log/Xorg.0.log", Time: Tue Mar 24 12:22:34 2026 Mar 24 12:22:34 volumio startx[1684]: (==) Using config directory: "/etc/X11/xorg.conf.d" Mar 24 12:22:34 volumio startx[1684]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Mar 24 12:22:34 volumio sudo[1657]: 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 24 12:22:34 volumio sudo[1657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:34 volumio volumio[1256]: info: Volumio called home Mar 24 12:22:34 volumio sudo[1657]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:34 volumio volumio[1256]: 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: 5 Mar 24 12:22:34 volumio volumio[1256]: info: Received Get System Info Mar 24 12:22:34 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 12:22:34 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 12:22:34 volumio volumio[1256]: info: Discovery: Getting this device information Mar 24 12:22:34 volumio volumio[1256]: info: CoreCommandRouter::volumioGetState Mar 24 12:22:34 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:22:34 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 12:22:34 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:34.571+03:00 level=INFO msg="system info for 8a170db0a357b781d09c179a49b5a134" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 12:22:34 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:34.677+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 12:22:35 volumio volumio-remote-updater[718]: [2026-03-24 12:22:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774344152 101 Mar 24 12:22:35 volumio volumio[1256]: 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: 6 Mar 24 12:22:35 volumio volumio[1256]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Mar 24 12:22:35 volumio volumio[1256]: info: touch_display: Volumio Kiosk started. Mar 24 12:22:35 volumio volumio[1256]: info: CoreCommandRouter::volumioGetState Mar 24 12:22:35 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:22:36 volumio volumio[1256]: info: Received Get System Info Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 12:22:36 volumio volumio[1256]: info: Discovery: Getting this device information Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::volumioGetState Mar 24 12:22:36 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:22:36 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 12:22:37 volumio volumio[1256]: error: MPD error: The expression evaluated to a falsy value: Mar 24 12:22:37 volumio volumio[1256]: assert.ok(self.idling) Mar 24 12:22:37 volumio volumio[1256]: error: The expression evaluated to a falsy value: Mar 24 12:22:37 volumio volumio[1256]: assert.ok(self.idling) Mar 24 12:22:38 volumio volumio[1256]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 24 12:22:38 volumio volumio[1256]: info: MPD running with PID1545 Mar 24 12:22:38 volumio volumio[1256]: ,establishing connection Mar 24 12:22:38 volumio volumio[1256]: info: touch_display: IframeKeyboardBridge extension installed successfully Mar 24 12:22:38 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 12:22:38 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 12:22:38 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 12:22:38 volumio volumio[1256]: error: updateQueue error: null Mar 24 12:22:38 volumio volumio[1256]: info: touch_display: X display number found: 0 Mar 24 12:22:38 volumio volumio[1256]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Mar 24 12:22:38 volumio sudo[1772]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Mar 24 12:22:38 volumio volumio[1256]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 12:22:38 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 12:22:38 volumio sudo[1772]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:39 volumio sudo[1772]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:39 volumio sudo[1777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Mar 24 12:22:39 volumio sudo[1777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:39 volumio volumio[1256]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Mar 24 12:22:39 volumio sudo[1777]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:39 volumio volumio[1256]: info: Starting Shairport Sync Mar 24 12:22:39 volumio volumio[1256]: info: Starting Shairport Sync Mar 24 12:22:39 volumio volumio[1256]: info: Starting Shairport Sync Mar 24 12:22:39 volumio volumio[1256]: error: updateQueue error: null Mar 24 12:22:39 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 12:22:39 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:39.389+03: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 24 12:22:39 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:39.391+03: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 24 12:22:39 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:39.391+03: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 24 12:22:39 volumio sudo[1800]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 12:22:39 volumio sudo[1797]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 12:22:39 volumio sudo[1800]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:39 volumio sudo[1797]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:39 volumio sudo[1801]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 12:22:39 volumio sudo[1801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 12:22:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 12:22:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 12:22:39 volumio systemd[1]: shairport-sync.service: Consumed 1.717s CPU time. Mar 24 12:22:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 12:22:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 12:22:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 12:22:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 12:22:39 volumio sudo[1797]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 12:22:39 volumio sudo[1801]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:39 volumio sudo[1800]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:39 volumio volumio[1256]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Mar 24 12:22:39 volumio volumio[1256]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Mar 24 12:22:39 volumio volumio[1256]: info: touch_display: X display number found: 0 Mar 24 12:22:40 volumio volumio[1256]: info: ir_controller: LIRC correctly updated. Mar 24 12:22:40 volumio volumio[1256]: info: ir_controller: HAT did not load /proc/device-tree/ir_receiver! Mar 24 12:22:40 volumio volumio[1256]: info: Completed starting Core Plugins Mar 24 12:22:40 volumio volumio[1256]: info: ------------------------------------------- Mar 24 12:22:40 volumio volumio[1256]: info: ----- MyVolumio plugins startup ---- Mar 24 12:22:40 volumio volumio[1256]: info: ------------------------------------------- Mar 24 12:22:40 volumio volumio[1256]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 24 12:22:40 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 12:22:40 volumio volumio[1256]: info: CoreCommandRouter::volumioGetState Mar 24 12:22:40 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:22:40 volumio volumio[1256]: info: Shairport-Sync Started Mar 24 12:22:40 volumio volumio[1256]: Error adding Membership: Error: addMembership EINVAL Mar 24 12:22:40 volumio volumio[1256]: info: Shairport-Sync Started Mar 24 12:22:40 volumio volumio[1256]: info: Shairport-Sync Started Mar 24 12:22:40 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 12:22:41 volumio volumio[1256]: info: ir_controller: Raspberry Pi revision code: a02082 Mar 24 12:22:41 volumio volumio[1256]: info: Received Get System Info Mar 24 12:22:41 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 12:22:41 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 12:22:41 volumio volumio[1256]: info: Discovery: Getting this device information Mar 24 12:22:41 volumio volumio[1256]: info: CoreCommandRouter::volumioGetState Mar 24 12:22:41 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:22:41 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 12:22:41 volumio volumio[1256]: info: CoreCommandRouter::volumioGetState Mar 24 12:22:41 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:22:41 volumio sudo[1857]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart lircd.service Mar 24 12:22:41 volumio sudo[1857]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:41 volumio systemd[1]: Starting lircd-setup.service - lircd(8) initialization helper tool... Mar 24 12:22:41 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 12:22:41 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 12:22:41 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:41.807+03:00 level=INFO msg="enabling local network discovery" Mar 24 12:22:41 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:41.841+03:00 level=INFO msg="enabling BLE discovery" Mar 24 12:22:42 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:42.060+03:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.0.25:39934 Mar 24 12:22:42 volumio lircd-setup[1859]: /usr/sbin/lircd-setup:37: DeprecationWarning: The SafeConfigParser class has been renamed to ConfigParser in Python 3.2. This alias will be removed in Python 3.12. Use ConfigParser directly instead. Mar 24 12:22:42 volumio lircd-setup[1859]: parser = configparser.SafeConfigParser() Mar 24 12:22:42 volumio systemd[1]: lircd-setup.service: Deactivated successfully. Mar 24 12:22:42 volumio systemd[1]: Finished lircd-setup.service - lircd(8) initialization helper tool. Mar 24 12:22:42 volumio systemd[1]: Starting lircd.service - Flexible IR remote input/output application support... Mar 24 12:22:42 volumio lircd-0.10.1[1875]: Info: lircd: Opening log, level: Info Mar 24 12:22:42 volumio lircd-0.10.1[1875]: Notice: Version: lircd 0.10.1 Mar 24 12:22:42 volumio lircd-0.10.1[1875]: Notice: System info: Linux volumio 6.12.47-v7+ #1904 SMP Mon Sep 15 13:05:52 BST 2025 armv7l GNU/Linux Mar 24 12:22:42 volumio volumio[1256]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 24 12:22:42 volumio sudo[1874]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -r -1 Mar 24 12:22:42 volumio sudo[1874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:42 volumio sudo[1874]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:42 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:42.828+03:00 level=INFO msg="service successfully established" component=discovery/localnet Mar 24 12:22:43 volumio volumio[1256]: info: CoreCommandRouter::volumioGetState Mar 24 12:22:43 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Info: Initial device: /dev/lirc0 Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Warning: Cannot access device: /dev/lirc0 Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Info: Initial device: /dev/lirc0 Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Warning: Cannot access device: /dev/lirc0 Mar 24 12:22:43 volumio lircd[1875]: lircd-0.10.1[1875]: Info: lircd: Opening log, level: Info Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: driver: default Mar 24 12:22:43 volumio lircd[1875]: lircd-0.10.1[1875]: Notice: Using systemd fd Mar 24 12:22:43 volumio lircd[1875]: lircd-0.10.1[1875]: Warning: Running as root Mar 24 12:22:43 volumio lircd[1875]: lircd-0.10.1[1875]: Info: Using remote: lircd.conf. Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: output: /var/run/lirc/lircd Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: nodaemon: 1 Mar 24 12:22:43 volumio lircd[1875]: lircd-0.10.1[1875]: Notice: lircd(default) ready, using /var/run/lirc/lircd Mar 24 12:22:43 volumio systemd[1]: Started lircd.service - Flexible IR remote input/output application support. Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: plugindir: /usr/lib/arm-linux-gnueabihf/lirc/plugins Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: logfile: syslog Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: immediate-init: 0 Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: permission: 666 Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: driver-options: Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: pidfile: /var/run/lirc/lircd.pid Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: listen: 0 Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: connect: (null) Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: userelease: 0 Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: effective_user: (null) Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: release_suffix: _EVUP Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: allow_simulate: 0 Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: repeat_max: 600 Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: configfile: /etc/lirc/lircd.conf Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Options: dynamic_codes: (null) Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Current driver: default Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Driver API version: 3 Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Driver version: 0.10.0 Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Driver info: See file:///usr/share/doc/lirc/plugindocs/default.html Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Info: lircd: Opening log, level: Info Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: Using systemd fd Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Warning: Running as root Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Info: Using remote: lircd.conf. Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: lircd(default) ready, using /var/run/lirc/lircd Mar 24 12:22:43 volumio sudo[1857]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:43 volumio volumio[1256]: info: ir_controller: systemctl restart lircd.service succeeded. Mar 24 12:22:43 volumio sudo[1880]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart irexec.service Mar 24 12:22:43 volumio sudo[1880]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:43 volumio systemd[1]: Started irexec.service - Handle events from IR remotes decoded by lircd(8). Mar 24 12:22:43 volumio sudo[1880]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:43 volumio lircd[1875]: lircd-0.10.1[1875]: Notice: accepted new client on /var/run/lirc/lircd Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Notice: accepted new client on /var/run/lirc/lircd Mar 24 12:22:43 volumio lircd[1875]: lircd-0.10.1[1875]: Info: Cannot configure the rc device for /dev/lirc0 Mar 24 12:22:43 volumio lircd[1875]: lircd-0.10.1[1875]: Error: could not get file information for /dev/lirc0 Mar 24 12:22:43 volumio lircd[1875]: lircd-0.10.1[1875]: default_init(): No such file or directory Mar 24 12:22:43 volumio lircd[1875]: lircd-0.10.1[1875]: Warning: Failed to initialize hardware Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Info: Cannot configure the rc device for /dev/lirc0 Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Error: could not get file information for /dev/lirc0 Mar 24 12:22:43 volumio lircd-0.10.1[1875]: default_init(): No such file or directory Mar 24 12:22:43 volumio lircd-0.10.1[1875]: Warning: Failed to initialize hardware Mar 24 12:22:44 volumio volumio[1256]: info: ir_controller: systemctl restart irexec.service succeeded. Mar 24 12:22:44 volumio lircd[1875]: lircd-0.10.1[1875]: Error: could not get file information for /dev/lirc0 Mar 24 12:22:44 volumio lircd[1875]: lircd-0.10.1[1875]: default_init(): No such file or directory Mar 24 12:22:44 volumio lircd-0.10.1[1875]: Error: could not get file information for /dev/lirc0 Mar 24 12:22:44 volumio lircd-0.10.1[1875]: default_init(): No such file or directory Mar 24 12:22:45 volumio sudo[1902]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-ir gpio_pin=17 gpio_pull=up Mar 24 12:22:45 volumio sudo[1902]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:45 volumio lircd[1875]: lircd-0.10.1[1875]: Error: could not get file information for /dev/lirc0 Mar 24 12:22:45 volumio lircd[1875]: lircd-0.10.1[1875]: default_init(): No such file or directory Mar 24 12:22:45 volumio lircd-0.10.1[1875]: Error: could not get file information for /dev/lirc0 Mar 24 12:22:45 volumio lircd-0.10.1[1875]: default_init(): No such file or directory Mar 24 12:22:45 volumio kernel: Registered IR keymap rc-rc6-mce Mar 24 12:22:45 volumio kernel: IR RC6 protocol handler initialized Mar 24 12:22:45 volumio kernel: rc rc1: gpio_ir_recv as /devices/platform/ir-receiver@11/rc/rc1 Mar 24 12:22:45 volumio kernel: rc rc1: lirc_dev: driver gpio_ir_recv registered at minor = 0, raw IR receiver, no transmitter Mar 24 12:22:45 volumio kernel: input: gpio_ir_recv as /devices/platform/ir-receiver@11/rc/rc1/input2 Mar 24 12:22:45 volumio sudo[1902]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:45 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:45.994+03:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.0.25:39934 @ 0x2ffe510" latency=830.966102ms timeout=10s Mar 24 12:22:45 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:45.994+03:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.0.25:39934 @ 0x2ffe510" Mar 24 12:22:45 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:45.996+03:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.0.25:39934 @ 0x2ffe510" latency=833.979674ms platform=PLATFORM_ANDROID version=5.260209.0 Mar 24 12:22:46 volumio systemd-logind[711]: Watching system buttons on /dev/input/event2 (gpio_ir_recv) Mar 24 12:22:48 volumio volumio[1256]: info: Received Get System Info Mar 24 12:22:48 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 12:22:48 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 12:22:48 volumio volumio[1256]: info: Discovery: Getting this device information Mar 24 12:22:48 volumio volumio[1256]: info: CoreCommandRouter::volumioGetState Mar 24 12:22:48 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:22:48 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 12:22:48 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 12:22:48 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 12:22:48 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:48.368+03:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.0.25:39934 @ 0x2ffe510" name=Volumio Mar 24 12:22:48 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:48.390+03:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.0.25:39934 @ 0x2ffe510" language=ru Mar 24 12:22:48 volumio volumio[1256]: info: ir_controller: Overlay gpio-ir gpio_pin=17 gpio_pull=up loaded. Mar 24 12:22:50 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Mar 24 12:22:50 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:50.060+03:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.0.25:39934 @ 0x2ffe510" timezone=Europe/Moscow Mar 24 12:22:50 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:50.066+03:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.0.25:39934 @ 0x2ffe510" available=true connected=true macAddress=b8:27:eb:7a:9f:34 ip4Address=192.168.0.70/24 ip6Address= Mar 24 12:22:50 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:50.076+03:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.0.25:39934 @ 0x2ffe510" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Mar 24 12:22:50 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:50.080+03:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.0.25:39934 @ 0x2ffe510" setupComplete=true Mar 24 12:22:50 volumio sudo[1955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart lircd.service Mar 24 12:22:50 volumio sudo[1955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:50 volumio lircd[1875]: lircd-0.10.1[1875]: Notice: caught signal Mar 24 12:22:50 volumio lircd-0.10.1[1875]: Notice: caught signal Mar 24 12:22:50 volumio systemd[1]: Stopping lircd.service - Flexible IR remote input/output application support... Mar 24 12:22:50 volumio systemd[1]: lircd.service: Deactivated successfully. Mar 24 12:22:50 volumio systemd[1]: Stopped lircd.service - Flexible IR remote input/output application support. Mar 24 12:22:50 volumio systemd[1]: irexec.service: Deactivated successfully. Mar 24 12:22:51 volumio systemd[1]: Starting lircd-setup.service - lircd(8) initialization helper tool... Mar 24 12:22:51 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Mar 24 12:22:51 volumio lircd-setup[1984]: /usr/sbin/lircd-setup:37: DeprecationWarning: The SafeConfigParser class has been renamed to ConfigParser in Python 3.2. This alias will be removed in Python 3.12. Use ConfigParser directly instead. Mar 24 12:22:51 volumio lircd-setup[1984]: parser = configparser.SafeConfigParser() Mar 24 12:22:51 volumio systemd[1]: lircd-setup.service: Deactivated successfully. Mar 24 12:22:51 volumio systemd[1]: Finished lircd-setup.service - lircd(8) initialization helper tool. Mar 24 12:22:51 volumio systemd[1]: Starting lircd.service - Flexible IR remote input/output application support... Mar 24 12:22:51 volumio lircd-0.10.1[1995]: Info: lircd: Opening log, level: Info Mar 24 12:22:51 volumio lircd-0.10.1[1995]: Notice: Version: lircd 0.10.1 Mar 24 12:22:51 volumio lircd-0.10.1[1995]: Notice: System info: Linux volumio 6.12.47-v7+ #1904 SMP Mon Sep 15 13:05:52 BST 2025 armv7l GNU/Linux Mar 24 12:22:51 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Info: Initial device: /dev/lirc0 Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Info: [lirc] protocol is enabled Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Info: Initial device: /dev/lirc0 Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Info: [lirc] protocol is enabled Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: driver: default Mar 24 12:22:52 volumio lircd[1995]: lircd-0.10.1[1995]: Info: lircd: Opening log, level: Info Mar 24 12:22:52 volumio lircd[1995]: lircd-0.10.1[1995]: Notice: Using systemd fd Mar 24 12:22:52 volumio lircd[1995]: lircd-0.10.1[1995]: Warning: Running as root Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: output: /var/run/lirc/lircd Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: nodaemon: 1 Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: plugindir: /usr/lib/arm-linux-gnueabihf/lirc/plugins Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: logfile: syslog Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: immediate-init: 0 Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: permission: 666 Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: driver-options: Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: pidfile: /var/run/lirc/lircd.pid Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: listen: 0 Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: connect: (null) Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: userelease: 0 Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: effective_user: (null) Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: release_suffix: _EVUP Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: allow_simulate: 0 Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: repeat_max: 600 Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: configfile: /etc/lirc/lircd.conf Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Options: dynamic_codes: (null) Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Current driver: default Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Driver API version: 3 Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Driver version: 0.10.0 Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Driver info: See file:///usr/share/doc/lirc/plugindocs/default.html Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Info: lircd: Opening log, level: Info Mar 24 12:22:52 volumio lircd[1995]: lircd-0.10.1[1995]: Info: Using remote: lircd.conf. Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: Using systemd fd Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Warning: Running as root Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Info: Using remote: lircd.conf. Mar 24 12:22:52 volumio lircd[1995]: lircd-0.10.1[1995]: Notice: lircd(default) ready, using /var/run/lirc/lircd Mar 24 12:22:52 volumio lircd-0.10.1[1995]: Notice: lircd(default) ready, using /var/run/lirc/lircd Mar 24 12:22:52 volumio systemd[1]: Started lircd.service - Flexible IR remote input/output application support. Mar 24 12:22:52 volumio sudo[1955]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:52 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 12:22:52 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 24 12:22:52 volumio volumio[1256]: amixer -c 3 info | grep "snd_rpi_hifiberry_dacplus" Mar 24 12:22:52 volumio volumio[1256]: Card sysdefault:3 'sndrpihifiberry'/'snd_rpi_hifiberry_dacplus' Mar 24 12:22:52 volumio volumio[1256]: amixer -c 0 info | grep "bcm2835 ALSA" Mar 24 12:22:52 volumio volumio[1256]: amixer -c 1 info | grep "bcm2835 Headphones" Mar 24 12:22:52 volumio volumio[1256]: Card sysdefault:1 'Headphones'/'bcm2835 Headphones' Mar 24 12:22:52 volumio volumio[1256]: amixer -c 3 info | grep "snd_rpi_hifiberry_dacplus" Mar 24 12:22:52 volumio volumio[1256]: Card sysdefault:3 'sndrpihifiberry'/'snd_rpi_hifiberry_dacplus' Mar 24 12:22:55 volumio volumio[1256]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 2 Mar 24 12:22:55 volumio volumio[1256]: /bin/sh: 1: /usr/local/bin/alsacap: not found Mar 24 12:22:55 volumio volumio[1256]: {"cmd":"/usr/local/bin/alsacap -C 2","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 2\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 24 12:22:55 volumio volumio[1256]: amixer -c 2 info | grep "vc4-hdmi" Mar 24 12:22:56 volumio volumio5-onboarding[1529]: time=2026-03-24T12:22:56.011+03:00 level=ERROR msg="failed to notify all device data" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.0.25:39934 @ 0x2ffe510" latency=830.966102ms timeout=10s error="failed to get output devices: could not get extended output devices: context deadline exceeded" Mar 24 12:22:56 volumio volumio[1256]: Card sysdefault:2 'vc4hdmi'/'vc4-hdmi' Mar 24 12:22:56 volumio volumio[1256]: info: ir_controller: systemctl restart lircd.service succeeded. Mar 24 12:22:56 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 12:22:56 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 12:22:56 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 24 12:22:56 volumio sudo[2027]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart irexec.service Mar 24 12:22:56 volumio sudo[2027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 12:22:56 volumio systemd[1]: Started irexec.service - Handle events from IR remotes decoded by lircd(8). Mar 24 12:22:56 volumio sudo[2027]: pam_unix(sudo:session): session closed for user root Mar 24 12:22:56 volumio lircd[1995]: lircd-0.10.1[1995]: Notice: accepted new client on /var/run/lirc/lircd Mar 24 12:22:56 volumio lircd-0.10.1[1995]: Notice: accepted new client on /var/run/lirc/lircd Mar 24 12:22:56 volumio lircd[1995]: lircd-0.10.1[1995]: Info: [lirc] protocol is enabled Mar 24 12:22:56 volumio lircd-0.10.1[1995]: Info: [lirc] protocol is enabled Mar 24 12:23:01 volumio volumio[1256]: info: ir_controller: systemctl restart irexec.service succeeded. Mar 24 12:23:01 volumio volumio[1256]: error: MyVolumio Plugin failed to start in a timely fashion Mar 24 12:23:01 volumio volumio[1256]: [Metrics] CommandRouter: 66s 841.44ms Mar 24 12:23:01 volumio volumio[1256]: info: CoreCommandRouter::volumiosetStartupVolume Mar 24 12:23:01 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 12:23:01 volumio volumio[1256]: info: VolumeController:: Setting startup Volume 30 Mar 24 12:23:01 volumio volumio[1256]: info: VolumeController::SetAlsaVolume30 Mar 24 12:23:01 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 12:23:01 volumio volumio[1256]: info: CoreCommandRouter::Close All Modals sent Mar 24 12:23:01 volumio volumio[1256]: info: CoreCommandRouter::Close All Modals sent Mar 24 12:23:01 volumio volumio[1256]: info: CoreStateMachine::pushState Mar 24 12:23:01 volumio volumio[1256]: info: CorePlayQueue::getTrack 0 Mar 24 12:23:01 volumio volumio[1256]: info: CoreCommandRouter::volumioPushState Mar 24 12:23:01 volumio volumio5-onboarding[1529]: time=2026-03-24T12:23:01.722+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.25:39934 @ 0x2ffe510" state=STATUS_STOPPED positionMs=0 volume=100 Mar 24 12:23:01 volumio volumio5-onboarding[1529]: time=2026-03-24T12:23:01.724+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.25:39934 @ 0x2ffe510" id="mnt/NAS/HDD2/HI-RES/© 1982 P.F.T - Paris France Transit/01. Paris-France-Transit.flac" title=Paris-France-Transit Mar 24 12:23:11 volumio volumio5-onboarding[1529]: time=2026-03-24T12:23:11.132+03:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.0.25:39934 @ 0x2ffe510" latency=807.166959ms platform=PLATFORM_ANDROID version=5.260209.0 Mar 24 12:23:11 volumio volumio5-onboarding[1529]: time=2026-03-24T12:23:11.132+03:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.0.25:39934 @ 0x2ffe510" latency=807.441697ms timeout=10s Mar 24 12:23:11 volumio volumio5-onboarding[1529]: time=2026-03-24T12:23:11.132+03:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.0.25:39934 @ 0x2ffe510" Mar 24 12:23:11 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 24 12:23:11 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 24 12:23:11 volumio volumio[1256]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 24 12:23:11 volumio volumio[1256]: info: BOOT COMPLETED Mar 24 12:23:11 volumio volumio[1256]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 12:23:11 volumio volumio[1256]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Mar 24 12:23:11 volumio volumio[1256]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Mar 24 12:23:11 volumio volumio[1256]: at new NodeError (node:internal/errors:405:5) Mar 24 12:23:11 volumio volumio[1256]: at assert (node:internal/assert:14:11) Mar 24 12:23:11 volumio volumio[1256]: at internalConnectMultiple (node:net:1118:3) Mar 24 12:23:11 volumio volumio[1256]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Mar 24 12:23:11 volumio volumio[1256]: at listOnTimeout (node:internal/timers:575:11) Mar 24 12:23:11 volumio volumio[1256]: at process.processTimers (node:internal/timers:514:7) { Mar 24 12:23:11 volumio volumio[1256]: code: 'ERR_INTERNAL_ASSERTION' Mar 24 12:23:11 volumio volumio[1256]: } Mar 24 12:23:11 volumio volumio[1256]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 12:23:18 volumio sudo[2077]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 12:22' Mar 24 12:23:18 volumio sudo[2077]: 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="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"