Mar 26 15:37:39 mp-dx systemd[1]: setdatetime-helper.service: Deactivated successfully. Mar 26 15:37:39 mp-dx systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Mar 26 15:37:39 mp-dx systemd[1]: setdatetime-helper.service: Consumed 1.524s CPU time. Mar 26 15:37:39 mp-dx ntpd[822]: IO: Listen normally on 3 eth0 192.168.178.216:123 Mar 26 15:37:39 mp-dx ntpd[822]: IO: new interface(s) found: waking up resolver Mar 26 15:37:39 mp-dx ntpd[822]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Mar 26 15:37:39 mp-dx ntpd[822]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Mar 26 15:37:39 mp-dx ntpd[822]: DNS: Pool skipping: 77.37.65.181 Mar 26 15:37:39 mp-dx ntpd[822]: DNS: Pool skipping: 104.167.24.26 Mar 26 15:37:39 mp-dx ntpd[822]: DNS: Pool skipping: 159.69.64.189 Mar 26 15:37:39 mp-dx ntpd[822]: DNS: Pool skipping: 130.162.222.153 Mar 26 15:37:39 mp-dx ntpd[822]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Mar 26 15:37:39 mp-dx winbindd[991]: [2026/03/26 15:37:39.111077, 0] ../../source3/winbindd/winbindd.c:1440(main) Mar 26 15:37:39 mp-dx winbindd[991]: winbindd version 4.17.8-Raspbian started. Mar 26 15:37:39 mp-dx winbindd[991]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Mar 26 15:37:39 mp-dx wireless.js[637]: WIRELESS.JS - INFO: === SNM TRANSITION === Mar 26 15:37:39 mp-dx wireless.js[637]: WIRELESS.JS - INFO: Previous ethernet state: disconnected Mar 26 15:37:39 mp-dx wireless.js[637]: WIRELESS.JS - INFO: New ethernet state: connected Mar 26 15:37:39 mp-dx wireless.js[637]: WIRELESS.JS - INFO: Single Network Mode: enabled Mar 26 15:37:39 mp-dx wireless.js[637]: WIRELESS.JS - INFO: First start: yes Mar 26 15:37:39 mp-dx wireless.js[637]: WIRELESS.JS - INFO: Action: Switch to ethernet (WiFi scan mode) Mar 26 15:37:39 mp-dx systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Mar 26 15:37:39 mp-dx wireless.js[637]: WIRELESS.JS - INFO: === END TRANSITION === Mar 26 15:37:39 mp-dx wireless.js[637]: WIRELESS.JS - INFO: Wireless.js initializing wireless flow Mar 26 15:37:39 mp-dx systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Mar 26 15:37:39 mp-dx winbindd[991]: [2026/03/26 15:37:39.162257, 0] ../../source3/winbindd/winbindd_cache.c:3116(initialize_winbindd_cache) Mar 26 15:37:39 mp-dx winbindd[991]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Mar 26 15:37:39 mp-dx systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Mar 26 15:37:39 mp-dx wireless.js[637]: WIRELESS.JS - INFO: ERROR: wlan0 does not exist, exiting... Mar 26 15:37:39 mp-dx systemd[1]: Started winbind.service - Samba Winbind Daemon. Mar 26 15:37:39 mp-dx systemd[1]: Starting smbd.service - Samba SMB Daemon... Mar 26 15:37:39 mp-dx systemd[1]: wireless.service: Main process exited, code=exited, status=1/FAILURE Mar 26 15:37:39 mp-dx systemd[1]: wireless.service: Killing process 1021 (sh) with signal SIGKILL. Mar 26 15:37:39 mp-dx systemd[1]: wireless.service: Killing process 1023 (pkill) with signal SIGKILL. Mar 26 15:37:39 mp-dx systemd[1]: wireless.service: Failed with result 'exit-code'. Mar 26 15:37:39 mp-dx systemd[1]: Failed to start wireless.service - Wireless Services. Mar 26 15:37:39 mp-dx systemd[1]: wireless.service: Consumed 12.105s CPU time. Mar 26 15:37:39 mp-dx systemd[1]: Started volumio.service - Volumio Backend Module. Mar 26 15:37:39 mp-dx systemd[1]: Starting plymouth-quit.service - Terminate Plymouth Boot Screen... Mar 26 15:37:39 mp-dx systemd[1]: Started volumio_cpu_tweak.service - Volumio Cpu Tweaker. Mar 26 15:37:39 mp-dx systemd[1]: Finished plymouth-quit-wait.service - Hold until boot process finishes up. Mar 26 15:37:39 mp-dx systemd[1]: Finished plymouth-quit.service - Terminate Plymouth Boot Screen. Mar 26 15:37:39 mp-dx systemd[1]: Received SIGRTMIN+21 from PID 280 (n/a). Mar 26 15:37:39 mp-dx systemd[1]: Received SIGRTMIN+21 from PID 280 (n/a). Mar 26 15:37:39 mp-dx systemd[1]: Started getty@tty1.service - Getty on tty1. Mar 26 15:37:39 mp-dx systemd[1]: Started serial-getty@ttyAMA0.service - Serial Getty on ttyAMA0. Mar 26 15:37:39 mp-dx systemd[1]: Reached target getty.target - Login Prompts. Mar 26 15:37:39 mp-dx systemd[1]: dpkg-db-backup.service: Deactivated successfully. Mar 26 15:37:39 mp-dx systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Mar 26 15:37:39 mp-dx volumio-cpu-tweak[1033]: Setting RT Priority for mpd Mar 26 15:37:39 mp-dx volumio-cpu-tweak[1051]: pid 35's current scheduling policy: SCHED_OTHER Mar 26 15:37:39 mp-dx volumio-cpu-tweak[1051]: pid 35's current scheduling priority: 0 Mar 26 15:37:39 mp-dx volumio-cpu-tweak[1033]: Setting MPD Affinity Mar 26 15:37:39 mp-dx volumio-cpu-tweak[1052]: pid 3's current affinity mask: f Mar 26 15:37:39 mp-dx volumio-cpu-tweak[1033]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Mar 26 15:37:39 mp-dx volumio-cpu-tweak[1033]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Mar 26 15:37:39 mp-dx systemd[1]: volumio_cpu_tweak.service: Deactivated successfully. Mar 26 15:37:40 mp-dx ntpd[822]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Mar 26 15:37:40 mp-dx ntpd[822]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Mar 26 15:37:40 mp-dx ntpd[822]: DNS: Pool taking: 217.217.243.78 Mar 26 15:37:40 mp-dx ntpd[822]: DNS: Pool taking: 172.104.154.182 Mar 26 15:37:40 mp-dx ntpd[822]: DNS: Pool taking: 116.202.246.102 Mar 26 15:37:40 mp-dx ntpd[822]: DNS: Pool taking: 134.60.1.27 Mar 26 15:37:40 mp-dx ntpd[822]: DNS: Pool taking: 2606:4700:f1::123 Mar 26 15:37:40 mp-dx ntpd[822]: DNS: Pool taking: 2a01:4f8:201:3433::123 Mar 26 15:37:40 mp-dx ntpd[822]: DNS: Pool taking: 2003:a:843:7c00::2 Mar 26 15:37:40 mp-dx ntpd[822]: DNS: Pool taking: 2a0a:51c1:9:1a0::a Mar 26 15:37:40 mp-dx ntpd[822]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Mar 26 15:37:40 mp-dx smbd[1053]: [2026/03/26 15:37:40.374378, 0] ../../source3/smbd/server.c:1741(main) Mar 26 15:37:40 mp-dx smbd[1053]: smbd version 4.17.8-Raspbian started. Mar 26 15:37:40 mp-dx smbd[1053]: Copyright Andrew Tridgell and the Samba Team 1992-2022 Mar 26 15:37:41 mp-dx ntpd[822]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Mar 26 15:37:41 mp-dx ntpd[822]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Mar 26 15:37:41 mp-dx ntpd[822]: DNS: Pool taking: 130.61.133.198 Mar 26 15:37:41 mp-dx ntpd[822]: DNS: Pool taking: 85.214.133.14 Mar 26 15:37:41 mp-dx ntpd[822]: DNS: Pool taking: 77.42.16.222 Mar 26 15:37:41 mp-dx ntpd[822]: DNS: Pool taking: 94.16.122.152 Mar 26 15:37:41 mp-dx ntpd[822]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Mar 26 15:37:42 mp-dx ntpd[822]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Mar 26 15:37:42 mp-dx ntpd[822]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Mar 26 15:37:42 mp-dx ntpd[822]: DNS: Pool taking: 212.18.3.18 Mar 26 15:37:42 mp-dx ntpd[822]: DNS: Pool taking: 129.70.132.33 Mar 26 15:37:42 mp-dx ntpd[822]: DNS: Pool taking: 93.177.65.20 Mar 26 15:37:42 mp-dx ntpd[822]: DNS: Pool taking: 80.153.195.191 Mar 26 15:37:42 mp-dx ntpd[822]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Mar 26 15:37:42 mp-dx systemd[1]: Started smbd.service - Samba SMB Daemon. Mar 26 15:37:42 mp-dx systemd[1]: Reached target multi-user.target - Multi-User System. Mar 26 15:37:42 mp-dx systemd[1]: Reached target graphical.target - Graphical Interface. Mar 26 15:37:42 mp-dx systemd[1]: Starting systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP... Mar 26 15:37:43 mp-dx systemd[1]: systemd-update-utmp-runlevel.service: Deactivated successfully. Mar 26 15:37:43 mp-dx systemd[1]: Finished systemd-update-utmp-runlevel.service - Record Runlevel Change in UTMP. Mar 26 15:37:43 mp-dx systemd[1]: Startup finished in 18.925s (kernel) + 20.013s (userspace) = 38.939s. Mar 26 15:37:44 mp-dx volumio-remote-updater[633]: [2026-03-26 15:37:44] [info] asio async_connect error: asio.system:111 (Connection refused) Mar 26 15:37:44 mp-dx volumio-remote-updater[633]: [2026-03-26 15:37:44] [info] Error getting remote endpoint: asio.system:107 (Transport endpoint is not connected) Mar 26 15:37:44 mp-dx volumio-remote-updater[633]: [2026-03-26 15:37:44] [error] handle_connect error: Connection refused Mar 26 15:37:46 mp-dx ntpd[822]: CLOCK: time stepped by 0.299901 Mar 26 15:37:46 mp-dx ntpd[822]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Mar 26 15:37:47 mp-dx volumio[1030]: info: ------------------------------------------- Mar 26 15:37:47 mp-dx volumio[1030]: info: ----- Volumio3 ---- Mar 26 15:37:47 mp-dx volumio[1030]: info: ------------------------------------------- Mar 26 15:37:47 mp-dx volumio[1030]: info: ----- System startup ---- Mar 26 15:37:47 mp-dx volumio[1030]: info: ------------------------------------------- Mar 26 15:37:48 mp-dx systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 1. Mar 26 15:37:48 mp-dx systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 26 15:37:48 mp-dx systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 26 15:37:48 mp-dx upmpdcli[1086]: Could not open config: /tmp/upmpdcli.conf Mar 26 15:37:48 mp-dx systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Mar 26 15:37:48 mp-dx systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Mar 26 15:37:49 mp-dx volumio[1030]: info: MYVOLUMIO Environment detected Mar 26 15:37:49 mp-dx volumio[1030]: info: Plugin folders cleanup Mar 26 15:37:49 mp-dx volumio[1030]: info: Scanning into folder /volumio/app/plugins/ Mar 26 15:37:49 mp-dx volumio[1030]: info: Scanning category audio_interface Mar 26 15:37:49 mp-dx volumio[1030]: info: Scanning category miscellanea Mar 26 15:37:49 mp-dx volumio[1030]: info: Scanning category music_service Mar 26 15:37:49 mp-dx volumio[1030]: info: Scanning category plugins.json Mar 26 15:37:49 mp-dx volumio[1030]: info: Scanning category system_controller Mar 26 15:37:49 mp-dx volumio[1030]: info: Scanning category user_interface Mar 26 15:37:49 mp-dx volumio[1030]: info: Scanning into folder /data/plugins/ Mar 26 15:37:49 mp-dx volumio[1030]: info: Plugin folders cleanup completed Mar 26 15:37:49 mp-dx volumio[1030]: info: ------------------------------------------- Mar 26 15:37:49 mp-dx volumio[1030]: info: ----- Core plugins startup ---- Mar 26 15:37:49 mp-dx volumio[1030]: info: ------------------------------------------- Mar 26 15:37:49 mp-dx volumio[1030]: info: Loading plugins from folder /volumio/app/plugins/ Mar 26 15:37:49 mp-dx volumio[1030]: info: Adding plugin upnp to MyMusic Plugins Mar 26 15:37:49 mp-dx volumio[1030]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 26 15:37:49 mp-dx volumio[1030]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 26 15:37:49 mp-dx volumio[1030]: info: Loading plugins from folder /data/plugins/ Mar 26 15:37:49 mp-dx volumio[1030]: info: Loading plugin "system"... Mar 26 15:37:49 mp-dx volumio[1030]: info: Loading plugin "appearance"... Mar 26 15:37:53 mp-dx volumio[1030]: info: Loading plugin "network"... Mar 26 15:37:53 mp-dx volumio[1030]: info: Refreshing Cached IP Addresses Mar 26 15:37:53 mp-dx volumio[1030]: info: Loading plugin "services"... Mar 26 15:37:53 mp-dx volumio[1030]: info: Loading plugin "volumio5onboarding"... Mar 26 15:37:53 mp-dx volumio[1030]: info: Loading plugin "alsa_controller"... Mar 26 15:37:53 mp-dx sudo[1104]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 26 15:37:53 mp-dx sudo[1097]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 26 15:37:53 mp-dx sudo[1095]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 26 15:37:53 mp-dx sudo[1104]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 15:37:53 mp-dx sudo[1095]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 15:37:53 mp-dx sudo[1097]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 15:37:53 mp-dx sudo[1095]: pam_unix(sudo:session): session closed for user root Mar 26 15:37:53 mp-dx sudo[1104]: pam_unix(sudo:session): session closed for user root Mar 26 15:37:53 mp-dx sudo[1097]: pam_unix(sudo:session): session closed for user root Mar 26 15:37:53 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 26 15:37:53 mp-dx volumio[1030]: info: Loading plugin "wizard"... Mar 26 15:37:53 mp-dx volumio[1030]: info: Loading plugin "networkfs"... Mar 26 15:37:54 mp-dx volumio[1030]: info: Starting Udev Watcher for removable devices Mar 26 15:37:54 mp-dx sudo[1130]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Dirk,password=Vidfs@1964sieaw,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,noserverino //192.168.178.5/NAS /mnt/NAS/Synology Mar 26 15:37:54 mp-dx sudo[1130]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 15:37:54 mp-dx volumio[1030]: info: Ignoring mount for partition: boot Mar 26 15:37:54 mp-dx volumio[1030]: info: Ignoring mount for partition: volumio Mar 26 15:37:54 mp-dx volumio[1030]: info: Ignoring mount for partition: volumio_data Mar 26 15:37:54 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 26 15:37:54 mp-dx volumio[1030]: info: Loading plugin "volumio_command_line_client"... Mar 26 15:37:54 mp-dx volumio[1030]: info: Loading plugin "upnp"... Mar 26 15:37:54 mp-dx volumio[1030]: info: [1774535874128] Starting Upmpd Daemon Mar 26 15:37:54 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 26 15:37:54 mp-dx volumio[1030]: info: Loading plugin "my_music"... Mar 26 15:37:54 mp-dx volumio[1030]: info: Loading plugin "mpd"... Mar 26 15:37:54 mp-dx kernel: netfs: FS-Cache loaded Mar 26 15:37:54 mp-dx kernel: Key type cifs.spnego registered Mar 26 15:37:54 mp-dx kernel: Key type cifs.idmap registered Mar 26 15:37:54 mp-dx kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Mar 26 15:37:54 mp-dx kernel: CIFS: Attempting to mount //192.168.178.5/NAS Mar 26 15:37:55 mp-dx volumio-remote-updater[633]: [2026-03-26 15:37:55] [connect] Successful connection Mar 26 15:37:55 mp-dx kernel: cryptd: max_cpu_qlen set to 1000 Mar 26 15:37:55 mp-dx volumio[1030]: info: Loading plugin "upnp_browser"... Mar 26 15:37:56 mp-dx sudo[1130]: pam_unix(sudo:session): session closed for user root Mar 26 15:37:58 mp-dx systemd[1]: systemd-fsckd.service: Deactivated successfully. Mar 26 15:37:58 mp-dx volumio[1030]: info: Starting UPNP Browser Mar 26 15:37:58 mp-dx volumio[1030]: info: Loading plugin "alarm-clock"... Mar 26 15:37:58 mp-dx volumio[1030]: info: Loading plugin "airplay_emulation"... Mar 26 15:37:58 mp-dx volumio[1030]: info: Starting Shairport Sync Mar 26 15:37:58 mp-dx volumio[1030]: info: Loading plugin "last_100"... Mar 26 15:37:58 mp-dx volumio[1030]: info: Loading plugin "webradio"... Mar 26 15:37:59 mp-dx volumio[1030]: info: Loading plugin "i2s_dacs"... Mar 26 15:37:59 mp-dx volumio[1030]: info: Loading plugin "volumiodiscovery"... Mar 26 15:37:59 mp-dx volumio[1030]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 26 15:37:59 mp-dx volumio[1030]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 26 15:37:59 mp-dx volumio[1030]: *** WARNING *** For more information see Mar 26 15:37:59 mp-dx volumio[1030]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 26 15:37:59 mp-dx volumio[1030]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 26 15:37:59 mp-dx volumio[1030]: *** WARNING *** For more information see Mar 26 15:37:59 mp-dx node[1030]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 26 15:37:59 mp-dx node[1030]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 26 15:37:59 mp-dx node[1030]: *** WARNING *** For more information see Mar 26 15:37:59 mp-dx node[1030]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 26 15:37:59 mp-dx node[1030]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 26 15:37:59 mp-dx node[1030]: *** WARNING *** For more information see Mar 26 15:37:59 mp-dx volumio[1030]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 26 15:37:59 mp-dx volumio[1030]: info: Discovery: Started advertising with name: MP-DX Mar 26 15:37:59 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 26 15:37:59 mp-dx volumio[1030]: info: Loading plugin "outputs"... Mar 26 15:37:59 mp-dx volumio[1030]: info: Loading plugin "albumart"... Mar 26 15:37:59 mp-dx volumio[1030]: info: Plugin example_plugin is not enabled Mar 26 15:37:59 mp-dx volumio[1030]: info: Loading plugin "inputs"... Mar 26 15:37:59 mp-dx volumio[1030]: info: Loading plugin "updater_comm"... Mar 26 15:38:00 mp-dx volumio[1030]: info: Plugin mpdemulation is not enabled Mar 26 15:38:00 mp-dx volumio[1030]: info: Loading plugin "rest_api"... Mar 26 15:38:00 mp-dx volumio[1030]: info: Loading plugin "websocket"... Mar 26 15:38:00 mp-dx volumio[1030]: info: Starting Socket.io Server version 1.7.4 Mar 26 15:38:00 mp-dx volumio[1030]: info: Loading i18n strings for locale de Mar 26 15:38:00 mp-dx volumio[1030]: Updating browse sources language Mar 26 15:38:00 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 26 15:38:00 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 26 15:38:00 mp-dx volumio[1030]: info: CoreCommandRouter::initPlayerControls Mar 26 15:38:00 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:00 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:00 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:00 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:00 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:00 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:00 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:00 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:00 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 26 15:38:00 mp-dx volumio[1030]: Express server listening on port 3000 Mar 26 15:38:00 mp-dx volumio[1030]: [Metrics] WebUI: 15s 138.38ms Mar 26 15:38:01 mp-dx volumio[1030]: info: CoreStateMachine::resetVolumioState Mar 26 15:38:01 mp-dx volumio[1030]: info: CoreStateMachine::getcurrentVolume Mar 26 15:38:01 mp-dx volumio[1030]: info: CoreCommandRouter::volumioRetrievevolume Mar 26 15:38:01 mp-dx volumio[1030]: info: CoreStateMachine::pushState Mar 26 15:38:01 mp-dx volumio[1030]: info: CorePlayQueue::getTrack 0 Mar 26 15:38:01 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 15:38:01 mp-dx volumio[1030]: info: CoreCommandRouter::volumioPushState Mar 26 15:38:01 mp-dx volumio[1030]: info: Volumio Network Manager: Network status updated: 1 Mar 26 15:38:01 mp-dx volumio[1030]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Mar 26 15:38:01 mp-dx volumio[1030]: wlan0 Interface doesn't support scanning. Mar 26 15:38:01 mp-dx volumio[1030]: info: Cannot use regular scanning, forcing with ap-force Mar 26 15:38:01 mp-dx sudo[1191]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Mar 26 15:38:01 mp-dx sudo[1191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 15:38:01 mp-dx sudo[1191]: pam_unix(sudo:session): session closed for user root Mar 26 15:38:01 mp-dx volumio[1030]: command failed: No such device (-19) Mar 26 15:38:01 mp-dx volumio[1030]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Mar 26 15:38:01 mp-dx volumio[1030]: command failed: No such device (-19) Mar 26 15:38:01 mp-dx volumio[1030]: info: Reloading queue from file Mar 26 15:38:01 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 15:38:01 mp-dx volumio[1030]: info: CoreStateMachine::setRepeat null single undefined Mar 26 15:38:01 mp-dx volumio[1030]: info: CoreStateMachine::pushState Mar 26 15:38:01 mp-dx volumio[1030]: info: CorePlayQueue::getTrack 0 Mar 26 15:38:01 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 15:38:01 mp-dx volumio[1030]: info: CoreCommandRouter::volumioPushState Mar 26 15:38:01 mp-dx volumio[1030]: info: CoreStateMachine::setRandom null Mar 26 15:38:01 mp-dx volumio[1030]: info: CoreStateMachine::pushState Mar 26 15:38:01 mp-dx volumio[1030]: info: CorePlayQueue::getTrack 0 Mar 26 15:38:01 mp-dx volumio[1030]: info: CoreCommandRouter::volumioPushState Mar 26 15:38:01 mp-dx volumio[1030]: info: Setting Device type: Raspberry PI Mar 26 15:38:01 mp-dx volumio[1030]: info: Completed loading Core Plugins Mar 26 15:38:01 mp-dx volumio[1030]: info: Preparing to generate the ALSA configuration file Mar 26 15:38:01 mp-dx volumio[1176]: Forking 3 albumart workers Mar 26 15:38:02 mp-dx volumio[1030]: info: Asound.conf file unchanged, so no further update is needed Mar 26 15:38:02 mp-dx volumio[1030]: info: Output device has changed, restarting MPD Mar 26 15:38:02 mp-dx volumio[1030]: info: Output device has changed, restarting Shairport Sync Mar 26 15:38:02 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:02 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 15:38:02 mp-dx sudo[1232]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 26 15:38:02 mp-dx sudo[1232]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 15:38:02 mp-dx sudo[1232]: pam_unix(sudo:session): session closed for user root Mar 26 15:38:02 mp-dx sudo[1234]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 26 15:38:02 mp-dx volumio[1030]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 26 15:38:02 mp-dx sudo[1234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 15:38:02 mp-dx volumio[1030]: info: ___________ START PLUGINS ___________ Mar 26 15:38:02 mp-dx volumio[1030]: info: ControllerMpd::onStart: Initializing MPD Mar 26 15:38:02 mp-dx volumio[1030]: info: Creating MPD Configuration file Mar 26 15:38:02 mp-dx sudo[1242]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Mar 26 15:38:02 mp-dx sudo[1242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 15:38:02 mp-dx systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 26 15:38:02 mp-dx systemd[1]: Starting mpd.service - Music Player Daemon... Mar 26 15:38:03 mp-dx sudo[1247]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 26 15:38:03 mp-dx sudo[1247]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 15:38:03 mp-dx sudo[1247]: pam_unix(sudo:session): session closed for user root Mar 26 15:38:03 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 26 15:38:03 mp-dx volumio[1030]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 26 15:38:03 mp-dx volumio[1030]: info: [1774535883146] CoreMusicLibrary::Adding element Medienserver Mar 26 15:38:03 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 26 15:38:03 mp-dx sudo[1251]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 26 15:38:03 mp-dx sudo[1251]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 15:38:03 mp-dx systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 15:38:03 mp-dx sudo[1242]: pam_unix(sudo:session): session closed for user root Mar 26 15:38:03 mp-dx systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Mar 26 15:38:03 mp-dx systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 26 15:38:03 mp-dx systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 26 15:38:03 mp-dx sudo[1246]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 26 15:38:03 mp-dx sudo[1246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 26 15:38:03 mp-dx volumio[1030]: info: UPNP Browser: Client initialized successfully Mar 26 15:38:03 mp-dx sudo[1256]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Mar 26 15:38:03 mp-dx sudo[1246]: pam_unix(sudo:session): session closed for user root Mar 26 15:38:03 mp-dx upmpdcli[1255]: Could not open config: /tmp/upmpdcli.conf Mar 26 15:38:03 mp-dx systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Mar 26 15:38:03 mp-dx systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Mar 26 15:38:03 mp-dx systemd[1]: mpd.service: Deactivated successfully. Mar 26 15:38:03 mp-dx systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 26 15:38:03 mp-dx systemd[1]: mpd.socket: Deactivated successfully. Mar 26 15:38:03 mp-dx systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 26 15:38:03 mp-dx systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 26 15:38:03 mp-dx systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 26 15:38:03 mp-dx systemd[1]: Starting mpd.service - Music Player Daemon... Mar 26 15:38:04 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:04 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 15:38:04 mp-dx volumio5-onboarding[1252]: time=2026-03-26T15:38:04.423+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 15:38:04 mp-dx volumio[1030]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 26 15:38:04 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:04 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 15:38:04 mp-dx sudo[1273]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 26 15:38:04 mp-dx sudo[1273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 26 15:38:04 mp-dx sudo[1287]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Mar 26 15:38:04 mp-dx sudo[1273]: pam_unix(sudo:session): session closed for user root Mar 26 15:38:04 mp-dx systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Mar 26 15:38:04 mp-dx volumio[1030]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 26 15:38:04 mp-dx volumio[1030]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 26 15:38:04 mp-dx volumio[1030]: info: [1774535884869] CoreMusicLibrary::Adding element Last_100 Mar 26 15:38:04 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 26 15:38:04 mp-dx volumio[1030]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 26 15:38:04 mp-dx volumio[1030]: info: [1774535884950] CoreMusicLibrary::Adding element Webradio Mar 26 15:38:04 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 26 15:38:05 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 26 15:38:05 mp-dx volumio[1030]: info: Initializing BBC Radios Mar 26 15:38:05 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 26 15:38:05 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 15:38:06 mp-dx volumio[1030]: info: Volumio Calling Home Mar 26 15:38:10 mp-dx volumio-remote-updater[633]: [2026-03-26 15:38:10] [connect] Successful connection Mar 26 15:38:10 mp-dx systemd[1]: setdatetime-helper.service: Deactivated successfully. Mar 26 15:38:10 mp-dx systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Mar 26 15:38:10 mp-dx systemd[1]: setdatetime-helper.service: Consumed 2.998s CPU time. Mar 26 15:38:13 mp-dx volumio[1030]: info: Discovery: adding e24a5138-4bd3-40ef-955e-37e6cf25a304 Mar 26 15:38:13 mp-dx volumio[1030]: info: Discovery: Found device MP-DX Mar 26 15:38:13 mp-dx volumio[1030]: info: CoreCommandRouter::volumioGetState Mar 26 15:38:13 mp-dx volumio[1030]: info: CorePlayQueue::getTrack 0 Mar 26 15:38:13 mp-dx volumio[1030]: info: Discovery: this is already registered, e24a5138-4bd3-40ef-955e-37e6cf25a304 Mar 26 15:38:13 mp-dx volumio[1030]: info: Discovery: Found device MP-DX Mar 26 15:38:13 mp-dx volumio[1030]: info: CoreCommandRouter::volumioGetState Mar 26 15:38:13 mp-dx volumio[1030]: info: CorePlayQueue::getTrack 0 Mar 26 15:38:14 mp-dx sudo[1337]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 26 15:38:14 mp-dx sudo[1337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 15:38:14 mp-dx sudo[1335]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 26 15:38:14 mp-dx sudo[1335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 15:38:14 mp-dx volumio[1030]: info: MPD Permissions set Mar 26 15:38:14 mp-dx sudo[1335]: pam_unix(sudo:session): session closed for user root Mar 26 15:38:14 mp-dx sudo[1337]: pam_unix(sudo:session): session closed for user root Mar 26 15:38:14 mp-dx volumio5-onboarding[1252]: failed to create app: failed to initialize host: failed to create socket connection: could not connect to socket.io server: read tcp 127.0.0.1:49380->127.0.0.1:3000: i/o timeout Mar 26 15:38:14 mp-dx systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 15:38:14 mp-dx systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 15:38:14 mp-dx volumio[1030]: info: MPD Permissions set Mar 26 15:38:14 mp-dx systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Mar 26 15:38:14 mp-dx systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 15:38:14 mp-dx systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 15:38:14 mp-dx volumio5-onboarding[1357]: time=2026-03-26T15:38:14.810+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 15:38:15 mp-dx volumio[1030]: info: Volumio called home Mar 26 15:38:15 mp-dx volumio[1206]: Starting albumart workers Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx mpd[1290]: 2026-03-26T15:38:17 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 15:38:17 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:17 mp-dx volumio[1204]: Starting albumart workers Mar 26 15:38:17 mp-dx volumio[1205]: Starting albumart workers Mar 26 15:38:18 mp-dx systemd[1]: Started mpd.service - Music Player Daemon. Mar 26 15:38:18 mp-dx sudo[1251]: pam_unix(sudo:session): session closed for user root Mar 26 15:38:18 mp-dx sudo[1234]: pam_unix(sudo:session): session closed for user root Mar 26 15:38:18 mp-dx volumio[1030]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 26 15:38:18 mp-dx dbus-daemon[604]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.12' (uid=0 pid=1357 comm="/usr/bin/volumio5-onboarding") Mar 26 15:38:18 mp-dx systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Mar 26 15:38:18 mp-dx systemd[1]: Starting bluetooth.service - Bluetooth service... Mar 26 15:38:18 mp-dx systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Mar 26 15:38:18 mp-dx volumio[1030]: 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: 2 Mar 26 15:38:18 mp-dx systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Mar 26 15:38:19 mp-dx volumio[1030]: info: Completed starting Core Plugins Mar 26 15:38:19 mp-dx volumio[1030]: info: ------------------------------------------- Mar 26 15:38:19 mp-dx volumio[1030]: info: ----- MyVolumio plugins startup ---- Mar 26 15:38:19 mp-dx volumio[1030]: info: ------------------------------------------- Mar 26 15:38:19 mp-dx volumio[1030]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 26 15:38:19 mp-dx volumio[1030]: info: Starting Shairport Sync Mar 26 15:38:19 mp-dx volumio[1030]: info: Starting Shairport Sync Mar 26 15:38:19 mp-dx volumio[1030]: info: Starting Shairport Sync Mar 26 15:38:19 mp-dx sudo[1400]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 26 15:38:19 mp-dx sudo[1400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 15:38:19 mp-dx kernel: Bluetooth: Core ver 2.22 Mar 26 15:38:19 mp-dx kernel: NET: Registered PF_BLUETOOTH protocol family Mar 26 15:38:19 mp-dx kernel: Bluetooth: HCI device and connection manager initialized Mar 26 15:38:19 mp-dx kernel: Bluetooth: HCI socket layer initialized Mar 26 15:38:19 mp-dx kernel: Bluetooth: L2CAP socket layer initialized Mar 26 15:38:19 mp-dx kernel: Bluetooth: SCO socket layer initialized Mar 26 15:38:19 mp-dx bluetoothd[1382]: Bluetooth daemon 5.83 Mar 26 15:38:19 mp-dx dbus-daemon[604]: [system] Successfully activated service 'org.bluez' Mar 26 15:38:19 mp-dx systemd[1]: Started bluetooth.service - Bluetooth service. Mar 26 15:38:19 mp-dx bluetoothd[1382]: Starting SDP server Mar 26 15:38:19 mp-dx bluetoothd[1382]: Excluding (cli) sap Mar 26 15:38:19 mp-dx bluetoothd[1382]: Excluding (cli) scanparam Mar 26 15:38:19 mp-dx bluetoothd[1382]: Excluding (cli) midi Mar 26 15:38:19 mp-dx bluetoothd[1382]: Excluding (cli) battery Mar 26 15:38:19 mp-dx sudo[1408]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 26 15:38:19 mp-dx sudo[1408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 15:38:19 mp-dx kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Mar 26 15:38:19 mp-dx kernel: Bluetooth: BNEP filters: protocol multicast Mar 26 15:38:19 mp-dx kernel: Bluetooth: BNEP socket layer initialized Mar 26 15:38:19 mp-dx bluetoothd[1382]: Bluetooth management interface 1.23 initialized Mar 26 15:38:19 mp-dx dbus-daemon[604]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.13' (uid=0 pid=1382 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Mar 26 15:38:19 mp-dx volumio5-onboarding[1357]: time=2026-03-26T15:38:19.611+01:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci0 error="bluetooth: adapter /org/bluez/hci0 does not exist" Mar 26 15:38:19 mp-dx volumio5-onboarding[1357]: time=2026-03-26T15:38:19.616+01:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci1 error="bluetooth: adapter /org/bluez/hci1 does not exist" Mar 26 15:38:19 mp-dx volumio5-onboarding[1357]: time=2026-03-26T15:38:19.622+01:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci2 error="bluetooth: adapter /org/bluez/hci2 does not exist" Mar 26 15:38:19 mp-dx volumio5-onboarding[1357]: time=2026-03-26T15:38:19.628+01:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci3 error="bluetooth: adapter /org/bluez/hci3 does not exist" Mar 26 15:38:19 mp-dx volumio5-onboarding[1357]: time=2026-03-26T15:38:19.632+01:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci4 error="bluetooth: adapter /org/bluez/hci4 does not exist" Mar 26 15:38:19 mp-dx volumio5-onboarding[1357]: time=2026-03-26T15:38:19.632+01:00 level=WARN msg="no Bluetooth adapter found, BLE discovery disabled" Mar 26 15:38:19 mp-dx systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 26 15:38:19 mp-dx sudo[1398]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 26 15:38:19 mp-dx sudo[1398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 15:38:19 mp-dx systemd[1]: Starting systemd-hostnamed.service - Hostname Service... Mar 26 15:38:19 mp-dx systemd[1]: shairport-sync.service: Deactivated successfully. Mar 26 15:38:19 mp-dx systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 26 15:38:19 mp-dx systemd[1]: shairport-sync.service: Consumed 2.881s CPU time. Mar 26 15:38:19 mp-dx sudo[1403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 26 15:38:19 mp-dx sudo[1403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 26 15:38:20 mp-dx systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 26 15:38:20 mp-dx sudo[1400]: pam_unix(sudo:session): session closed for user root Mar 26 15:38:20 mp-dx systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 26 15:38:20 mp-dx systemd[1]: shairport-sync.service: Deactivated successfully. Mar 26 15:38:20 mp-dx systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 26 15:38:20 mp-dx sudo[1398]: pam_unix(sudo:session): session closed for user root Mar 26 15:38:20 mp-dx systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 26 15:38:20 mp-dx sudo[1408]: pam_unix(sudo:session): session closed for user root Mar 26 15:38:20 mp-dx systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 26 15:38:20 mp-dx systemd[1]: shairport-sync.service: Deactivated successfully. Mar 26 15:38:20 mp-dx systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 26 15:38:20 mp-dx systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 26 15:38:20 mp-dx sudo[1403]: pam_unix(sudo:session): session closed for user root Mar 26 15:38:20 mp-dx dbus-daemon[604]: [system] Successfully activated service 'org.freedesktop.hostname1' Mar 26 15:38:20 mp-dx systemd[1]: Started systemd-hostnamed.service - Hostname Service. Mar 26 15:38:21 mp-dx volumio[1030]: error: MPD error: The expression evaluated to a falsy value: Mar 26 15:38:21 mp-dx volumio[1030]: assert.ok(self.idling) Mar 26 15:38:21 mp-dx volumio[1030]: error: The expression evaluated to a falsy value: Mar 26 15:38:21 mp-dx volumio[1030]: assert.ok(self.idling) Mar 26 15:38:21 mp-dx volumio[1030]: error: updateQueue error: null Mar 26 15:38:21 mp-dx volumio[1030]: 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: 2 Mar 26 15:38:21 mp-dx volumio[1030]: info: Received Get System Info Mar 26 15:38:21 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 15:38:21 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 15:38:21 mp-dx volumio[1030]: info: Discovery: Getting this device information Mar 26 15:38:21 mp-dx volumio[1030]: info: CoreCommandRouter::volumioGetState Mar 26 15:38:21 mp-dx volumio[1030]: info: CorePlayQueue::getTrack 0 Mar 26 15:38:21 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 15:38:22 mp-dx volumio5-onboarding[1357]: time=2026-03-26T15:38:22.032+01:00 level=INFO msg="system info for faa5cadbc4e57d66e29193512a586a75" deviceName=MP-DX deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 15:38:22 mp-dx volumio5-onboarding[1357]: time=2026-03-26T15:38:22.062+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 15:38:22 mp-dx volumio[1030]: info: Shairport-Sync Started Mar 26 15:38:22 mp-dx volumio[1030]: Error adding Membership: Error: addMembership EINVAL Mar 26 15:38:22 mp-dx volumio[1030]: info: Shairport-Sync Started Mar 26 15:38:22 mp-dx volumio[1030]: info: Shairport-Sync Started Mar 26 15:38:22 mp-dx volumio[1030]: info: Upmpdcli Daemon Started Mar 26 15:38:22 mp-dx volumio[1030]: info: MPD running with PID1290 Mar 26 15:38:22 mp-dx volumio[1030]: ,establishing connection Mar 26 15:38:22 mp-dx volumio[1030]: info: Received Get System Info Mar 26 15:38:22 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 15:38:22 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 15:38:22 mp-dx volumio[1030]: info: Discovery: Getting this device information Mar 26 15:38:22 mp-dx volumio[1030]: info: CoreCommandRouter::volumioGetState Mar 26 15:38:22 mp-dx volumio[1030]: info: CorePlayQueue::getTrack 0 Mar 26 15:38:22 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 15:38:22 mp-dx volumio[1030]: error: updateQueue error: null Mar 26 15:38:22 mp-dx volumio[1030]: info: CoreCommandRouter::volumioGetState Mar 26 15:38:22 mp-dx volumio[1030]: info: CorePlayQueue::getTrack 0 Mar 26 15:38:25 mp-dx volumio-remote-updater[633]: [2026-03-26 15:38:25] [connect] Successful connection Mar 26 15:38:25 mp-dx volumio-remote-updater[633]: [2026-03-26 15:38:25] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774535905 101 Mar 26 15:38:25 mp-dx volumio[1030]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 3 Mar 26 15:38:26 mp-dx volumio[1030]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 26 15:38:39 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 26 15:38:39 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 15:38:39 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 26 15:38:39 mp-dx volumio[1030]: error: MyVolumio Plugin failed to start in a timely fashion Mar 26 15:38:39 mp-dx volumio[1030]: [Metrics] CommandRouter: 52s 549.11ms Mar 26 15:38:39 mp-dx volumio[1030]: info: CoreCommandRouter::volumiosetStartupVolume Mar 26 15:38:39 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 26 15:38:39 mp-dx volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 26 15:38:40 mp-dx volumio[1030]: info: CoreCommandRouter::Close All Modals sent Mar 26 15:38:40 mp-dx volumio[1030]: info: CoreCommandRouter::Close All Modals sent Mar 26 15:38:40 mp-dx volumio[1030]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 15:38:40 mp-dx volumio[1030]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals. Mar 26 15:38:40 mp-dx volumio[1030]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues Mar 26 15:38:40 mp-dx volumio[1030]: at new NodeError (node:internal/errors:405:5) Mar 26 15:38:40 mp-dx volumio[1030]: at assert (node:internal/assert:14:11) Mar 26 15:38:40 mp-dx volumio[1030]: at internalConnectMultiple (node:net:1118:3) Mar 26 15:38:40 mp-dx volumio[1030]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3) Mar 26 15:38:40 mp-dx volumio[1030]: at listOnTimeout (node:internal/timers:575:11) Mar 26 15:38:40 mp-dx volumio[1030]: at process.processTimers (node:internal/timers:514:7) { Mar 26 15:38:40 mp-dx volumio[1030]: code: 'ERR_INTERNAL_ASSERTION' Mar 26 15:38:40 mp-dx volumio[1030]: } Mar 26 15:38:40 mp-dx volumio[1030]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 15:38:49 mp-dx sudo[1516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-26 15:37' Mar 26 15:38:49 mp-dx sudo[1516]: 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"