Apr 13 10:50:19 volumio4 ntpd[1117]: CLOCK: time stepped by 242660.886955 Apr 13 10:50:19 volumio4 ntpd[1117]: CLOCK: time changed from 2026-04-10 to 2026-04-13 Apr 13 10:50:19 volumio4 ntpd[1117]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Apr 13 10:50:19 volumio4 systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Apr 13 10:50:19 volumio4 systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Apr 13 10:50:19 volumio4 systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Apr 13 10:50:19 volumio4 systemd[1]: dpkg-db-backup.service: Deactivated successfully. Apr 13 10:50:19 volumio4 systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Apr 13 10:50:19 volumio4 volumio[1801]: info: Discovery: A device disappeared from network Apr 13 10:50:19 volumio4 volumio[1801]: info: Discovery: A device disappeared from network Apr 13 10:50:19 volumio4 volumio[1801]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 13 10:50:20 volumio4 volumio[1801]: info: Discovery: adding b92f35fe-f9bc-4c59-b16d-ecc119400c6f Apr 13 10:50:20 volumio4 volumio[1801]: info: Discovery: Found device Volumio4 Apr 13 10:50:20 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:20 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 0 Apr 13 10:50:20 volumio4 volumio[1801]: info: Discovery: this is already registered, b92f35fe-f9bc-4c59-b16d-ecc119400c6f Apr 13 10:50:20 volumio4 volumio[1801]: info: Discovery: Found device Volumio4 Apr 13 10:50:20 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:20 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 0 Apr 13 10:50:21 volumio4 systemd[1]: systemd-fsckd.service: Deactivated successfully. Apr 13 10:50:22 volumio4 sh[859]: timed out Apr 13 10:50:22 volumio4 dhcpcd[871]: timed out Apr 13 10:50:22 volumio4 sh[792]: ifup: failed to bring up eth0 Apr 13 10:50:22 volumio4 systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Apr 13 10:50:22 volumio4 systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Apr 13 10:50:22 volumio4 systemd[1]: systemd-hostnamed.service: Deactivated successfully. Apr 13 10:50:23 volumio4 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Apr 13 10:50:23 volumio4 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 13 10:50:23 volumio4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 13 10:50:23 volumio4 upmpdcli[2043]: Could not open config: /tmp/upmpdcli.conf Apr 13 10:50:23 volumio4 systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Apr 13 10:50:23 volumio4 systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Apr 13 10:50:23 volumio4 sudo[2059]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 13 10:50:23 volumio4 sudo[2059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:50:23 volumio4 sudo[2061]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 13 10:50:23 volumio4 sudo[2061]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:50:23 volumio4 sudo[2059]: pam_unix(sudo:session): session closed for user root Apr 13 10:50:23 volumio4 sudo[2061]: pam_unix(sudo:session): session closed for user root Apr 13 10:50:23 volumio4 sudo[2065]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 13 10:50:23 volumio4 sudo[2065]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 13 10:50:23 volumio4 volumio[1801]: info: Adding plugin bluetooth to MyMusic Plugins Apr 13 10:50:23 volumio4 volumio[1801]: info: Adding plugin multiroom to MyMusic Plugins Apr 13 10:50:23 volumio4 volumio[1801]: info: Adding plugin metavolumio to MyMusic Plugins Apr 13 10:50:23 volumio4 volumio[1801]: info: Adding plugin cd_controller to MyMusic Plugins Apr 13 10:50:23 volumio4 volumio[1801]: info: Adding plugin qobuzconnect to MyMusic Plugins Apr 13 10:50:23 volumio4 volumio[1801]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 13 10:50:23 volumio4 volumio[1801]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 13 10:50:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:23 volumio4 volumio[1801]: info: Starting MyVolumio Remote Streaming Endpoints Apr 13 10:50:23 volumio4 volumio[1801]: info: MyVolumio login type: Token Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 13 10:50:23 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 13 10:50:24 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 13 10:50:24 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 13 10:50:24 volumio4 volumio[1801]: info: Streaming services startup Apr 13 10:50:24 volumio4 volumio[1801]: info: Starting Streaming Daemon Apr 13 10:50:24 volumio4 sudo[2068]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 13 10:50:24 volumio4 sudo[2068]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:50:24 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 13 10:50:24 volumio4 sudo[2068]: pam_unix(sudo:session): session closed for user root Apr 13 10:50:24 volumio4 volumio[1801]: error: Cannot start Volumio Streaming Daemon Apr 13 10:50:24 volumio4 volumio[1801]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 13 10:50:24 volumio4 volumio[1801]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 13 10:50:24 volumio4 volumio[1801]: error: MyVolumio Custom Token format not valid, refreshing it Apr 13 10:50:25 volumio4 volumio[1801]: info: MyVolumio login type: Token Apr 13 10:50:26 volumio4 volumio[1801]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 13 10:50:26 volumio4 volumio[1801]: info: MyVolumio token set successfully Apr 13 10:50:26 volumio4 volumio[1801]: info: MYVOLUMIO: Adding device Apr 13 10:50:26 volumio4 volumio[1801]: info: MYVOLUMIO: Evaluating Server Apr 13 10:50:27 volumio4 volumio[1801]: info: MyVolumio Plan changed: premium Apr 13 10:50:27 volumio4 volumio[1801]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Apr 13 10:50:27 volumio4 volumio[1801]: info: Removing browser output: myVolumio user plan is not superstar Apr 13 10:50:27 volumio4 volumio[1801]: info: Removing audio output: Apr 13 10:50:27 volumio4 volumio[1801]: info: MYVOLUMIO: Adding device Apr 13 10:50:27 volumio4 volumio[1801]: info: MYVOLUMIO: Evaluating Server Apr 13 10:50:27 volumio4 volumio[1801]: info: Remote config written successfully Apr 13 10:50:27 volumio4 volumio[1801]: info: Starting Tunnel 1 Apr 13 10:50:27 volumio4 volumio[1801]: info: Starting Tunnel Connection Checker Apr 13 10:50:27 volumio4 volumio[1801]: info: Completed starting MyVolumio Plugin Apr 13 10:50:27 volumio4 volumio[1801]: info: MYVolumio Device disabled Apr 13 10:50:27 volumio4 volumio[1801]: info: MyVolumio status changed Apr 13 10:50:27 volumio4 volumio[1801]: info: Streaming services startup Apr 13 10:50:27 volumio4 volumio[1801]: info: Starting Streaming Daemon Apr 13 10:50:27 volumio4 sudo[2114]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 13 10:50:27 volumio4 sudo[2114]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:50:27 volumio4 sudo[2114]: pam_unix(sudo:session): session closed for user root Apr 13 10:50:27 volumio4 volumio[1801]: error: Cannot start Volumio Streaming Daemon Apr 13 10:50:27 volumio4 volumio[1801]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 13 10:50:27 volumio4 volumio[1801]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 13 10:50:27 volumio4 volumio[1801]: info: Setting Geolocation for MyVolumio to as1 Apr 13 10:50:27 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:27 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:27 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:27 volumio4 volumio[1801]: info: Setting Geolocation for MyVolumio to as1 Apr 13 10:50:27 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:27 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:27 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:27 volumio4 volumio[1801]: info: Successfully Added MyVolumio device Apr 13 10:50:28 volumio4 volumio[1801]: info: Successfully Added MyVolumio device Apr 13 10:50:28 volumio4 volumio[1801]: info: Updating MyVolumio device info Apr 13 10:50:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:28 volumio4 volumio[1801]: info: Updating MyVolumio device info Apr 13 10:50:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:29 volumio4 volumio[1801]: info: Successfully Updated MyVolumio device Apr 13 10:50:30 volumio4 volumio[1801]: info: Successfully Updated MyVolumio device Apr 13 10:50:32 volumio4 sudo[2123]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Apr 13 10:50:32 volumio4 sudo[2123]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:50:32 volumio4 systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 13 10:50:32 volumio4 systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 13 10:50:32 volumio4 systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Apr 13 10:50:32 volumio4 sudo[2123]: pam_unix(sudo:session): session closed for user root Apr 13 10:50:32 volumio4 volumio[1801]: info: Remote SSH Started Apr 13 10:50:32 volumio4 autossh[2126]: port set to 0, monitoring disabled Apr 13 10:50:32 volumio4 autossh[2126]: starting ssh (count 1) Apr 13 10:50:32 volumio4 autossh[2126]: ssh child pid is 2129 Apr 13 10:50:32 volumio4 volumio[1801]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 13 10:50:32 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:32 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 0 Apr 13 10:50:32 volumio4 volumiossh-tunnel[2129]: Warning: Permanently added '[as1.myvolumio.org]:2222' (RSA) to the list of known hosts. Apr 13 10:50:38 volumio4 systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Apr 13 10:50:38 volumio4 systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Apr 13 10:50:38 volumio4 systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Apr 13 10:50:38 volumio4 sudo[2065]: pam_unix(sudo:session): session closed for user root Apr 13 10:50:38 volumio4 volumio[1801]: info: Upmpdcli Daemon Started Apr 13 10:50:38 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 13 10:50:38 volumio4 volumio[1801]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Apr 13 10:50:38 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:38 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 0 Apr 13 10:50:43 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:50:43 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:50:43 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 13 10:50:43 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 13 10:50:43 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 13 10:50:43 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetBrowseSources Apr 13 10:50:43 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 13 10:50:44 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 13 10:50:44 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:44 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 13 10:50:44 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 13 10:50:44 volumio4 volumio-remote-updater[896]: Test mode disabled Apr 13 10:50:44 volumio4 volumio-remote-updater[896]: Alpha mode disabled Apr 13 10:50:44 volumio4 volumio-remote-updater[896]: Alpha legacy test mode disabled Apr 13 10:50:45 volumio4 volumio[1801]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 13 10:50:45 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 13 10:50:45 volumio4 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Apr 13 10:50:45 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:45.479+09:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.50.36:58351 Apr 13 10:50:45 volumio4 volumio[1801]: verbose: New Socket.io Connection to 192.168.50.37:3000 from 192.168.50.36 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Apr 13 10:50:45 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:50:45 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:50:45 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:50:45 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:45 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 0 Apr 13 10:50:45 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:50:45 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:50:45 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:50:45 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:50:45 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:45 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 0 Apr 13 10:50:45 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:50:45 volumio4 volumio[1801]: verbose: New Socket.io Connection to 192.168.50.37:3000 from 192.168.50.36 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Apr 13 10:50:45 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 13 10:50:45 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 13 10:50:46 volumio4 systemd[1]: setdatetime-helper.service: Deactivated successfully. Apr 13 10:50:46 volumio4 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Apr 13 10:50:46 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:46.493+09:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.50.36:58351 @ 0x2e56750" latency=3.777381ms platform=PLATFORM_IOS version=5.260331.0 Apr 13 10:50:46 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:46.494+09:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.50.36:58351 @ 0x2e56750" latency=4.501324ms timeout=10s Apr 13 10:50:46 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:46.494+09:00 level=INFO msg="emitting device capabilities changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 13 10:50:46 volumio4 volumio[1801]: info: Received Get System Info Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:50:46 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:46 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 0 Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:50:46 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:46.496+09:00 level=INFO msg="emitting device name changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" name=Volumio4 Apr 13 10:50:46 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:46.498+09:00 level=INFO msg="emitting device language changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" language=ko Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Apr 13 10:50:46 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:46.499+09:00 level=INFO msg="emitting device timezone changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" timezone=Asia/Seoul Apr 13 10:50:46 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:46.499+09:00 level=INFO msg="emitting ethernet info changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" available=true connected=false macAddress= ip4Address= ip6Address= Apr 13 10:50:46 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:46.501+09:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" available=true connected=true macAddress=2c:cf:67:c1:37:44 ip4Address=192.168.50.37/24 ip6Address= ssid=Pandora_5GHz Apr 13 10:50:46 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:46.501+09:00 level=INFO msg="emitting device setup status changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" setupComplete=true Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 13 10:50:46 volumio4 volumio[1801]: amixer -c 0 info | grep "vc4-hdmi-0" Apr 13 10:50:46 volumio4 volumio[1801]: Card sysdefault:0 'vc4hdmi0'/'vc4-hdmi-0' Apr 13 10:50:46 volumio4 volumio[1801]: amixer -c 1 info | grep "vc4-hdmi-1" Apr 13 10:50:46 volumio4 volumio[1801]: Card sysdefault:1 'vc4hdmi1'/'vc4-hdmi-1' Apr 13 10:50:46 volumio4 volumio[1801]: error: Cannot read Audio Device Capabilities Command failed: /usr/local/bin/alsacap -C 5 Apr 13 10:50:46 volumio4 volumio[1801]: /bin/sh: 1: /usr/local/bin/alsacap: not found Apr 13 10:50:46 volumio4 volumio[1801]: {"cmd":"/usr/local/bin/alsacap -C 5","code":127,"killed":false,"signal":null,"stack":"Error: Command failed: /usr/local/bin/alsacap -C 5\n/bin/sh: 1: /usr/local/bin/alsacap: not found\n\n at ChildProcess.exithandler (node:child_process:421:12)\n at ChildProcess.emit (node:events:514:28)\n at maybeClose (node:internal/child_process:1105:16)\n at Socket. (node:internal/child_process:457:11)\n at Socket.emit (node:events:514:28)\n at Pipe. (node:net:337:12)"} Apr 13 10:50:46 volumio4 volumio[1801]: amixer -c 5 info | grep "USB HiRes Audio" Apr 13 10:50:46 volumio4 volumio[1801]: Invalid card number '5'. Apr 13 10:50:46 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:46.537+09:00 level=WARN msg="active output device not found in available devices" component=volumio/socket activeDeviceId=5 Apr 13 10:50:46 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:46.537+09:00 level=INFO msg="emitting audio outputs changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" selectedOutputId=5 Apr 13 10:50:46 volumio4 volumio[1801]: verbose: New Socket.io Connection to 192.168.50.37:3000 from 192.168.50.36 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:50:46 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:46 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 0 Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:50:46 volumio4 volumio[1801]: info: Received Get System Info Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:50:46 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:46 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 0 Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:50:46 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:46.568+09:00 level=INFO msg="emitting software info changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" currentVersion=4.119 latestVersion=4.119 Apr 13 10:50:46 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:46.568+09:00 level=INFO msg="emitting software update progress event" component=server peer="192.168.50.36:58351 @ 0x2e56750" status=UPDATE_STATUS_NONE progress=0 Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 13 10:50:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 13 10:50:47 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:47.976+09:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=SOrHrOzeEGf9UxP2y7jLF3qvxqq2 tokenExpiry=2026-04-13T11:50:47.976+09:00 Apr 13 10:50:48 volumio4 volumio[1801]: verbose: New Socket.io Connection to 192.168.50.37:3000 from 192.168.50.36 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Apr 13 10:50:48 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:50:48 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:50:48 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:50:48 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:48 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 0 Apr 13 10:50:48 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:50:49 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:49.460+09:00 level=INFO msg="emitting user changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" userId=SOrHrOzeEGf9UxP2y7jLF3qvxqq2 Apr 13 10:50:49 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 13 10:50:49 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 13 10:50:49 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 13 10:50:49 volumio4 upmpdcli[2221]: writing RSA key Apr 13 10:50:50 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:50.602+09:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=spotify error="could not open plugin config file for \"spop\": open /data/configuration/music_service/spop/config.json: no such file or directory" Apr 13 10:50:50 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:50.602+09:00 level=INFO msg="emitting music providers changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" providers=9 Apr 13 10:50:50 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 13 10:50:50 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 13 10:50:50 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 13 10:50:50 volumio4 bluealsa[1046]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_6D_2D_57_DC_98_A4, ...) Apr 13 10:50:51 volumio4 systemd[1]: Starting e2scrub_all.service - Online ext4 Metadata Check for All Filesystems... Apr 13 10:50:51 volumio4 systemd[1]: e2scrub_all.service: Deactivated successfully. Apr 13 10:50:51 volumio4 systemd[1]: Finished e2scrub_all.service - Online ext4 Metadata Check for All Filesystems. Apr 13 10:50:51 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:51.159+09:00 level=INFO msg="emitting plugins changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" plugins=63 Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:51 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 0 Apr 13 10:50:51 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:51.164+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" state=STATUS_STOPPED positionMs=0 volume=100 Apr 13 10:50:51 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:51.164+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" id=qobuz://song/754590 title=Fragile Apr 13 10:50:51 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:51.247+09:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.50.36:58351 @ 0x2e56750" latency=5.244181ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Apr 13 10:50:51 volumio4 sudo[2229]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 13 10:50:51 volumio4 sudo[2229]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:50:51 volumio4 sudo[2231]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 13 10:50:51 volumio4 sudo[2231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:50:51 volumio4 sudo[2229]: pam_unix(sudo:session): session closed for user root Apr 13 10:50:51 volumio4 sudo[2231]: pam_unix(sudo:session): session closed for user root Apr 13 10:50:51 volumio4 volumio[1801]: verbose: New Socket.io Connection to 192.168.50.37 from 192.168.50.36 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 6 Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 13 10:50:51 volumio4 sudo[2235]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 13 10:50:51 volumio4 sudo[2235]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:50:51 volumio4 sudo[2237]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 13 10:50:51 volumio4 sudo[2237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:50:51 volumio4 sudo[2235]: pam_unix(sudo:session): session closed for user root Apr 13 10:50:51 volumio4 sudo[2237]: pam_unix(sudo:session): session closed for user root Apr 13 10:50:51 volumio4 volumio[1801]: verbose: New Socket.io Connection to 192.168.50.37 from 192.168.50.36 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 7 Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetVisibleSources Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:51 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 0 Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 13 10:50:51 volumio4 volumio[1801]: info: Received Get System Info Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:50:51 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:51 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 0 Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:51 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 0 Apr 13 10:50:51 volumio4 volumio[1801]: info: Listing playlists Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 13 10:50:51 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 13 10:50:52 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:52.571+09:00 level=INFO msg="new address was allocated" component=ble/conn old=1 new=2 Apr 13 10:50:52 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetQueue Apr 13 10:50:52 volumio4 volumio[1801]: info: CoreStateMachine::getQueue Apr 13 10:50:52 volumio4 volumio[1801]: info: CorePlayQueue::getQueue Apr 13 10:50:52 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:50:52 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:50:53 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:50:53 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Apr 13 10:50:53 volumio4 volumio[1801]: info: CoreCommandRouter::volumioPlay Apr 13 10:50:53 volumio4 volumio[1801]: info: CoreStateMachine::play index 7 Apr 13 10:50:53 volumio4 volumio[1801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 13 10:50:53 volumio4 volumio[1801]: info: CoreStateMachine::stop Apr 13 10:50:53 volumio4 volumio[1801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 13 10:50:53 volumio4 volumio[1801]: info: CoreStateMachine::play index undefined Apr 13 10:50:53 volumio4 volumio[1801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 13 10:50:53 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:50:53 volumio4 volumio[1801]: info: CoreStateMachine::startPlaybackTimer Apr 13 10:50:53 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:50:53 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 13 10:50:53 volumio4 volumio[1801]: info: Received Get System Info Apr 13 10:50:53 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:50:53 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:50:53 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:50:53 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:53 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:50:53 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:50:53 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 13 10:50:54 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:54.491+09:00 level=INFO msg="new address was allocated" component=ble/conn old=2 new=3 Apr 13 10:50:54 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:50:54 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:50:54 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:50:56 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:56.381+09:00 level=INFO msg="new address was allocated" component=ble/conn old=3 new=4 Apr 13 10:50:56 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 13 10:50:56 volumio4 volumio[1801]: info: Received Get System Info Apr 13 10:50:56 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:50:56 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:50:56 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:50:56 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:56 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:50:56 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:50:56 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:50:56 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:50:56 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:50:57 volumio4 volumio[1801]: error: MyVolumio Plugins failed to start in a timely fashion Apr 13 10:50:57 volumio4 volumio[1801]: [Metrics] CommandRouter: 43s 866.73ms Apr 13 10:50:57 volumio4 volumio[1801]: info: CoreCommandRouter::volumiosetStartupVolume Apr 13 10:50:57 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:50:57 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:50:57 volumio4 volumio[1801]: info: CoreCommandRouter::Close All Modals sent Apr 13 10:50:57 volumio4 volumio[1801]: info: CoreCommandRouter::Close All Modals sent Apr 13 10:50:57 volumio4 volumio[1801]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Apr 13 10:50:57 volumio4 volumio[1801]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for Audio Apr 13 10:50:57 volumio4 volumio[1801]: aplay: main:831: audio open error: No such device Apr 13 10:50:57 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 13 10:50:57 volumio4 volumio[1801]: info: Received Get System Info Apr 13 10:50:57 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:50:57 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:50:57 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:50:57 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:57 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:50:57 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:50:57 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 13 10:50:57 volumio4 volumio[1801]: info: Received Get System Info Apr 13 10:50:57 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:50:57 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:50:57 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:50:57 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:50:57 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:50:57 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:50:58 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 13 10:50:58 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 13 10:50:58 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: raat , onStop Apr 13 10:50:58 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 13 10:50:58 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:50:58.271+09:00 level=INFO msg="new address was allocated" component=ble/conn old=4 new=5 Apr 13 10:50:58 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:50:58 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:50:58 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:00 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:00.101+09:00 level=INFO msg="new address was allocated" component=ble/conn old=5 new=6 Apr 13 10:51:00 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:00 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:01 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 13 10:51:03 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:03.311+09:00 level=INFO msg="new address was allocated" component=ble/conn old=6 new=7 Apr 13 10:51:03 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:03 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:03 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:04 volumio4 volumio[1801]: info: BOOT COMPLETED Apr 13 10:51:04 volumio4 kernel: usb 1-1: new high-speed USB device number 2 using xhci-hcd Apr 13 10:51:04 volumio4 kernel: usb 1-1: New USB device found, idVendor=152a, idProduct=86ef, bcdDevice= 3.03 Apr 13 10:51:04 volumio4 kernel: usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Apr 13 10:51:04 volumio4 kernel: usb 1-1: Product: USB HiRes Audio Apr 13 10:51:04 volumio4 kernel: usb 1-1: Manufacturer: DENAFRIPS Apr 13 10:51:04 volumio4 kernel: usbcore: registered new interface driver snd-usb-audio Apr 13 10:51:04 volumio4 volumio[1801]: info: Apr 13 10:51:04 volumio4 volumio[1801]: ---------------------------- USB Audio Device Attached Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::Close All Modals sent Apr 13 10:51:04 volumio4 volumio[1801]: info: Preparing to save Alsa Options, stopping services first Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:51:04 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::volumioPause Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreStateMachine::pause Apr 13 10:51:04 volumio4 volumio[1801]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"USB HiRes Audio","alsacard":"Audio"},"i2s":false} Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 13 10:51:04 volumio4 volumio[1801]: info: Setting mixer PCM for card USB HiRes Audio Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 13 10:51:04 volumio4 volumio[1801]: info: Updating Volume Controller Parameters: Device: 5 Name: USB HiRes Audio Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 13 10:51:04 volumio4 volumio[1801]: info: Disabling external Volume Control Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 13 10:51:04 volumio4 volumio[1801]: info: Preparing to generate the ALSA configuration file Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 13 10:51:04 volumio4 volumio[1801]: info: VolumeController:: Volume=33 Mute =false Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreStateMachine::pushState Apr 13 10:51:04 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::volumioPushState Apr 13 10:51:04 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:04.645+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" state=STATUS_STOPPED positionMs=10777 volume=33 Apr 13 10:51:04 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:04.645+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" id=qobuz://song/361720878 title="A Trace of Grace" Apr 13 10:51:04 volumio4 volumio[1801]: info: Asound.conf file unchanged, so no further update is needed Apr 13 10:51:04 volumio4 volumio[1801]: info: Output device has changed, restarting MPD Apr 13 10:51:04 volumio4 volumio[1801]: info: Output device has changed, restarting Shairport Sync Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:51:04 volumio4 sudo[2309]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 13 10:51:04 volumio4 sudo[2309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:51:04 volumio4 sudo[2309]: pam_unix(sudo:session): session closed for user root Apr 13 10:51:04 volumio4 sudo[2311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 13 10:51:04 volumio4 sudo[2311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:51:04 volumio4 volumio[1801]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 13 10:51:04 volumio4 volumio[1801]: info: MPD Permissions set Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:04 volumio4 systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:04 volumio4 volumio[1801]: info: Starting Shairport Sync Apr 13 10:51:04 volumio4 systemd[1]: mpd.service: Deactivated successfully. Apr 13 10:51:04 volumio4 systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 13 10:51:04 volumio4 systemd[1]: mpd.socket: Deactivated successfully. Apr 13 10:51:04 volumio4 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 13 10:51:04 volumio4 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 13 10:51:04 volumio4 sudo[2324]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 13 10:51:04 volumio4 sudo[2324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:51:04 volumio4 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 13 10:51:04 volumio4 systemd[1]: Starting mpd.service - Music Player Daemon... Apr 13 10:51:04 volumio4 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 13 10:51:04 volumio4 systemd[1]: shairport-sync.service: Deactivated successfully. Apr 13 10:51:04 volumio4 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 13 10:51:04 volumio4 systemd[1]: shairport-sync.service: Consumed 1.486s CPU time. Apr 13 10:51:04 volumio4 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 13 10:51:04 volumio4 sudo[2324]: pam_unix(sudo:session): session closed for user root Apr 13 10:51:04 volumio4 volumio[1801]: info: Shairport-Sync Started Apr 13 10:51:04 volumio4 sudo[2328]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 13 10:51:04 volumio4 sudo[2328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 13 10:51:04 volumio4 sudo[2328]: pam_unix(sudo:session): session closed for user root Apr 13 10:51:05 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat Apr 13 10:51:05 volumio4 mpd[2345]: 2026-04-13T10:51:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 13 10:51:05 volumio4 systemd[1]: Started mpd.service - Music Player Daemon. Apr 13 10:51:05 volumio4 sudo[2311]: pam_unix(sudo:session): session closed for user root Apr 13 10:51:05 volumio4 volumio[1801]: error: updateQueue error: null Apr 13 10:51:05 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:05.261+09:00 level=INFO msg="new address was allocated" component=ble/conn old=7 new=8 Apr 13 10:51:05 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:05 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:05 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:07 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:07.061+09:00 level=INFO msg="new address was allocated" component=ble/conn old=8 new=9 Apr 13 10:51:07 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:07 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:07 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:08 volumio4 volumio[1801]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Apr 13 10:51:08 volumio4 volumio[1801]: info: CoreStateMachine::getcurrentVolume Apr 13 10:51:08 volumio4 volumio[1801]: info: CoreCommandRouter::volumioRetrievevolume Apr 13 10:51:08 volumio4 volumio[1801]: info: VolumeController:: Volume=33 Mute =false Apr 13 10:51:08 volumio4 volumio[1801]: info: CoreStateMachine::pushState Apr 13 10:51:08 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:08 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 13 10:51:08 volumio4 volumio[1801]: info: CoreCommandRouter::volumioPushState Apr 13 10:51:08 volumio4 volumio[1801]: info: CoreStateMachine::updateTrackBlock Apr 13 10:51:08 volumio4 volumio[1801]: info: CorePlayQueue::getTrackBlock Apr 13 10:51:08 volumio4 volumio[1801]: info: CoreCommandRouter::volumioRetrievevolume Apr 13 10:51:08 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:08.629+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" state=STATUS_STOPPED positionMs=14529 volume=33 Apr 13 10:51:08 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:08.629+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" id=qobuz://song/361720878 title="A Trace of Grace" Apr 13 10:51:08 volumio4 volumio[1801]: info: VolumeController:: Volume=33 Mute =false Apr 13 10:51:08 volumio4 volumio[1801]: info: CoreStateMachine::pushState Apr 13 10:51:08 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:08 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 13 10:51:08 volumio4 volumio[1801]: info: CoreCommandRouter::volumioPushState Apr 13 10:51:08 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:08.644+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" state=STATUS_STOPPED positionMs=14779 volume=33 Apr 13 10:51:08 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:08.644+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" id=qobuz://song/361720878 title="A Trace of Grace" Apr 13 10:51:09 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:09.371+09:00 level=INFO msg="new address was allocated" component=ble/conn old=9 new=10 Apr 13 10:51:09 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:09 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:09 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:09 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:11 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:11.441+09:00 level=INFO msg="new address was allocated" component=ble/conn old=10 new=11 Apr 13 10:51:11 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:11 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:11 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:13 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:13.241+09:00 level=INFO msg="new address was allocated" component=ble/conn old=11 new=12 Apr 13 10:51:13 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:13 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:13 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:13 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 13 10:51:13 volumio4 volumio[1801]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 13 10:51:13 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 13 10:51:13 volumio4 volumio[1801]: info: Received Get System Version Apr 13 10:51:13 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 13 10:51:13 volumio4 volumio[1801]: info: Received Get System Info Apr 13 10:51:13 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:51:13 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:51:13 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:51:13 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:51:13 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:13 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:51:14 volumio4 volumio[1801]: verbose: New Socket.io Connection to 192.168.50.37:3000 from 192.168.50.36 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Apr 13 10:51:14 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:51:14 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:51:14 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:51:14 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:51:14 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:14 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:51:15 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:15.011+09:00 level=INFO msg="new address was allocated" component=ble/conn old=12 new=13 Apr 13 10:51:15 volumio4 volumio[1801]: info: CoreCommandRouter::volumioPlay Apr 13 10:51:15 volumio4 volumio[1801]: info: CoreStateMachine::play index 7 Apr 13 10:51:15 volumio4 volumio[1801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 13 10:51:15 volumio4 volumio[1801]: info: CoreStateMachine::stop Apr 13 10:51:15 volumio4 volumio[1801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 13 10:51:15 volumio4 volumio[1801]: info: CoreStateMachine::play index undefined Apr 13 10:51:15 volumio4 volumio[1801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 13 10:51:15 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:15 volumio4 volumio[1801]: info: CoreStateMachine::startPlaybackTimer Apr 13 10:51:15 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:15 volumio4 volumio[1801]: verbose: New Socket.io Connection to 192.168.50.37:3000 from 192.168.50.36 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Apr 13 10:51:15 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:51:15 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:51:15 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:51:15 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:51:15 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:15 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:51:15 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:15 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:15 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:16 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:16.961+09:00 level=INFO msg="new address was allocated" component=ble/conn old=13 new=14 Apr 13 10:51:17 volumio4 volumio[1801]: verbose: New Socket.io Connection to 192.168.50.37:3000 from 192.168.50.36 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Apr 13 10:51:17 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:17 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:51:17 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:51:17 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:51:17 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:51:17 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:17 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:51:17 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:17 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:18 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:18.761+09:00 level=INFO msg="new address was allocated" component=ble/conn old=14 new=15 Apr 13 10:51:19 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:19 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:19 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:20 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:20.651+09:00 level=INFO msg="new address was allocated" component=ble/conn old=15 new=16 Apr 13 10:51:20 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:21 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:21 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:21 volumio4 volumio[1801]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 13 10:51:21 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 13 10:51:21 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:51:21 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 13 10:51:21 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:21 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:21 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:21 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:21 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:21 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:21 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:21 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 13 10:51:21 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 13 10:51:22 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:22.481+09:00 level=INFO msg="new address was allocated" component=ble/conn old=16 new=17 Apr 13 10:51:22 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:22 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:22 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:23 volumio4 volumio[1801]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Apr 13 10:51:23 volumio4 volumio[1801]: info: Preparing to save Alsa Options, stopping services first Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:51:23 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::volumioPause Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreStateMachine::pause Apr 13 10:51:23 volumio4 volumio[1801]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"USB HiRes Audio"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 13 10:51:23 volumio4 volumio[1801]: info: Setting mixer PCM for card USB HiRes Audio Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 13 10:51:23 volumio4 volumio[1801]: info: Updating Volume Controller Parameters: Device: 5 Name: USB HiRes Audio Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 13 10:51:23 volumio4 volumio[1801]: info: Disabling external Volume Control Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 13 10:51:23 volumio4 volumio[1801]: info: Preparing to generate the ALSA configuration file Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 13 10:51:23 volumio4 volumio[1801]: info: Asound.conf file unchanged, so no further update is needed Apr 13 10:51:23 volumio4 volumio[1801]: info: Output device has changed, restarting MPD Apr 13 10:51:23 volumio4 sudo[2400]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 13 10:51:23 volumio4 sudo[2400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:51:23 volumio4 volumio[1801]: info: Output device has changed, restarting Shairport Sync Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:51:23 volumio4 sudo[2402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 13 10:51:23 volumio4 sudo[2400]: pam_unix(sudo:session): session closed for user root Apr 13 10:51:23 volumio4 sudo[2402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:51:23 volumio4 volumio[1801]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 13 10:51:23 volumio4 systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 13 10:51:23 volumio4 volumio[1801]: info: MPD Permissions set Apr 13 10:51:23 volumio4 volumio[1801]: info: VolumeController:: Volume=33 Mute =false Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreStateMachine::pushState Apr 13 10:51:23 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::volumioPushState Apr 13 10:51:23 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:23.510+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" state=STATUS_STOPPED positionMs=8429 volume=33 Apr 13 10:51:23 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:23.510+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" id=qobuz://song/361720878 title="A Trace of Grace" Apr 13 10:51:23 volumio4 systemd[1]: mpd.service: Deactivated successfully. Apr 13 10:51:23 volumio4 systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 13 10:51:23 volumio4 systemd[1]: mpd.socket: Deactivated successfully. Apr 13 10:51:23 volumio4 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 13 10:51:23 volumio4 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:23 volumio4 volumio[1801]: info: Starting Shairport Sync Apr 13 10:51:23 volumio4 sudo[2416]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 13 10:51:23 volumio4 sudo[2416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:51:23 volumio4 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 13 10:51:23 volumio4 systemd[1]: Starting mpd.service - Music Player Daemon... Apr 13 10:51:23 volumio4 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 13 10:51:23 volumio4 systemd[1]: shairport-sync.service: Deactivated successfully. Apr 13 10:51:23 volumio4 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 13 10:51:23 volumio4 systemd[1]: shairport-sync.service: Consumed 1.526s CPU time. Apr 13 10:51:23 volumio4 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 13 10:51:23 volumio4 sudo[2416]: pam_unix(sudo:session): session closed for user root Apr 13 10:51:23 volumio4 volumio[1801]: info: Shairport-Sync Started Apr 13 10:51:23 volumio4 sudo[2418]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 13 10:51:23 volumio4 sudo[2418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 13 10:51:23 volumio4 sudo[2418]: pam_unix(sudo:session): session closed for user root Apr 13 10:51:23 volumio4 mpd[2434]: 2026-04-13T10:51:23 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 13 10:51:23 volumio4 systemd[1]: Started mpd.service - Music Player Daemon. Apr 13 10:51:23 volumio4 sudo[2402]: pam_unix(sudo:session): session closed for user root Apr 13 10:51:23 volumio4 volumio[1801]: error: updateQueue error: null Apr 13 10:51:24 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:24.401+09:00 level=INFO msg="new address was allocated" component=ble/conn old=17 new=18 Apr 13 10:51:24 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:24 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:24 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:26 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:26.111+09:00 level=INFO msg="new address was allocated" component=ble/conn old=18 new=19 Apr 13 10:51:26 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:26 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:27 volumio4 volumio[1801]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Apr 13 10:51:27 volumio4 volumio[1801]: info: CoreStateMachine::getcurrentVolume Apr 13 10:51:27 volumio4 volumio[1801]: info: CoreCommandRouter::volumioRetrievevolume Apr 13 10:51:27 volumio4 volumio[1801]: info: VolumeController:: Volume=33 Mute =false Apr 13 10:51:27 volumio4 volumio[1801]: info: CoreStateMachine::pushState Apr 13 10:51:27 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:27 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 13 10:51:27 volumio4 volumio[1801]: info: CoreCommandRouter::volumioPushState Apr 13 10:51:27 volumio4 volumio[1801]: info: CoreStateMachine::updateTrackBlock Apr 13 10:51:27 volumio4 volumio[1801]: info: CorePlayQueue::getTrackBlock Apr 13 10:51:27 volumio4 volumio[1801]: info: CoreCommandRouter::volumioRetrievevolume Apr 13 10:51:27 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:27.466+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" state=STATUS_STOPPED positionMs=12432 volume=33 Apr 13 10:51:27 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:27.466+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" id=qobuz://song/361720878 title="A Trace of Grace" Apr 13 10:51:27 volumio4 volumio[1801]: info: VolumeController:: Volume=33 Mute =false Apr 13 10:51:27 volumio4 volumio[1801]: info: CoreStateMachine::pushState Apr 13 10:51:27 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:27 volumio4 volumio[1801]: info: CoreCommandRouter::volumioPushState Apr 13 10:51:27 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:27.482+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" state=STATUS_STOPPED positionMs=12432 volume=33 Apr 13 10:51:27 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:27.483+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" id=qobuz://song/361720878 title="A Trace of Grace" Apr 13 10:51:28 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:28.151+09:00 level=INFO msg="new address was allocated" component=ble/conn old=19 new=20 Apr 13 10:51:28 volumio4 volumio[1801]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:51:28 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:28 volumio4 volumio[1801]: info: Restoring Previous Volume level: 100 false false Apr 13 10:51:28 volumio4 volumio[1801]: info: Output device has changed, restarting MPD Apr 13 10:51:28 volumio4 volumio[1801]: info: Output device has changed, restarting Shairport Sync Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:51:28 volumio4 sudo[2457]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 13 10:51:28 volumio4 sudo[2457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:51:28 volumio4 sudo[2459]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 13 10:51:28 volumio4 sudo[2459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:51:28 volumio4 sudo[2457]: pam_unix(sudo:session): session closed for user root Apr 13 10:51:28 volumio4 volumio[1801]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 13 10:51:28 volumio4 volumio[1801]: info: Volume configurations have been set Apr 13 10:51:28 volumio4 systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 13 10:51:28 volumio4 volumio[1801]: info: Updating Volume Controller Parameters: Device: 5 Name: USB HiRes Audio Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 13 10:51:28 volumio4 volumio[1801]: info: Disabling external Volume Control Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreStateMachine::pushState Apr 13 10:51:28 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::volumioPushState Apr 13 10:51:28 volumio4 systemd[1]: mpd.service: Deactivated successfully. Apr 13 10:51:28 volumio4 systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 13 10:51:28 volumio4 systemd[1]: mpd.socket: Deactivated successfully. Apr 13 10:51:28 volumio4 systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 13 10:51:28 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:28.199+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" state=STATUS_STOPPED positionMs=13009 volume=100 Apr 13 10:51:28 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:28.199+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" id=qobuz://song/361720878 title="A Trace of Grace" Apr 13 10:51:28 volumio4 systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 13 10:51:28 volumio4 volumio[1801]: info: MPD Permissions set Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 13 10:51:28 volumio4 systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 13 10:51:28 volumio4 systemd[1]: Starting mpd.service - Music Player Daemon... Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 13 10:51:28 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 13 10:51:28 volumio4 volumio[1801]: info: Starting Shairport Sync Apr 13 10:51:28 volumio4 sudo[2484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 13 10:51:28 volumio4 sudo[2484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:51:28 volumio4 sudo[2477]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 13 10:51:28 volumio4 sudo[2477]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 13 10:51:28 volumio4 sudo[2477]: pam_unix(sudo:session): session closed for user root Apr 13 10:51:28 volumio4 systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 13 10:51:28 volumio4 systemd[1]: shairport-sync.service: Deactivated successfully. Apr 13 10:51:28 volumio4 systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 13 10:51:28 volumio4 systemd[1]: shairport-sync.service: Consumed 1.511s CPU time. Apr 13 10:51:28 volumio4 systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 13 10:51:28 volumio4 sudo[2484]: pam_unix(sudo:session): session closed for user root Apr 13 10:51:28 volumio4 volumio[1801]: info: Shairport-Sync Started Apr 13 10:51:28 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:28 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:28 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:28 volumio4 mpd[2487]: 2026-04-13T10:51:28 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 13 10:51:28 volumio4 systemd[1]: Started mpd.service - Music Player Daemon. Apr 13 10:51:28 volumio4 sudo[2459]: pam_unix(sudo:session): session closed for user root Apr 13 10:51:28 volumio4 volumio[1801]: error: updateQueue error: null Apr 13 10:51:30 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:30.191+09:00 level=INFO msg="new address was allocated" component=ble/conn old=20 new=21 Apr 13 10:51:30 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:30 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:30 volumio4 volumio[1801]: info: CoreCommandRouter::volumioPlay Apr 13 10:51:30 volumio4 volumio[1801]: info: CoreStateMachine::play index 2 Apr 13 10:51:30 volumio4 volumio[1801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 13 10:51:30 volumio4 volumio[1801]: info: CoreStateMachine::stop Apr 13 10:51:30 volumio4 volumio[1801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 13 10:51:30 volumio4 volumio[1801]: info: CoreStateMachine::play index undefined Apr 13 10:51:30 volumio4 volumio[1801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 13 10:51:30 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 2 Apr 13 10:51:30 volumio4 volumio[1801]: info: CoreStateMachine::startPlaybackTimer Apr 13 10:51:30 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 2 Apr 13 10:51:32 volumio4 volumio[1801]: verbose: New Socket.io Connection to 192.168.50.37:3000 from 192.168.50.36 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Apr 13 10:51:32 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:51:32 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:51:32 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:51:32 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:51:32 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 2 Apr 13 10:51:32 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:51:32 volumio4 volumio[1801]: info: VolumeController::SetAlsaVolume100 Apr 13 10:51:32 volumio4 volumio[1801]: info: CoreStateMachine::pushState Apr 13 10:51:32 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 2 Apr 13 10:51:32 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 13 10:51:32 volumio4 volumio[1801]: info: CoreCommandRouter::volumioPushState Apr 13 10:51:32 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:32.658+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" state=STATUS_STOPPED positionMs=1750 volume=100 Apr 13 10:51:32 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:32.659+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.50.36:58351 @ 0x2e56750" id=qobuz://song/22954812 title="Keep The Wolves Away" Apr 13 10:51:33 volumio4 volumio[1801]: verbose: New Socket.io Connection to 192.168.50.37:3000 from 192.168.50.36 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Apr 13 10:51:33 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:51:33 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:51:33 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:51:33 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:51:33 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 2 Apr 13 10:51:33 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:51:33 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:33.461+09:00 level=INFO msg="new address was allocated" component=ble/conn old=21 new=22 Apr 13 10:51:33 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:33 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:33 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:35 volumio4 volumio[1801]: verbose: New Socket.io Connection to 192.168.50.37:3000 from 192.168.50.36 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Apr 13 10:51:35 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 13 10:51:35 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 13 10:51:35 volumio4 volumio[1801]: info: Discovery: Getting this device information Apr 13 10:51:35 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetState Apr 13 10:51:35 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 2 Apr 13 10:51:35 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 13 10:51:35 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:35.572+09:00 level=INFO msg="new address was allocated" component=ble/conn old=22 new=23 Apr 13 10:51:35 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:35 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:36 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:36 volumio4 volumio[1801]: info: CoreCommandRouter::volumioPlay Apr 13 10:51:36 volumio4 volumio[1801]: info: CoreStateMachine::play index 7 Apr 13 10:51:36 volumio4 volumio[1801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 13 10:51:36 volumio4 volumio[1801]: info: CoreStateMachine::stop Apr 13 10:51:36 volumio4 volumio[1801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 13 10:51:36 volumio4 volumio[1801]: info: CoreStateMachine::play index undefined Apr 13 10:51:36 volumio4 volumio[1801]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 13 10:51:36 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:36 volumio4 volumio[1801]: info: CoreStateMachine::startPlaybackTimer Apr 13 10:51:36 volumio4 volumio[1801]: info: CorePlayQueue::getTrack 7 Apr 13 10:51:37 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:37.372+09:00 level=INFO msg="new address was allocated" component=ble/conn old=23 new=24 Apr 13 10:51:37 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:37 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:39 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:39.322+09:00 level=INFO msg="new address was allocated" component=ble/conn old=24 new=25 Apr 13 10:51:39 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:39 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:39 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:41 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:41.122+09:00 level=INFO msg="new address was allocated" component=ble/conn old=25 new=26 Apr 13 10:51:41 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:41 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:41 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:43 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:43.012+09:00 level=INFO msg="new address was allocated" component=ble/conn old=26 new=27 Apr 13 10:51:43 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:43 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:43 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:44 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:44.872+09:00 level=INFO msg="new address was allocated" component=ble/conn old=27 new=28 Apr 13 10:51:45 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:45 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:45 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:46 volumio4 volumio[1801]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 13 10:51:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 13 10:51:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 13 10:51:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 13 10:51:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 13 10:51:46 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 13 10:51:46 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:46.822+09:00 level=INFO msg="new address was allocated" component=ble/conn old=28 new=29 Apr 13 10:51:47 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:47 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:47 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:48 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:48.652+09:00 level=INFO msg="new address was allocated" component=ble/conn old=29 new=30 Apr 13 10:51:48 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:49 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:49 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 13 10:51:49 volumio4 volumio[1801]: info: Retrieving Cloud Streaming UI Apr 13 10:51:49 volumio4 volumio[1801]: info: Getting Tidal Cloud Configuration Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 13 10:51:49 volumio4 volumio[1801]: info: Getting Qobuz Cloud Configuration Apr 13 10:51:49 volumio4 volumio[1801]: info: Asking plugin for UI Config Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 13 10:51:49 volumio4 volumio[1801]: info: Getting Spotify Cloud Configuration Apr 13 10:51:49 volumio4 volumio[1801]: info: Asking plugin for UI Config Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 13 10:51:49 volumio4 volumio[1801]: info: Saving Spotify Acccount Apr 13 10:51:49 volumio4 volumio[1801]: info: Got Tidal Cloud Configuration Apr 13 10:51:49 volumio4 volumio[1801]: info: Got it Apr 13 10:51:49 volumio4 volumio[1801]: info: Got it Apr 13 10:51:49 volumio4 volumio[1801]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 13 10:51:49 volumio4 volumio[1801]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetBrowseSources Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetBrowseSources Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::volumioGetBrowseSources Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 13 10:51:49 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Apr 13 10:51:50 volumio4 volumio5-onboarding[1509]: time=2026-04-13T10:51:50.662+09:00 level=INFO msg="new address was allocated" component=ble/conn old=30 new=31 Apr 13 10:51:50 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:51 volumio4 dbus-daemon[884]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.13" (uid=0 pid=1509 comm="/usr/bin/volumio5-onboarding") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.1" (uid=0 pid=883 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") Apr 13 10:51:51 volumio4 kernel: Bluetooth: hci0: Opcode 0x200a failed: -16 Apr 13 10:51:51 volumio4 volumio[1801]: info: Disabling MyMusic plugin upnp Apr 13 10:51:51 volumio4 sudo[2546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Apr 13 10:51:51 volumio4 sudo[2546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 13 10:51:51 volumio4 systemd[1]: Stopping upmpdcli.service - UPnP Renderer front-end to MPD... Apr 13 10:51:52 volumio4 volumio[1801]: info: Enabling MyMusic plugin upnp Apr 13 10:51:52 volumio4 volumio[1801]: info: Enabling plugin upnp Apr 13 10:51:52 volumio4 volumio[1801]: info: Loading plugin "upnp"... Apr 13 10:51:52 volumio4 volumio[1801]: info: [1776045112436] Starting Upmpd Daemon Apr 13 10:51:52 volumio4 volumio[1801]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 13 10:51:52 volumio4 volumio[1801]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 13 10:51:52 volumio4 volumio[1801]: Error: listen EADDRINUSE: address already in use :::6599 Apr 13 10:51:52 volumio4 volumio[1801]: at Server.setupListenHandle [as _listen2] (node:net:1872:16) Apr 13 10:51:52 volumio4 volumio[1801]: at listenInCluster (node:net:1920:12) Apr 13 10:51:52 volumio4 volumio[1801]: at Server.listen (node:net:2008:7) Apr 13 10:51:52 volumio4 volumio[1801]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Apr 13 10:51:52 volumio4 volumio[1801]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Apr 13 10:51:52 volumio4 volumio[1801]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Apr 13 10:51:52 volumio4 volumio[1801]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 13 10:51:52 volumio4 volumio[1801]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) { Apr 13 10:51:52 volumio4 volumio[1801]: code: 'EADDRINUSE', Apr 13 10:51:52 volumio4 volumio[1801]: errno: -98, Apr 13 10:51:52 volumio4 volumio[1801]: syscall: 'listen', Apr 13 10:51:52 volumio4 volumio[1801]: address: '::', Apr 13 10:51:52 volumio4 volumio[1801]: port: 6599 Apr 13 10:51:52 volumio4 volumio[1801]: } Apr 13 10:51:52 volumio4 volumio[1801]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 13 10:51:52 volumio4 sudo[2562]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-13 10:50' Apr 13 10:51:52 volumio4 sudo[2562]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"