-- Logs begin at Thu 2019-02-14 05:11:58 EST, end at Fri 2026-10-16 21:10:08 EDT. -- Oct 16 21:09:44 drs1 systemd-timedated[1273]: Changed local time to Fri Oct 16 21:09:44 2026 Oct 16 21:09:44 drs1 systemd[1]: Starting Samba Winbind Daemon... Oct 16 21:09:44 drs1 sudo[1270]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:44 drs1 volumio-time-update[608]: volumio-time-update-util: System time updated successfully. Oct 16 21:09:44 drs1 systemd[1]: Started Volumio Time Update Utility. Oct 16 21:09:44 drs1 systemd[1]: Starting Daily apt download activities... Oct 16 21:09:44 drs1 systemd[1]: Starting Daily man-db regeneration... Oct 16 21:09:44 drs1 nmbd[715]: [2026/10/16 21:09:44.175121, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Oct 16 21:09:44 drs1 nmbd[715]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.50.81 for name WORKGROUP<1d>. Oct 16 21:09:44 drs1 nmbd[715]: This response was from IP 192.168.50.114, reporting an IP address of 192.168.50.114. Oct 16 21:09:44 drs1 nmbd[715]: [2026/10/16 21:09:44.175503, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Oct 16 21:09:44 drs1 nmbd[715]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.50.81 for name WORKGROUP<1d>. Oct 16 21:09:44 drs1 nmbd[715]: This response was from IP 192.168.50.114, reporting an IP address of 192.168.50.114. Oct 16 21:09:44 drs1 nmbd[715]: [2026/10/16 21:09:44.175737, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Oct 16 21:09:44 drs1 nmbd[715]: query_name_response: Multiple (3) responses received for a query on subnet 192.168.50.81 for name WORKGROUP<1d>. Oct 16 21:09:44 drs1 nmbd[715]: This response was from IP 192.168.50.114, reporting an IP address of 192.168.50.114. Oct 16 21:09:44 drs1 nmbd[715]: [2026/10/16 21:09:44.175916, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Oct 16 21:09:44 drs1 nmbd[715]: query_name_response: Multiple (4) responses received for a query on subnet 192.168.50.81 for name WORKGROUP<1d>. Oct 16 21:09:44 drs1 nmbd[715]: This response was from IP 192.168.50.114, reporting an IP address of 192.168.50.114. Oct 16 21:09:44 drs1 systemd[1]: man-db.service: Succeeded. Oct 16 21:09:44 drs1 systemd[1]: Started Daily man-db regeneration. Oct 16 21:09:44 drs1 winbindd[1274]: [2026/10/16 21:09:44.627609, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Oct 16 21:09:44 drs1 winbindd[1274]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Oct 16 21:09:44 drs1 winbindd[1274]: [2026/10/16 21:09:44.660001, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 16 21:09:44 drs1 systemd[1]: Started Samba Winbind Daemon. Oct 16 21:09:44 drs1 winbindd[1274]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Oct 16 21:09:44 drs1 systemd[1]: Starting Samba SMB Daemon... Oct 16 21:09:44 drs1 volumio[810]: Starting albumart workers Oct 16 21:09:45 drs1 smbd[1313]: [2026/10/16 21:09:45.134217, 0] ../lib/util/become_daemon.c:138(daemon_ready) Oct 16 21:09:45 drs1 systemd[1]: Started Samba SMB Daemon. Oct 16 21:09:45 drs1 smbd[1313]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Oct 16 21:09:45 drs1 systemd[1]: Reached target Multi-User System. Oct 16 21:09:45 drs1 systemd[1]: Reached target Graphical Interface. Oct 16 21:09:45 drs1 volumio[810]: Starting albumart workers Oct 16 21:09:45 drs1 systemd[1]: Starting Update UTMP about System Runlevel Changes... Oct 16 21:09:45 drs1 volumio[810]: Starting albumart workers Oct 16 21:09:45 drs1 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Oct 16 21:09:45 drs1 systemd[1]: Started Update UTMP about System Runlevel Changes. Oct 16 21:09:45 drs1 systemd[1]: apt-daily.service: Succeeded. Oct 16 21:09:45 drs1 systemd[1]: Started Daily apt download activities. Oct 16 21:09:45 drs1 systemd[1]: Starting Daily apt upgrade and clean activities... Oct 16 21:09:45 drs1 volumio-remote-updater[597]: [2026-10-16 21:09:45] [connect] Successful connection Oct 16 21:09:45 drs1 volumio[810]: info: Applying required configuration parameters for plugin hi_res_audio Oct 16 21:09:45 drs1 volumio[810]: info: Loading plugin "inputs"... Oct 16 21:09:46 drs1 systemd[1]: apt-daily-upgrade.service: Succeeded. Oct 16 21:09:46 drs1 systemd[1]: Started Daily apt upgrade and clean activities. Oct 16 21:09:46 drs1 systemd[1]: Startup finished in 11.855s (kernel) + 21.234s (userspace) = 33.090s. Oct 16 21:09:46 drs1 volumio[810]: info: Loading plugin "qobuz"... Oct 16 21:09:47 drs1 volumio[810]: info: Loading plugin "smart_inputs"... Oct 16 21:09:47 drs1 volumio[810]: info: Loading plugin "tidal"... Oct 16 21:09:48 drs1 volumio[810]: info: Loading plugin "emotivadrs1control"... Oct 16 21:09:48 drs1 volumio[810]: info: Initializing System Ready GPIO for kernel version: 6.6.62-v8+ Oct 16 21:09:48 drs1 volumio[810]: info: Adding this device properties Oct 16 21:09:48 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , setThisDeviceVolumioProperties Oct 16 21:09:48 drs1 volumio[810]: info: Setting Additional Device Volumio Properties: [object Object] Oct 16 21:09:48 drs1 volumio[810]: info: Loading plugin "oem_helper"... Oct 16 21:09:49 drs1 volumio[810]: info: Applying required configuration parameters for plugin oem_helper Oct 16 21:09:49 drs1 volumio[810]: info: Loading plugin "updater_comm"... Oct 16 21:09:49 drs1 volumio[810]: info: Plugin mpdemulation is not enabled Oct 16 21:09:49 drs1 volumio[810]: info: Loading plugin "rest_api"... Oct 16 21:09:49 drs1 volumio[810]: info: Loading plugin "websocket"... Oct 16 21:09:49 drs1 volumio[810]: info: Starting Socket.io Server version 2.3.0 Oct 16 21:09:49 drs1 volumio[810]: info: Loading i18n strings for locale en Oct 16 21:09:49 drs1 volumio[810]: Updating browse sources language Oct 16 21:09:49 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::initPlayerControls Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 21:09:50 drs1 volumio[810]: Express server listening on port 3000 Oct 16 21:09:50 drs1 volumio[810]: [Metrics] WebUI: 18s 509.63ms Oct 16 21:09:50 drs1 volumio[810]: info: CoreStateMachine::resetVolumioState Oct 16 21:09:50 drs1 volumio[810]: info: CoreStateMachine::getcurrentVolume Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::volumioRetrievevolume Oct 16 21:09:50 drs1 volumio[810]: info: CoreStateMachine::pushState Oct 16 21:09:50 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::volumioPushState Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 21:09:50 drs1 sudo[1441]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 21:09:50 drs1 sudo[1441]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:50 drs1 sudo[1441]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:50 drs1 sudo[1443]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 21:09:50 drs1 sudo[1443]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:50 drs1 sudo[1443]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:50 drs1 volumio[810]: info: Volumio Network Manager: Network status updated: 0 Oct 16 21:09:50 drs1 volumio[810]: info: MRS: Removed streaming files Oct 16 21:09:50 drs1 volumio[810]: info: MRS: volumioStreaming STOPPED Oct 16 21:09:50 drs1 volumio[810]: info: MRS: SNAPSERVER STOPPED Oct 16 21:09:50 drs1 volumio[810]: info: MRS: SNAPCLIENT STOPPED Oct 16 21:09:50 drs1 volumio[810]: info: Cannot mount NAS Plex at system boot, trial number 1 ,retrying in 5 seconds Oct 16 21:09:50 drs1 volumio[810]: info: Cannot mount NAS Musicnas at system boot, trial number 1 ,retrying in 5 seconds Oct 16 21:09:50 drs1 volumio-remote-updater[597]: [2026-10-16 21:09:50] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1792199385 101 Oct 16 21:09:50 drs1 volumio[810]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 21:09:50 drs1 volumio[810]: info: Discovery: Getting this device information Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:09:50 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 21:09:50 drs1 volumio[810]: info: Discovery: Getting this device information Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:09:50 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 21:09:50 drs1 volumio[810]: info: CoreStateMachine::setRepeat true single undefined Oct 16 21:09:50 drs1 volumio[810]: info: CoreStateMachine::pushState Oct 16 21:09:50 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::volumioPushState Oct 16 21:09:50 drs1 volumio[810]: info: CoreStateMachine::setRandom null Oct 16 21:09:50 drs1 volumio[810]: info: CoreStateMachine::pushState Oct 16 21:09:50 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::volumioPushState Oct 16 21:09:50 drs1 volumio[810]: info: Setting Device type: Raspberry PI Oct 16 21:09:50 drs1 volumio[810]: verbose: New Socket.io Connection to 192.168.50.81:3000 from 192.168.50.172 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 21:09:50 drs1 sudo[1453]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 16 21:09:50 drs1 sudo[1453]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:50 drs1 volumio[810]: info: Reloading queue from file Oct 16 21:09:50 drs1 systemd[1]: Started UPnP Renderer front-end to MPD. Oct 16 21:09:50 drs1 volumio[810]: info: Completed loading Core Plugins Oct 16 21:09:50 drs1 volumio[810]: info: Preparing to generate the ALSA configuration file Oct 16 21:09:50 drs1 sudo[1453]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 16 21:09:50 drs1 volumio[810]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 16 21:09:50 drs1 volumio[810]: info: Reading ALSA contributions from plugins. Oct 16 21:09:50 drs1 volumio[810]: info: Discovery: adding be5e68c0-1220-4c97-8905-8f3f49951bc3 Oct 16 21:09:50 drs1 volumio[810]: info: Discovery: Found device DRS1 Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:09:50 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:50 drs1 volumio[810]: info: MRS: Pushing multiroomSync output for this device Oct 16 21:09:50 drs1 volumio[810]: info: MRS: Pushing multiroomSync output Oct 16 21:09:50 drs1 volumio[810]: info: Adding audio output: Oct 16 21:09:50 drs1 volumio[810]: info: Adding audio output: Oct 16 21:09:50 drs1 volumio[810]: info: Upmpdcli Daemon Started Oct 16 21:09:50 drs1 volumio[810]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Oct 16 21:09:50 drs1 volumio[810]: verbose: New Socket.io Connection to 192.168.50.81:3000 from 192.168.50.172 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 2 Oct 16 21:09:50 drs1 volumio[810]: info: Discovery: A device disappeared from network Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 21:09:50 drs1 volumio[810]: info: Discovery: Getting this device information Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:09:50 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 21:09:50 drs1 volumio[810]: info: Asound.conf file unchanged, so no further update is needed Oct 16 21:09:50 drs1 volumio[810]: info: Output device has changed, restarting MPD Oct 16 21:09:50 drs1 sudo[1458]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 21:09:50 drs1 volumio[810]: info: Output device has changed, restarting Shairport Sync Oct 16 21:09:50 drs1 sudo[1458]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 21:09:50 drs1 sudo[1458]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:50 drs1 sudo[1460]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 21:09:50 drs1 sudo[1460]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:50 drs1 volumio[810]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 21:09:50 drs1 volumio[810]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:50 drs1 volumio[810]: info: ___________ START PLUGINS ___________ Oct 16 21:09:50 drs1 systemd[1]: Listening on mpd.socket. Oct 16 21:09:50 drs1 systemd[1]: Starting Music Player Daemon... Oct 16 21:09:50 drs1 volumio[810]: info: ControllerMpd::onStart: Initializing MPD Oct 16 21:09:50 drs1 volumio[810]: info: Creating MPD Configuration file Oct 16 21:09:50 drs1 sudo[1471]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Oct 16 21:09:50 drs1 sudo[1471]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:50 drs1 sudo[1469]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 16 21:09:50 drs1 sudo[1469]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 16 21:09:50 drs1 sudo[1469]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 21:09:50 drs1 volumio[810]: info: [1792199390911] CoreMusicLibrary::Adding element Media Servers Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 21:09:50 drs1 sudo[1469]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:50 drs1 sudo[1474]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 21:09:50 drs1 sudo[1474]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:50 drs1 volumio[810]: info: UPNP Browser: Client initialized successfully Oct 16 21:09:50 drs1 systemd[1]: Started Volumio5 Onboarding Server. Oct 16 21:09:50 drs1 sudo[1476]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 21:09:50 drs1 sudo[1476]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:50 drs1 sudo[1474]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 16 21:09:50 drs1 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Oct 16 21:09:50 drs1 systemd[1]: mpd.service: Succeeded. Oct 16 21:09:50 drs1 systemd[1]: Stopped Music Player Daemon. Oct 16 21:09:50 drs1 sudo[1471]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:50 drs1 volumio[810]: info: Adding METAVOLUMIO REST API Endpoints Oct 16 21:09:50 drs1 volumio[810]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Oct 16 21:09:50 drs1 volumio[810]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Oct 16 21:09:50 drs1 volumio[810]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Oct 16 21:09:50 drs1 volumio[810]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Oct 16 21:09:50 drs1 systemd[1]: Starting Music Player Daemon... Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:50 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 21:09:50 drs1 sudo[1483]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name DRS1 Oct 16 21:09:50 drs1 sudo[1483]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:51 drs1 sudo[1483]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:51 drs1 volumio[810]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 21:09:51 drs1 sudo[1484]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 16 21:09:51 drs1 sudo[1484]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:51 drs1 sudo[1484]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Oct 16 21:09:51 drs1 sudo[1484]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:51 drs1 volumio[810]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 21:09:51 drs1 volumio[810]: info: Preparing CD Folders Oct 16 21:09:51 drs1 volumio[810]: info: Adding CD REST API Endpoints Oct 16 21:09:51 drs1 volumio[810]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Oct 16 21:09:51 drs1 volumio[810]: info: Starting UDEV Watcher for CD Oct 16 21:09:51 drs1 volumio[810]: info: Detecting CD presence with UDEV Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 21:09:51 drs1 volumio[810]: info: [1792199391145] CoreMusicLibrary::Adding element Last_100 Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 21:09:51 drs1 volumio[810]: info: Starting RAAT Plugin Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Oct 16 21:09:51 drs1 volumio[810]: info: Additional UI Settings Added for plugin music_service/raat Oct 16 21:09:51 drs1 volumio[810]: info: Registering DSP Elements listener and retrieving current ones Oct 16 21:09:51 drs1 volumio[810]: info: Additional DSP elements updated Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:51 drs1 volumio[810]: info: Updating RAAT Signal Path Oct 16 21:09:51 drs1 volumio[810]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Oct 16 21:09:51 drs1 volumio[810]: info: Streaming services startup Oct 16 21:09:51 drs1 volumio[810]: info: Starting Streaming Daemon Oct 16 21:09:51 drs1 sudo[1502]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 16 21:09:51 drs1 sudo[1502]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:51 drs1 sudo[1502]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 21:09:51 drs1 volumio[810]: info: [1792199391319] CoreMusicLibrary::Adding element Webradio Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 21:09:51 drs1 volumio[810]: info: Initializing BBC Radios Oct 16 21:09:51 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:09:51.334-04:00 level=INFO msg="running volumio5-device-gateway" version=687ad144+CHANGES buildDate=2026-02-10T16:50:24Z Oct 16 21:09:51 drs1 sudo[1509]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 16 21:09:51 drs1 sudo[1509]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:51 drs1 sudo[1509]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Oct 16 21:09:51 drs1 volumio[810]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:51 drs1 volumio[810]: error: Hi Res Audio Failed Login: Missing Login Data Oct 16 21:09:51 drs1 volumio[810]: info: Adding HIGHRESAUDIO REST API Endpoints Oct 16 21:09:51 drs1 volumio[810]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Oct 16 21:09:51 drs1 volumio[810]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Oct 16 21:09:51 drs1 volumio[810]: info: Initializing Serial Communication on port /dev/ttyAMA4 Oct 16 21:09:51 drs1 volumio[810]: info: Touch Event Listener Process Starting Oct 16 21:09:51 drs1 kernel: uart-pl011 fe201800.serial: no DMA platform data Oct 16 21:09:51 drs1 volumio[810]: info: Refreshing QOBUZ token Oct 16 21:09:51 drs1 volumio[810]: info: Adding inputs REST Endpoints Oct 16 21:09:51 drs1 volumio[810]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Oct 16 21:09:51 drs1 volumio[810]: info: Scanning Audio Inputs Oct 16 21:09:51 drs1 sudo[1529]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xinput --test-xi2 --root Oct 16 21:09:51 drs1 sudo[1529]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:51 drs1 volumio[810]: info: Checking against Known Cards name Oct 16 21:09:51 drs1 volumio[810]: info: Checking against Known Cards name Oct 16 21:09:51 drs1 volumio[810]: info: Adding Server instance for streaming Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 21:09:51 drs1 volumio[810]: info: Volumio Calling Home Oct 16 21:09:51 drs1 volumio[810]: (node:810) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Oct 16 21:09:51 drs1 volumio[810]: (Use `node --trace-deprecation ...` to show where the warning was created) Oct 16 21:09:51 drs1 volumio[810]: info: Adding TIDAL REST API Endpoints Oct 16 21:09:51 drs1 volumio[810]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Oct 16 21:09:51 drs1 volumio[810]: info: Serial port opened successfully Oct 16 21:09:51 drs1 volumio[810]: info: Sending serial start messages Oct 16 21:09:51 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:51 drs1 volumio[810]: info: Reporting MCU Network Status: 0 Oct 16 21:09:52 drs1 volumio[810]: error: Cannot start Volumio Streaming Daemon Oct 16 21:09:52 drs1 volumio[810]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 16 21:09:52 drs1 volumio[810]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 16 21:09:52 drs1 volumio[810]: info: RAAT Albumart path created successfully Oct 16 21:09:52 drs1 volumio[810]: info: Bluetooth name changed to DRS1 Oct 16 21:09:52 drs1 volumio[810]: info: MPD Permissions set Oct 16 21:09:52 drs1 volumio[810]: info: MPD Permissions set Oct 16 21:09:52 drs1 volumio[810]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Oct 16 21:09:52 drs1 volumio[810]: info: Discovery: adding be5e68c0-1220-4c97-8905-8f3f49951bc3 Oct 16 21:09:52 drs1 volumio[810]: info: Discovery: Found device DRS1 Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:09:52 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:52 drs1 volumio[810]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride Oct 16 21:09:52 drs1 volumio[810]: info: Setting Device Volume Override Oct 16 21:09:52 drs1 volumio[810]: info: Applying Volume Override Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 16 21:09:52 drs1 volumio[810]: info: Updating Volume Controller Parameters: Device: 0 Name: Analog + Digital Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 16 21:09:52 drs1 volumio[810]: info: Enabling external Volume Control Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: inputs , updateVolumeSettings Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: inputs , retrievevolume Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: CoreStateMachine::pushState Oct 16 21:09:52 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::volumioPushState Oct 16 21:09:52 drs1 volumio[810]: info: MRS: Pushing multiroomSync output update for this device Oct 16 21:09:52 drs1 volumio[810]: info: MRS: Pushing multiroomSync output Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Oct 16 21:09:52 drs1 volumio[810]: info: Setting Additional System Software info: Hardware Revision: 1.3 Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Oct 16 21:09:52 drs1 volumio[810]: info: Setting HW Firmware info: undefined Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Oct 16 21:09:52 drs1 volumio[810]: info: Setting HW Version info: 1.3 Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Oct 16 21:09:52 drs1 volumio[810]: info: Setting Additional System Software info: Hardware Revision: 1.3, Firmware Version: 0.2.1 Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Oct 16 21:09:52 drs1 volumio[810]: info: Setting HW Firmware info: 0.2.1 Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Oct 16 21:09:52 drs1 volumio[810]: info: Setting HW Version info: 1.3 Oct 16 21:09:52 drs1 volumio[810]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Oct 16 21:09:52 drs1 volumio[810]: info: MCU Signalled Headphone Mode Disabled Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Oct 16 21:09:52 drs1 volumio[810]: info: Reporting Headphone State: false Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 21:09:52 drs1 volumio[810]: info: Updating RAAT Signal Path Oct 16 21:09:52 drs1 volumio[810]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Oct 16 21:09:52 drs1 volumio[810]: info: MCU Signalled Sleep Mode Disabled Oct 16 21:09:52 drs1 volumio[810]: info: Enabling Advanced system settings configuration Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , addAdditionalUISections Oct 16 21:09:52 drs1 sudo[1568]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on Oct 16 21:09:52 drs1 volumio[810]: info: Additional UI Settings Added for plugin music_service/inputs Oct 16 21:09:52 drs1 sudo[1568]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:52 drs1 volumio[810]: info: MCU Signalled Auto Boot Mode On Power Disabled Oct 16 21:09:52 drs1 sudo[1568]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:52 drs1 volumio[810]: 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: 4 Oct 16 21:09:52 drs1 volumio[810]: info: Received Get System Info Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 21:09:52 drs1 volumio[810]: info: Discovery: Getting this device information Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:09:52 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 21:09:52 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:09:52.467-04:00 level=INFO msg="system info for 690420ec55dae3b8d16c07762039d185" deviceName=DRS1 deviceVariant=emotivadrs1 deviceModel="Emotiva DRS-1" softwareVersion=3.912 Oct 16 21:09:52 drs1 volumio[810]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 16 21:09:52 drs1 volumio[810]: error: Serial API: Failed to decode command: MAXVOL, message: 100 Oct 16 21:09:52 drs1 volumio[810]: info: Received Get System Info Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 21:09:52 drs1 volumio[810]: info: Discovery: Getting this device information Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:09:52 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 21:09:52 drs1 volumio[810]: info: Volumio called home Oct 16 21:09:52 drs1 sudo[1573]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0 Oct 16 21:09:52 drs1 sudo[1573]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:52 drs1 sudo[1573]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 16 21:09:52 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:09:52.777-04:00 level=INFO msg="enabling local network discovery" Oct 16 21:09:52 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:09:52.795-04:00 level=INFO msg="enabling BLE discovery" Oct 16 21:09:52 drs1 volumio[810]: info: Access Token successfully retrieved Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 16 21:09:52 drs1 volumio[810]: info: [1792199392837] CoreMusicLibrary::Adding element QOBUZ Oct 16 21:09:52 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 21:09:52 drs1 volumio[810]: Cannot find translation for source QOBUZ Oct 16 21:09:52 drs1 volumio[810]: info: Stopping AccessToken refresher cron for QOBUZ Oct 16 21:09:52 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:09:52.871-04:00 level=INFO msg="bootstrapping state" hasInternet=true Oct 16 21:09:52 drs1 volumio[810]: info: AccessToken refresher cron started for QOBUZ Oct 16 21:09:52 drs1 volumio[810]: info: Adding QOBUZ REST API Endpoints Oct 16 21:09:52 drs1 volumio[810]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Oct 16 21:09:52 drs1 volumio[810]: error: error Oct 16 21:09:52 drs1 volumio[810]: error: error Oct 16 21:09:52 drs1 volumio[810]: error: error Oct 16 21:09:52 drs1 volumio[810]: error: error Oct 16 21:09:52 drs1 volumio[810]: error: error Oct 16 21:09:52 drs1 volumio[810]: error: error Oct 16 21:09:52 drs1 volumio[810]: info: Starting Shairport Sync Oct 16 21:09:52 drs1 volumio[810]: info: Starting Shairport Sync Oct 16 21:09:52 drs1 sudo[1579]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 21:09:52 drs1 sudo[1579]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:52 drs1 mpd[1497]: Oct 16 21:09 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 16 21:09:52 drs1 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 16 21:09:52 drs1 systemd[1]: shairport-sync.service: Succeeded. Oct 16 21:09:52 drs1 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 16 21:09:53 drs1 volumio[810]: info: Starting Shairport Sync Oct 16 21:09:53 drs1 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 16 21:09:53 drs1 sudo[1583]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 21:09:53 drs1 sudo[1579]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:53 drs1 sudo[1583]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:53 drs1 volumio[810]: info: MRS: Found cast device: BRAVIA-4K-AE2-71152af1c21d10368a43650492dc691d Oct 16 21:09:53 drs1 volumio[810]: info: Adding audio output: Oct 16 21:09:53 drs1 volumio[810]: info: Received Get System Info Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 21:09:53 drs1 volumio[810]: info: Discovery: Getting this device information Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:09:53 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 21:09:53 drs1 shairport-sync[1582]: free(): double free detected in tcache 2 Oct 16 21:09:53 drs1 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 16 21:09:53 drs1 systemd[1]: shairport-sync.service: Main process exited, code=killed, status=6/ABRT Oct 16 21:09:53 drs1 systemd[1]: shairport-sync.service: Failed with result 'signal'. Oct 16 21:09:53 drs1 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 16 21:09:53 drs1 sudo[1586]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 21:09:53 drs1 sudo[1586]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:53 drs1 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 16 21:09:53 drs1 sudo[1583]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:53 drs1 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 16 21:09:53 drs1 systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 16 21:09:53 drs1 systemd[1]: shairport-sync.service: Succeeded. Oct 16 21:09:53 drs1 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 16 21:09:53 drs1 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 16 21:09:53 drs1 sudo[1586]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:09:53 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:53 drs1 volumio[810]: error: error Oct 16 21:09:53 drs1 volumio[810]: error: error Oct 16 21:09:53 drs1 volumio[810]: error: error Oct 16 21:09:53 drs1 volumio[810]: error: error Oct 16 21:09:53 drs1 volumio[810]: info: MRS: Found cast device: Pioneer-VSX-LX101-b74357850ff7cbe9e6d7dbb3339e5f66 Oct 16 21:09:53 drs1 volumio[810]: info: Adding audio output: Oct 16 21:09:53 drs1 volumio[810]: info: Adding Inputs via Serial API Oct 16 21:09:53 drs1 volumio[810]: info: Adding Advanced Audio Settings via Serial API Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Oct 16 21:09:53 drs1 volumio[810]: info: Additional UI Settings Added for plugin music_service/inputs Oct 16 21:09:53 drs1 volumio[810]: error: Serial API: Failed to decode command: MAXVOL, message: 100 Oct 16 21:09:53 drs1 volumio[810]: info: CoreStateMachine::pushState Oct 16 21:09:53 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::volumioPushState Oct 16 21:09:53 drs1 volumio[810]: info: MRS: Pushing multiroomSync output update for this device Oct 16 21:09:53 drs1 volumio[810]: info: MRS: Pushing multiroomSync output Oct 16 21:09:53 drs1 volumio[810]: info: CoreStateMachine::pushState Oct 16 21:09:53 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::volumioPushState Oct 16 21:09:53 drs1 volumio[810]: info: MRS: Pushing multiroomSync output update for this device Oct 16 21:09:53 drs1 volumio[810]: info: MRS: Pushing multiroomSync output Oct 16 21:09:53 drs1 volumio-remote-updater[597]: No test mode Oct 16 21:09:53 drs1 volumio-remote-updater[597]: No alpha test mode Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:09:53 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:53 drs1 volumio[810]: error: error Oct 16 21:09:53 drs1 volumio[810]: error: error Oct 16 21:09:53 drs1 volumio[810]: error: error Oct 16 21:09:53 drs1 volumio[810]: error: error Oct 16 21:09:53 drs1 volumio[810]: error: error Oct 16 21:09:53 drs1 volumio[810]: error: error Oct 16 21:09:53 drs1 volumio[810]: info: Shairport-Sync Started Oct 16 21:09:53 drs1 volumio[810]: Error adding Membership: Error: addMembership EINVAL Oct 16 21:09:53 drs1 volumio[810]: info: Shairport-Sync Started Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::servicePushState Oct 16 21:09:53 drs1 volumio[810]: info: CoreStateMachine::pushState Oct 16 21:09:53 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::volumioPushState Oct 16 21:09:53 drs1 volumio[810]: info: MRS: Pushing multiroomSync output update for this device Oct 16 21:09:53 drs1 volumio[810]: info: MRS: Pushing multiroomSync output Oct 16 21:09:53 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:53 drs1 volumio[810]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received inputs Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::volumiosetSourceActiveno-source Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 21:09:53 drs1 volumio[810]: Cannot find translation for source QOBUZ Oct 16 21:09:53 drs1 volumio[810]: info: MRS: Found cast device: BRAVIA-4K-VH22-1641f8d66ca3b06897c044a7662ee201 Oct 16 21:09:53 drs1 volumio[810]: info: Adding audio output: Oct 16 21:09:53 drs1 volumio[810]: info: MRS: Found cast device: SHIELD-Android-TV-915fc3fda5b1cbf1499fd6df14d11610 Oct 16 21:09:53 drs1 volumio[810]: info: Adding audio output: Oct 16 21:09:53 drs1 volumio[810]: error: error Oct 16 21:09:53 drs1 volumio[810]: error: error Oct 16 21:09:53 drs1 volumio[810]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

Update to Volumio 4

\n\n
⚠️ IMPORTANT: Do NOT cut power or turn off the device until it has completed the restart. Interrupting the update may permanently damage your device.
\n\n

WARNING: This update will reset your system's custom settings to the default ones (including playlists, favourites and web radios, except saved WiFi networks). This was unavoidable given how different the two versions are.

\n\n

If you have a MyVolumio account (even a free one) your playlists, favourites and web radios are saved in the cloud and will not be lost.

\n\n

What you'll get with the new version: faster and smoother operations, better handling of large music libraries, several improvements for bluetooth, CD Playback and much more.

\n","title":"Update v4.215","updateavailable":true} Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 21:09:53 drs1 volumio[810]: info: MCU Signalled Playback Inactive Oct 16 21:09:53 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 21:09:54 drs1 sudo[1599]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Oct 16 21:09:54 drs1 sudo[1599]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:54 drs1 systemd[1]: Started Volumio Bluetooth Module. Oct 16 21:09:54 drs1 sudo[1599]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:54 drs1 volumio[810]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 6 Oct 16 21:09:54 drs1 sudo[1602]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Oct 16 21:09:54 drs1 sudo[1602]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:54 drs1 volumio[810]: info: Volumio BT Module successfully started Oct 16 21:09:54 drs1 volumiobt[1601]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Oct 16 21:09:54 drs1 sudo[1602]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:54 drs1 volumio[810]: info: TidalConnect service stoped! Oct 16 21:09:54 drs1 volumio[810]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 16 21:09:54 drs1 volumio[810]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 16 21:09:54 drs1 sudo[1615]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 16 21:09:54 drs1 sudo[1615]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:54 drs1 volumio[810]: info: Reporting MCU Network Status: 1 Oct 16 21:09:54 drs1 volumio[810]: info: Volumio Network Manager: Network status updated: 1 Oct 16 21:09:54 drs1 systemd[1]: Started Volumio Tidal Connect Service. Oct 16 21:09:54 drs1 sudo[1615]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:54 drs1 volumio[810]: info: Initializing I2S Bus Oct 16 21:09:54 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:09:54.761-04:00 level=INFO msg="service successfully established" component=discovery/localnet Oct 16 21:09:54 drs1 volumio[810]: info: Executing endpoint tc_getconfig Oct 16 21:09:54 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Oct 16 21:09:54 drs1 vtcs[1625]: STARTING TidalConnect services, version: 1.6.1 Oct 16 21:09:54 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:09:54.943-04:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.50.172:59937 Oct 16 21:09:54 drs1 vtcs[1625]: STARTED TidalConnect services. Oct 16 21:09:54 drs1 volumio[810]: info: Executing endpoint tc_connect Oct 16 21:09:54 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Oct 16 21:09:54 drs1 volumio[810]: info: Connecting to TidalConnect Oct 16 21:09:54 drs1 volumio[810]: info: CoreCommandRouter::servicePushState Oct 16 21:09:54 drs1 volumio[810]: info: CoreStateMachine::pushState Oct 16 21:09:54 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:54 drs1 volumio[810]: info: CoreCommandRouter::volumioPushState Oct 16 21:09:54 drs1 volumio[810]: info: MRS: Pushing multiroomSync output update for this device Oct 16 21:09:54 drs1 volumio[810]: info: MRS: Pushing multiroomSync output Oct 16 21:09:54 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:54 drs1 volumio[810]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received tidalconnect Oct 16 21:09:54 drs1 volumio[810]: info: CoreCommandRouter::servicePushState Oct 16 21:09:54 drs1 volumio[810]: info: CoreStateMachine::pushState Oct 16 21:09:54 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:54 drs1 volumio[810]: info: CoreCommandRouter::volumioPushState Oct 16 21:09:54 drs1 volumio[810]: info: MRS: Pushing multiroomSync output update for this device Oct 16 21:09:54 drs1 volumio[810]: info: MRS: Pushing multiroomSync output Oct 16 21:09:54 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:55 drs1 volumio[810]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received tidalconnect Oct 16 21:09:55 drs1 volumio[810]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Oct 16 21:09:55 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:09:55 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:55 drs1 sudo[1653]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Oct 16 21:09:55 drs1 sudo[1653]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:55 drs1 volumiobt[1601]: pulseaudio: no process found Oct 16 21:09:55 drs1 sudo[1653]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:55 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:09:55.167-04:00 level=INFO msg="new address was allocated" component=ble/conn old=1 new=2 Oct 16 21:09:55 drs1 dbus-daemon[622]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.30' (uid=1000 pid=1657 comm="/usr/bin/pulseaudio --high-priority=true ") Oct 16 21:09:55 drs1 systemd[1]: Starting RealtimeKit Scheduling Policy Service... Oct 16 21:09:55 drs1 sudo[1659]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=MusicUser,password=2Nw!QYm5,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.50.202/Music /mnt/NAS/Plex Oct 16 21:09:55 drs1 sudo[1659]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:55 drs1 volumio[810]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 16 21:09:55 drs1 dbus-daemon[622]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Oct 16 21:09:55 drs1 systemd[1]: Started RealtimeKit Scheduling Policy Service. Oct 16 21:09:55 drs1 rtkit-daemon[1660]: Successfully called chroot. Oct 16 21:09:55 drs1 rtkit-daemon[1660]: Successfully dropped privileges. Oct 16 21:09:55 drs1 rtkit-daemon[1660]: Successfully limited resources. Oct 16 21:09:55 drs1 rtkit-daemon[1660]: Running. Oct 16 21:09:55 drs1 rtkit-daemon[1660]: Canary thread running. Oct 16 21:09:55 drs1 rtkit-daemon[1660]: Watchdog thread running. Oct 16 21:09:55 drs1 dbus-daemon[622]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.31' (uid=0 pid=1660 comm="/usr/lib/rtkit/rtkit-daemon ") Oct 16 21:09:55 drs1 kernel: CIFS: Attempting to mount //192.168.50.202/Music Oct 16 21:09:55 drs1 sudo[1662]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=MusicUser,password=2Nw!QYm5,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.50.202/Music /mnt/NAS/Musicnas Oct 16 21:09:55 drs1 systemd[1]: Starting Authorization Manager... Oct 16 21:09:55 drs1 sudo[1662]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:09:55 drs1 volumio[810]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 16 21:09:55 drs1 polkitd[1670]: started daemon version 0.105 using authority implementation `local' version `0.105' Oct 16 21:09:55 drs1 dbus-daemon[622]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Oct 16 21:09:55 drs1 systemd[1]: Started Authorization Manager. Oct 16 21:09:55 drs1 dbus-daemon[622]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.21" (uid=0 pid=1478 comm="/usr/bin/volumio5-onboarding ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.5" (uid=0 pid=764 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap,hostn") Oct 16 21:09:55 drs1 pulseaudio[1657]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Oct 16 21:09:55 drs1 pulseaudio[1657]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Oct 16 21:09:55 drs1 bluetoothd[764]: Endpoint registered: sender=:1.51 path=/MediaEndpoint/A2DPSource Oct 16 21:09:55 drs1 bluetoothd[764]: Endpoint registered: sender=:1.51 path=/MediaEndpoint/A2DPSink Oct 16 21:09:55 drs1 pulseaudio[1657]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Oct 16 21:09:55 drs1 volumiobt[1601]: Applying permissions Oct 16 21:09:55 drs1 volumiobt[1601]: Setting BT discoverable and pairable Oct 16 21:09:55 drs1 kernel: Bluetooth: RFCOMM TTY layer initialized Oct 16 21:09:55 drs1 kernel: Bluetooth: RFCOMM socket layer initialized Oct 16 21:09:55 drs1 kernel: Bluetooth: RFCOMM ver 1.11 Oct 16 21:09:55 drs1 volumiobt[1601]: [118B blob data] Oct 16 21:09:55 drs1 volumiobt[1601]: [82B blob data] Oct 16 21:09:55 drs1 volumiobt[1601]: [82B blob data] Oct 16 21:09:55 drs1 volumiobt[1601]: [38B blob data] Oct 16 21:09:55 drs1 volumiobt[1601]: [6C-C4-8F-64-F8-DB]> -e power on Oct 16 21:09:55 drs1 volumiobt[1601]: Invalid command in menu main: -e Oct 16 21:09:55 drs1 volumiobt[1601]: Oct 16 21:09:55 drs1 volumiobt[1601]: Use "help" for a list of available commands in a menu. Oct 16 21:09:55 drs1 volumiobt[1601]: Use "menu " if you want to enter any submenu. Oct 16 21:09:55 drs1 volumiobt[1601]: Use "back" if you want to return to menu main. Oct 16 21:09:55 drs1 volumiobt[1601]: [6C-C4-8F-64-F8-DB]> agent on Oct 16 21:09:55 drs1 volumiobt[1601]: Agent is already registered Oct 16 21:09:55 drs1 volumiobt[1601]: [6C-C4-8F-64-F8-DB]> discoverable on Oct 16 21:09:55 drs1 volumiobt[1601]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended Oct 16 21:09:55 drs1 volumiobt[1601]: [6C-C4-8F-64-F8-DB]> pairable on Oct 16 21:09:55 drs1 volumiobt[1601]: [6C-C4-8F-64-F8-DB]> agent NoInputNoOutput Oct 16 21:09:55 drs1 volumiobt[1601]: Agent is already registered Oct 16 21:09:55 drs1 volumiobt[1601]: [6C-C4-8F-64-F8-DB]> default-agent Oct 16 21:09:55 drs1 volumiobt[1601]: [6C-C4-8F-64-F8-DB]> quit Oct 16 21:09:55 drs1 volumiobt[1601]: [75B blob data] Oct 16 21:09:55 drs1 kernel: CIFS: Attempting to mount //192.168.50.202/Music Oct 16 21:09:55 drs1 sudo[1659]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:55 drs1 sudo[1662]: pam_unix(sudo:session): session closed for user root Oct 16 21:09:55 drs1 volumio[810]: info: Successfully initialized I2S Bus Oct 16 21:09:56 drs1 volumio[810]: info: MRS: Getting audio outputs on start Oct 16 21:09:56 drs1 volumio[810]: info: MRS: Requesting all other devices output Oct 16 21:09:57 drs1 systemd[1]: systemd-fsckd.service: Succeeded. Oct 16 21:09:57 drs1 volumio[810]: info: TidalConnect service started! Oct 16 21:09:57 drs1 volumio[810]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 8 Oct 16 21:09:58 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 16 21:09:58 drs1 volumio[810]: info: CoreCommandRouter::volumioGetVisibleSources Oct 16 21:09:58 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 21:09:58 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:09:58 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:58 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 16 21:09:58 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 16 21:09:58 drs1 volumio[810]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 16 21:09:58 drs1 volumio[810]: info: Received Get System Info Oct 16 21:09:58 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 21:09:58 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 21:09:58 drs1 volumio[810]: info: Discovery: Getting this device information Oct 16 21:09:58 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:09:58 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:58 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 21:09:58 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:09:58 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:58 drs1 volumio[810]: info: Listing playlists Oct 16 21:09:58 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 16 21:09:58 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 16 21:09:59 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:09:59 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:59 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 21:09:59 drs1 volumio[810]: info: Received Get System Info Oct 16 21:09:59 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 21:09:59 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 21:09:59 drs1 volumio[810]: info: Discovery: Getting this device information Oct 16 21:09:59 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:09:59 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:09:59 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 21:10:00 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 16 21:10:01 drs1 volumio[810]: info: Executing endpoint metavolumio Oct 16 21:10:01 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 16 21:10:01 drs1 volumio[810]: info: Executing endpoint metavolumio Oct 16 21:10:01 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 16 21:10:01 drs1 volumio[810]: info: Executing endpoint metavolumio Oct 16 21:10:01 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 16 21:10:01 drs1 volumio[810]: info: Checking for updated MCU Firmware Oct 16 21:10:01 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 21:10:01 drs1 volumio[810]: info: Firware on device is on latest version, no need to update Oct 16 21:10:02 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:02.553-04:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.50.172:59937 @ 0x1cb9020" latency=-786.832654ms timeout=20s Oct 16 21:10:02 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:02.553-04:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.50.172:59937 @ 0x1cb9020" Oct 16 21:10:02 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:02.553-04:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.50.172:59937 @ 0x1cb9020" latency=-785.881912ms platform=PLATFORM_IOS version=6.260930.0 Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 16 21:10:02 drs1 volumio[810]: info: Received Get System Info Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 21:10:02 drs1 volumio[810]: info: Discovery: Getting this device information Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:10:02 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 21:10:02 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:02.559-04:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.50.172:59937 @ 0x1cb9020" name=DRS1 Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 21:10:02 drs1 volumio[810]: info: Discovery: Getting this device information Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:10:02 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 21:10:02 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:02.564-04:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.50.172:59937 @ 0x1cb9020" language=en Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Oct 16 21:10:02 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:02.568-04:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.50.172:59937 @ 0x1cb9020" timezone=America/New_York Oct 16 21:10:02 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:02.569-04:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.50.172:59937 @ 0x1cb9020" available=true connected=true macAddress=88:a2:9e:3a:e6:d4 ip4Address=192.168.50.81/24 ip6Address= Oct 16 21:10:02 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:02.572-04:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.50.172:59937 @ 0x1cb9020" available=true connected=false macAddress= ip4Address= ip6Address= ssid= Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 16 21:10:02 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:02.573-04:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.50.172:59937 @ 0x1cb9020" setupComplete=true Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Oct 16 21:10:02 drs1 volumio[810]: No protocol specified Oct 16 21:10:02 drs1 volumio[810]: xcb_connection_has_error() returned true Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 16 21:10:02 drs1 volumio[810]: amixer -c 0 info | grep "IQAudIODigi" Oct 16 21:10:02 drs1 volumio[810]: No protocol specified Oct 16 21:10:02 drs1 volumio[810]: xcb_connection_has_error() returned true Oct 16 21:10:02 drs1 volumio[810]: Card hw:0 'IQAudIODigi'/'IQAudIODigi' Oct 16 21:10:02 drs1 volumio[810]: amixer -c 0 info | grep "IQAudIODigi" Oct 16 21:10:02 drs1 volumio[810]: No protocol specified Oct 16 21:10:02 drs1 volumio[810]: xcb_connection_has_error() returned true Oct 16 21:10:02 drs1 volumio[810]: Card hw:0 'IQAudIODigi'/'IQAudIODigi' Oct 16 21:10:02 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:02.779-04:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.50.172:59937 @ 0x1cb9020" selectedOutputId=0 Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Oct 16 21:10:02 drs1 sudo[1723]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Oct 16 21:10:02 drs1 sudo[1723]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:10:02 drs1 sudo[1728]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 16 21:10:02 drs1 sudo[1728]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:10:02 drs1 sudo[1728]: pam_unix(sudo:session): session closed for user root Oct 16 21:10:02 drs1 sudo[1735]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 16 21:10:02 drs1 sudo[1735]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:10:02 drs1 sudo[1740]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 16 21:10:02 drs1 sudo[1740]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:10:02 drs1 sudo[1735]: pam_unix(sudo:session): session closed for user root Oct 16 21:10:02 drs1 sudo[1740]: pam_unix(sudo:session): session closed for user root Oct 16 21:10:02 drs1 volumio[810]: info: Received Get System Info Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 21:10:02 drs1 sudo[1747]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 21:10:02 drs1 sudo[1747]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 21:10:02 drs1 volumio[810]: info: Discovery: Getting this device information Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:10:02 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 21:10:02 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:02.975-04:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.50.172:59937 @ 0x1cb9020" currentVersion=3.912 latestVersion=4.215 Oct 16 21:10:02 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:02.976-04:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.50.172:59937 @ 0x1cb9020" status=UPDATE_STATUS_NONE progress=0 Oct 16 21:10:02 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:02.977-04:00 level=INFO msg="emitting user changed event" component=server peer="192.168.50.172:59937 @ 0x1cb9020" userId= Oct 16 21:10:02 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:02.977-04:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.50.172:59937 @ 0x1cb9020" providers=3 Oct 16 21:10:02 drs1 sudo[1747]: pam_unix(sudo:session): session closed for user root Oct 16 21:10:02 drs1 sudo[1750]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 21:10:02 drs1 sudo[1750]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:10:02 drs1 sudo[1723]: pam_unix(sudo:session): session closed for user root Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 21:10:02 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:02.994-04:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.50.172:59937 @ 0x1cb9020" plugins=0 Oct 16 21:10:02 drs1 sudo[1750]: pam_unix(sudo:session): session closed for user root Oct 16 21:10:02 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:10:02 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:10:03 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:03.002-04:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.50.172:59937 @ 0x1cb9020" state=STATUS_STOPPED positionMs=0 volume=59 Oct 16 21:10:03 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:03.003-04:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.50.172:59937 @ 0x1cb9020" id=qobuz://song/15644299 title="Dancing Queen" Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 21:10:03 drs1 volumio[810]: info: Discovery: Getting this device information Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:10:03 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:10:03 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:10:03 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:03.041-04:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.50.172:59937,00:00:00:00:00:00%01 @ 0x1cb9020" latency=-784.13013ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 16 21:10:03 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:03.055-04:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.50.172:59937,00:00:00:00:00:00%01 @ 0x1cb9020" latency=-790.330228ms timeout=10s Oct 16 21:10:03 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:03.393-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.50.172:59937,00:00:00:00:00:00%01 @ 0x1cb9020" latency=-790.330228ms timeout=10s endpoint=http://pushupdates.volumio.org duration=333.79358ms Oct 16 21:10:03 drs1 sudo[1764]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 21:10:03 drs1 sudo[1764]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:10:03 drs1 sudo[1764]: pam_unix(sudo:session): session closed for user root Oct 16 21:10:03 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:03.427-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.50.172:59937,00:00:00:00:00:00%01 @ 0x1cb9020" latency=-790.330228ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=371.025246ms Oct 16 21:10:03 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:03.447-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.50.172:59937,00:00:00:00:00:00%01 @ 0x1cb9020" latency=-790.330228ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=390.067466ms Oct 16 21:10:03 drs1 sudo[1767]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 21:10:03 drs1 sudo[1767]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:10:03 drs1 sudo[1767]: pam_unix(sudo:session): session closed for user root Oct 16 21:10:03 drs1 volumio[810]: verbose: New Socket.io Connection to 192.168.50.81 from 192.168.50.172 UA: Mozilla/5.0 (iPad; CPU OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 8 Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 16 21:10:03 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:03.553-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.50.172:59937,00:00:00:00:00:00%01 @ 0x1cb9020" latency=-790.330228ms timeout=10s endpoint=http://plugins.volumio.org duration=496.431043ms Oct 16 21:10:03 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:03.651-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.50.172:59937,00:00:00:00:00:00%01 @ 0x1cb9020" latency=-790.330228ms timeout=10s endpoint=https://securetoken.googleapis.com duration=594.578366ms Oct 16 21:10:03 drs1 sudo[1770]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 21:10:03 drs1 sudo[1770]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:10:03 drs1 sudo[1772]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 21:10:03 drs1 sudo[1772]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 21:10:03 drs1 sudo[1770]: pam_unix(sudo:session): session closed for user root Oct 16 21:10:03 drs1 sudo[1772]: pam_unix(sudo:session): session closed for user root Oct 16 21:10:03 drs1 volumio[810]: verbose: New Socket.io Connection to 192.168.50.81 from 192.168.50.172 UA: Mozilla/5.0 (iPad; CPU OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 8 Oct 16 21:10:03 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:03.709-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.50.172:59937,00:00:00:00:00:00%01 @ 0x1cb9020" latency=-790.330228ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=648.780526ms Oct 16 21:10:03 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:03.726-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.50.172:59937,00:00:00:00:00:00%01 @ 0x1cb9020" latency=-790.330228ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=666.232362ms Oct 16 21:10:03 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:03.727-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.50.172:59937,00:00:00:00:00:00%01 @ 0x1cb9020" latency=-790.330228ms timeout=10s endpoint=https://www.googleapis.com duration=671.158828ms Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::volumioGetVisibleSources Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:10:03 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::volumioGetQueue Oct 16 21:10:03 drs1 volumio[810]: info: CoreStateMachine::getQueue Oct 16 21:10:03 drs1 volumio[810]: info: CorePlayQueue::getQueue Oct 16 21:10:03 drs1 volumio[810]: info: Listing playlists Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 16 21:10:03 drs1 volumio[810]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 16 21:10:03 drs1 volumio[810]: info: Received Get System Info Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 21:10:03 drs1 volumio[810]: info: Discovery: Getting this device information Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:10:03 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:10:03 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 16 21:10:03 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 16 21:10:03 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:03.774-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.50.172:59937,00:00:00:00:00:00%01 @ 0x1cb9020" latency=-790.330228ms timeout=10s endpoint=https://functions.volumio.cloud duration=715.83838ms Oct 16 21:10:03 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:03.774-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.50.172:59937,00:00:00:00:00:00%01 @ 0x1cb9020" latency=-790.330228ms timeout=10s endpoint=https://functions.volumio.cloud duration=714.71752ms Oct 16 21:10:03 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:03.887-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.50.172:59937,00:00:00:00:00:00%01 @ 0x1cb9020" latency=-790.330228ms timeout=10s endpoint=https://google.com duration=831.419797ms Oct 16 21:10:03 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:03.948-04:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.50.172:59937,00:00:00:00:00:00%01 @ 0x1cb9020" latency=-790.330228ms timeout=10s endpoint=http://cddb.volumio.org duration=891.975981ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 16 21:10:04 drs1 volumio5-onboarding[1478]: time=2026-10-16T21:10:04.010-04:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.50.172:59937,00:00:00:00:00:00%01 @ 0x1cb9020" latency=-790.330228ms timeout=10s endpoint=https://database.volumio.cloud duration=953.109595ms Oct 16 21:10:05 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 16 21:10:05 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 21:10:05 drs1 volumio[810]: info: Received Get System Info Oct 16 21:10:05 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 21:10:05 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 21:10:05 drs1 volumio[810]: info: Discovery: Getting this device information Oct 16 21:10:05 drs1 volumio[810]: info: CoreCommandRouter::volumioGetState Oct 16 21:10:05 drs1 volumio[810]: info: CorePlayQueue::getTrack 0 Oct 16 21:10:05 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 21:10:07 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 16 21:10:08 drs1 volumio[810]: Searching all installed plugins Oct 16 21:10:08 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 21:10:08 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: , search Oct 16 21:10:08 drs1 volumio[810]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 16 21:10:08 drs1 volumio[810]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 21:10:08 drs1 volumio[810]: TypeError: Cannot read property 'then' of undefined Oct 16 21:10:08 drs1 volumio[810]: at ControllerMpd.search (/volumio/app/plugins/music_service/mpd/index.js:1596:17) Oct 16 21:10:08 drs1 volumio[810]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32) Oct 16 21:10:08 drs1 volumio[810]: at CoreMusicLibrary.searchOnPlugin (/volumio/app/musiclibrary.js:668:44) Oct 16 21:10:08 drs1 volumio[810]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:455:27) Oct 16 21:10:08 drs1 volumio[810]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:485:44) Oct 16 21:10:08 drs1 volumio[810]: at Socket.emit (events.js:315:20) Oct 16 21:10:08 drs1 volumio[810]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Oct 16 21:10:08 drs1 volumio[810]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Oct 16 21:10:08 drs1 volumio[810]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 21:10:08 drs1 sudo[1798]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-10-16 21:09 Oct 16 21:10:08 drs1 sudo[1798]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="3dada8b1e619a5feb94867e0865ace17474d7bce" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="30045b259d1a704a832ca7c1460c1fdfa4b723f9" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="emotivadrs1" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 05 Mar 2026 12:03:30 PM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="cm4" VOLUMIO_DEVICENAME="CM4" VOLUMIO_VENDOR_MODEL="Emotiva DRS-1" VOLUMIO_VENDOR="Emotiva" VOLUMIO_MODEL="DRS-1" VOLUMIO_HASH="5655ad3ef69f605969779bb6dab18482"