Oct 17 11:23:34 volumio ntpd[1276]: CLOCK: time stepped by 53827.378072 Oct 17 11:23:34 volumio ntpd[1276]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Oct 17 11:23:34 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 17 11:23:34 volumio volumio[1620]: info: CoreCommandRouter::volumioGetVisibleSources Oct 17 11:23:34 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 17 11:23:34 volumio volumio[1620]: info: CoreCommandRouter::volumioGetState Oct 17 11:23:34 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:23:34 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 17 11:23:34 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 17 11:23:34 volumio systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Oct 17 11:23:34 volumio volumio[1620]: info: Received Get System Info Oct 17 11:23:34 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 17 11:23:34 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 17 11:23:34 volumio volumio[1620]: info: Discovery: Getting this device information Oct 17 11:23:34 volumio volumio[1620]: info: CoreCommandRouter::volumioGetState Oct 17 11:23:34 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:23:34 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 17 11:23:34 volumio volumio[1620]: info: CoreCommandRouter::volumioGetState Oct 17 11:23:34 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:23:34 volumio systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Oct 17 11:23:34 volumio volumio[1620]: info: Listing playlists Oct 17 11:23:34 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 17 11:23:34 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 17 11:23:34 volumio systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Oct 17 11:23:34 volumio systemd[1]: dpkg-db-backup.service: Deactivated successfully. Oct 17 11:23:34 volumio systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Oct 17 11:23:34 volumio volumio[1620]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 17 11:23:35 volumio volumio[1620]: info: Volumio Network Manager: Network status updated: 2 Oct 17 11:23:35 volumio sudo[2398]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 17 11:23:35 volumio sudo[2398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 17 11:23:35 volumio sudo[2400]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 17 11:23:35 volumio sudo[2400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 17 11:23:35 volumio sudo[2398]: pam_unix(sudo:session): session closed for user root Oct 17 11:23:35 volumio sudo[2400]: pam_unix(sudo:session): session closed for user root Oct 17 11:23:35 volumio sudo[2404]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 17 11:23:35 volumio sudo[2404]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 17 11:23:35 volumio volumio[1620]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 17 11:23:35 volumio volumio[1620]: info: camilladsp service started and running in background, instance 1 Oct 17 11:23:35 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 17 11:23:35 volumio volumio[1620]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA Oct 17 11:23:35 volumio volumio[1620]: info: FusionDsp loaded Oct 17 11:23:35 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 17 11:23:35 volumio volumio[1620]: info: FusionDsp - --[object Object] Oct 17 11:23:35 volumio volumio[1620]: info: FusionDsp - Reporting Fusion DSP Enabled Oct 17 11:23:35 volumio volumio[1620]: info: Adding Signal Path Element [object Object] Oct 17 11:23:35 volumio volumio[1620]: info: Adding fusiondspeq DSP Signal Path Element Oct 17 11:23:35 volumio volumio[1620]: info: FusionDsp - ---- installed callbackRead (debounced 200ms) Oct 17 11:23:35 volumio volumio[1620]: info: FusionDsp - PEQ graph server listening on port 10015 Oct 17 11:23:35 volumio volumio[1620]: error: FusionDsp - Reload WebSocket error: [object Object] Oct 17 11:23:35 volumio volumio[1620]: warn: FusionDsp - CamillaDSP reload failed; continuing without rejecting the Promise to avoid an unhandled rejection: connect ECONNREFUSED 127.0.0.1:9876 Oct 17 11:23:35 volumio sudo[2418]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Oct 17 11:23:35 volumio sudo[2418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 17 11:23:35 volumio systemd[1]: Starting fusiondsp.service - FusionDsp Daemon... Oct 17 11:23:36 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 17 11:23:36 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 17 11:23:36 volumio volumio[1620]: info: Received Get System Info Oct 17 11:23:36 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 17 11:23:36 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 17 11:23:36 volumio volumio[1620]: info: Discovery: Getting this device information Oct 17 11:23:36 volumio volumio[1620]: info: CoreCommandRouter::volumioGetState Oct 17 11:23:36 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:23:36 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 17 11:23:37 volumio volumio[1620]: info: Discovery: Started advertising with name: Volumio Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 17 11:23:37 volumio volumio[1620]: info: Adding plugin bluetooth to MyMusic Plugins Oct 17 11:23:37 volumio volumio[1620]: info: Adding plugin multiroom to MyMusic Plugins Oct 17 11:23:37 volumio volumio[1620]: info: Adding plugin metavolumio to MyMusic Plugins Oct 17 11:23:37 volumio volumio[1620]: info: Adding plugin cd_controller to MyMusic Plugins Oct 17 11:23:37 volumio volumio[1620]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 17 11:23:37 volumio volumio[1620]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 17 11:23:37 volumio volumio[1620]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 17 11:23:37 volumio volumio[1620]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 17 11:23:38 volumio volumio[1620]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 17 11:23:38 volumio volumio[1620]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 17 11:23:38 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 17 11:23:38 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 17 11:23:38 volumio volumio[1620]: info: Starting MyVolumio Remote Streaming Endpoints Oct 17 11:23:38 volumio volumio[1620]: info: MyVolumio not started Oct 17 11:23:38 volumio volumio[1620]: info: Initializing device activation check Oct 17 11:23:38 volumio volumio[1620]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 17 11:23:38 volumio volumio[1620]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 17 11:23:38 volumio volumio[1620]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 17 11:23:38 volumio volumio[1620]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 17 11:23:38 volumio volumio[1620]: info: Streaming services startup Oct 17 11:23:38 volumio volumio[1620]: info: Starting Streaming Daemon Oct 17 11:23:38 volumio sudo[2427]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 17 11:23:38 volumio sudo[2427]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 17 11:23:38 volumio volumio[1620]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 17 11:23:38 volumio sudo[2427]: pam_unix(sudo:session): session closed for user root Oct 17 11:23:38 volumio volumio[1620]: error: Cannot start Volumio Streaming Daemon Oct 17 11:23:38 volumio volumio[1620]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 17 11:23:38 volumio volumio[1620]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 17 11:23:38 volumio volumio[1620]: info: Discovery: this is already registered, 7ef138ca-55cb-4439-93c2-e18587a9a71c Oct 17 11:23:38 volumio volumio[1620]: info: Discovery: Found device Volumio Oct 17 11:23:38 volumio volumio[1620]: info: CoreCommandRouter::volumioGetState Oct 17 11:23:38 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:23:38 volumio volumio[1620]: info: Discovery: this is already registered, 7ef138ca-55cb-4439-93c2-e18587a9a71c Oct 17 11:23:38 volumio volumio[1620]: info: Discovery: Found device Volumio Oct 17 11:23:38 volumio volumio[1620]: info: CoreCommandRouter::volumioGetState Oct 17 11:23:38 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:23:40 volumio wpa_supplicant[1487]: RRM: Ignoring radio measurement request: Not RRM network Oct 17 11:23:40 volumio systemd[1]: Started fusiondsp.service - FusionDsp Daemon. Oct 17 11:23:40 volumio sudo[2418]: pam_unix(sudo:session): session closed for user root Oct 17 11:23:40 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Oct 17 11:23:41 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Oct 17 11:23:41 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Oct 17 11:23:41 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Oct 17 11:23:41 volumio sudo[2404]: pam_unix(sudo:session): session closed for user root Oct 17 11:23:41 volumio volumio[1620]: info: Upmpdcli Daemon Started Oct 17 11:23:42 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Oct 17 11:23:42 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Oct 17 11:23:42 volumio volumio[1620]: info: CoreCommandRouter::volumioGetQueue Oct 17 11:23:42 volumio volumio[1620]: info: CoreStateMachine::getQueue Oct 17 11:23:42 volumio volumio[1620]: info: CorePlayQueue::getQueue Oct 17 11:23:43 volumio wpa_supplicant[1487]: RRM: Ignoring radio measurement request: Not RRM network Oct 17 11:23:44 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 17 11:23:50 volumio upmpdcli[2496]: writing RSA key Oct 17 11:23:50 volumio wpa_supplicant[1487]: RRM: Ignoring radio measurement request: Not RRM network Oct 17 11:23:53 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 17 11:23:53 volumio volumio[1620]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Oct 17 11:23:53 volumio volumio[1620]: info: CoreCommandRouter::volumioGetState Oct 17 11:23:53 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:23:53 volumio wpa_supplicant[1487]: RRM: Ignoring radio measurement request: Not RRM network Oct 17 11:23:56 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 17 11:23:56 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 17 11:23:56 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 17 11:23:56 volumio volumio-remote-updater[1098]: Test mode disabled Oct 17 11:23:56 volumio volumio-remote-updater[1098]: Alpha mode disabled Oct 17 11:23:56 volumio volumio-remote-updater[1098]: Alpha legacy test mode disabled Oct 17 11:23:56 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 17 11:23:56 volumio volumio5-onboarding[1877]: failed to bootstrap state: failed to check for software update: could not check for updates: context deadline exceeded Oct 17 11:23:57 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Oct 17 11:23:57 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Oct 17 11:23:57 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 1. Oct 17 11:23:57 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 17 11:23:57 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Oct 17 11:23:57 volumio volumio5-onboarding[2523]: time=2026-10-17T11:23:57.302+08:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z Oct 17 11:23:57 volumio volumio[1620]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8 Oct 17 11:23:57 volumio volumio[1620]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8 Oct 17 11:23:57 volumio volumio[1620]: info: Received Get System Info Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 17 11:23:57 volumio volumio[1620]: info: Discovery: Getting this device information Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::volumioGetState Oct 17 11:23:57 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 17 11:23:57 volumio volumio5-onboarding[2523]: time=2026-10-17T11:23:57.318+08:00 level=INFO msg="system info for 309844ba389dcfaf8cb999f3e8ebac9a" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119 Oct 17 11:23:57 volumio volumio5-onboarding[2523]: time=2026-10-17T11:23:57.367+08:00 level=INFO msg="bootstrapping state" hasInternet=true Oct 17 11:23:57 volumio volumio[1620]: info: Received Get System Info Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 17 11:23:57 volumio volumio[1620]: info: Discovery: Getting this device information Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::volumioGetState Oct 17 11:23:57 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 17 11:23:57 volumio wpa_supplicant[1487]: RRM: Ignoring radio measurement request: Not RRM network Oct 17 11:23:57 volumio volumio-remote-updater[1098]: Test mode disabled Oct 17 11:23:57 volumio volumio-remote-updater[1098]: Alpha mode disabled Oct 17 11:23:57 volumio volumio-remote-updater[1098]: Alpha legacy test mode disabled Oct 17 11:23:57 volumio volumio[1620]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 17 11:23:57 volumio volumio5-onboarding[2523]: time=2026-10-17T11:23:57.706+08:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Oct 17 11:23:57 volumio volumio5-onboarding[2523]: time=2026-10-17T11:23:57.707+08:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Oct 17 11:23:57 volumio volumio5-onboarding[2523]: time=2026-10-17T11:23:57.707+08:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 17 11:23:57 volumio volumio[1620]: info: Received Get System Info Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 17 11:23:57 volumio volumio[1620]: info: Discovery: Getting this device information Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::volumioGetState Oct 17 11:23:57 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 17 11:23:57 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 17 11:23:57 volumio volumio5-onboarding[2523]: time=2026-10-17T11:23:57.715+08:00 level=INFO msg="enabling local network discovery" Oct 17 11:23:57 volumio volumio5-onboarding[2523]: time=2026-10-17T11:23:57.722+08:00 level=INFO msg="enabling BLE discovery" Oct 17 11:23:58 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 17 11:23:58 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 17 11:23:58 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 17 11:23:58 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 17 11:23:58 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 17 11:23:58 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 17 11:23:58 volumio volumio[1620]: info: CoreCommandRouter::volumioGetBrowseSources Oct 17 11:23:58 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 17 11:23:58 volumio volumio[1620]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 17 11:23:58 volumio volumio[1620]: info: Completed starting MyVolumio Plugin Oct 17 11:23:58 volumio volumio[1620]: [Metrics] CommandRouter: 34s 310.38ms Oct 17 11:23:58 volumio volumio[1620]: info: CoreCommandRouter::volumiosetStartupVolume Oct 17 11:23:58 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 17 11:23:58 volumio volumio[1620]: info: VolumeController:: Setting startup Volume 70 Oct 17 11:23:58 volumio volumio[1620]: info: VolumeController::SetAlsaVolume70 Oct 17 11:23:58 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 17 11:23:58 volumio volumio[1620]: info: CoreCommandRouter::Close All Modals sent Oct 17 11:23:58 volumio volumio[1620]: info: CoreCommandRouter::Close All Modals sent Oct 17 11:23:58 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:23:58 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:23:58 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 11:23:58 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:23:58 volumio volumio[1620]: info: FusionDsp - Volumio is not playing Oct 17 11:23:58 volumio volumio[1620]: info: FusionDsp - Clipped samples monitor stopped Oct 17 11:23:58 volumio volumio5-onboarding[2523]: time=2026-10-17T11:23:58.707+08:00 level=INFO msg="service successfully established" component=discovery/localnet Oct 17 11:23:58 volumio volumio[1620]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 17 11:23:58 volumio volumio[1620]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 17 11:23:58 volumio volumio[1620]: info: camilladsp stopping service pid 2413... Oct 17 11:23:59 volumio volumio[1620]: info: camilladsp service terminated, instance 1 Oct 17 11:23:59 volumio volumio[1620]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 17 11:23:59 volumio volumio[1620]: info: camilladsp service started and running in background, instance 1 Oct 17 11:23:59 volumio volumio[1620]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 17 11:23:59 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 17 11:23:59 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 17 11:23:59 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 17 11:23:59 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 17 11:24:00 volumio wpa_supplicant[1487]: RRM: Ignoring radio measurement request: Not RRM network Oct 17 11:24:04 volumio volumio[1620]: info: camilladsp respawn in 100 ms (attempt 1/10) Oct 17 11:24:05 volumio volumio[1620]: info: BOOT COMPLETED Oct 17 11:24:06 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Oct 17 11:24:06 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand update Oct 17 11:24:06 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:24:06 volumio volumio[1620]: info: Oct 17 11:24:06 volumio volumio[1620]: ---------------------------- MPD announces state update: update Oct 17 11:24:06 volumio volumio[1620]: info: sendMpdCommand update took 6 milliseconds Oct 17 11:24:06 volumio volumio[1620]: info: ControllerMpd::getState Oct 17 11:24:06 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:24:06 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:24:06 volumio volumio[1620]: info: Oct 17 11:24:06 volumio volumio[1620]: ---------------------------- MPD announces state update: update Oct 17 11:24:06 volumio volumio[1620]: info: ControllerMpd::getState Oct 17 11:24:06 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:24:06 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:24:06 volumio volumio[1620]: info: Oct 17 11:24:06 volumio volumio[1620]: ---------------------------- MPD announces state update: update Oct 17 11:24:06 volumio volumio[1620]: info: ControllerMpd::getState Oct 17 11:24:06 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:24:06 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:24:06 volumio volumio[1620]: info: Oct 17 11:24:06 volumio volumio[1620]: ---------------------------- MPD announces state update: update Oct 17 11:24:06 volumio volumio[1620]: info: ControllerMpd::getState Oct 17 11:24:06 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:24:06 volumio volumio[1620]: info: sendMpdCommand status took 9 milliseconds Oct 17 11:24:06 volumio volumio[1620]: info: sendMpdCommand status took 5 milliseconds Oct 17 11:24:06 volumio volumio[1620]: info: sendMpdCommand status took 6 milliseconds Oct 17 11:24:06 volumio volumio[1620]: info: sendMpdCommand status took 5 milliseconds Oct 17 11:24:06 volumio volumio[1620]: info: sendMpdCommand status took 4 milliseconds Oct 17 11:24:06 volumio volumio[1620]: info: sendMpdCommand status took 3 milliseconds Oct 17 11:24:06 volumio volumio[1620]: info: sendMpdCommand status took 3 milliseconds Oct 17 11:24:06 volumio volumio[1620]: info: sendMpdCommand status took 3 milliseconds Oct 17 11:24:06 volumio volumio[1620]: verbose: ControllerMpd::parseState Oct 17 11:24:07 volumio volumio[1620]: info: Command Router : Notfying DB Updatetrue Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::parseState Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::parseState Oct 17 11:24:07 volumio volumio[1620]: info: Command Router : Notfying DB Updatetrue Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::Close All Modals sent Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::parseState Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::parseState Oct 17 11:24:07 volumio volumio[1620]: info: Command Router : Notfying DB Updatetrue Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::Close All Modals sent Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::parseState Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::parseState Oct 17 11:24:07 volumio volumio[1620]: info: Command Router : Notfying DB Updatetrue Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::Close All Modals sent Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::parseState Oct 17 11:24:07 volumio volumio[1620]: info: ControllerMpd::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::servicePushState Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 17 11:24:07 volumio volumio[1620]: verbose: CURRENT POSITION 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::syncState stateService stop Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::syncState currentStatus stop Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: No code Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: ControllerMpd::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::servicePushState Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 17 11:24:07 volumio volumio[1620]: verbose: CURRENT POSITION 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::syncState stateService stop Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::syncState currentStatus stop Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: No code Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: ControllerMpd::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::servicePushState Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 17 11:24:07 volumio volumio[1620]: verbose: CURRENT POSITION 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::syncState stateService stop Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::syncState currentStatus stop Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: No code Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: ControllerMpd::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::servicePushState Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 17 11:24:07 volumio volumio[1620]: verbose: CURRENT POSITION 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::syncState stateService stop Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::syncState currentStatus stop Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: No code Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: ------------------------------ 355ms Oct 17 11:24:07 volumio volumio[1620]: info: ------------------------------ 352ms Oct 17 11:24:07 volumio volumio[1620]: info: ------------------------------ 350ms Oct 17 11:24:07 volumio volumio[1620]: info: ------------------------------ 349ms Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:24:07 volumio volumio[1620]: info: Oct 17 11:24:07 volumio volumio[1620]: ---------------------------- MPD announces state update: update Oct 17 11:24:07 volumio volumio[1620]: info: ControllerMpd::getState Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:24:07 volumio volumio[1620]: info: Oct 17 11:24:07 volumio volumio[1620]: ---------------------------- MPD announces state update: update Oct 17 11:24:07 volumio volumio[1620]: info: ControllerMpd::getState Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:24:07 volumio volumio[1620]: info: Oct 17 11:24:07 volumio volumio[1620]: ---------------------------- MPD announces state update: update Oct 17 11:24:07 volumio volumio[1620]: info: ControllerMpd::getState Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:24:07 volumio volumio[1620]: info: Oct 17 11:24:07 volumio volumio[1620]: ---------------------------- MPD announces state update: update Oct 17 11:24:07 volumio volumio[1620]: info: ControllerMpd::getState Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:24:07 volumio volumio[1620]: info: sendMpdCommand status took 31 milliseconds Oct 17 11:24:07 volumio volumio[1620]: info: sendMpdCommand status took 31 milliseconds Oct 17 11:24:07 volumio volumio[1620]: info: sendMpdCommand status took 2 milliseconds Oct 17 11:24:07 volumio volumio[1620]: info: sendMpdCommand status took 2 milliseconds Oct 17 11:24:07 volumio volumio[1620]: info: sendMpdCommand status took 2 milliseconds Oct 17 11:24:07 volumio volumio[1620]: info: sendMpdCommand status took 1 milliseconds Oct 17 11:24:07 volumio volumio[1620]: info: sendMpdCommand status took 2 milliseconds Oct 17 11:24:07 volumio volumio[1620]: info: sendMpdCommand status took 1 milliseconds Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::parseState Oct 17 11:24:07 volumio volumio[1620]: info: Command Router : Notfying DB Updatefalse Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::Close All Modals sent Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::parseState Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::parseState Oct 17 11:24:07 volumio volumio[1620]: info: Command Router : Notfying DB Updatefalse Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::Close All Modals sent Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::parseState Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::parseState Oct 17 11:24:07 volumio volumio[1620]: info: Command Router : Notfying DB Updatefalse Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::Close All Modals sent Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::parseState Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::parseState Oct 17 11:24:07 volumio volumio[1620]: info: Command Router : Notfying DB Updatefalse Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::Close All Modals sent Oct 17 11:24:07 volumio volumio[1620]: verbose: ControllerMpd::parseState Oct 17 11:24:07 volumio volumio[1620]: info: ControllerMpd::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::servicePushState Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 17 11:24:07 volumio volumio[1620]: verbose: CURRENT POSITION 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::syncState stateService stop Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::syncState currentStatus stop Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: No code Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: ControllerMpd::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::servicePushState Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 17 11:24:07 volumio volumio[1620]: verbose: CURRENT POSITION 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::syncState stateService stop Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::syncState currentStatus stop Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: No code Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: ControllerMpd::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::servicePushState Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 17 11:24:07 volumio volumio[1620]: verbose: CURRENT POSITION 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::syncState stateService stop Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::syncState currentStatus stop Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: No code Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: ControllerMpd::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::servicePushState Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 17 11:24:07 volumio volumio[1620]: verbose: CURRENT POSITION 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::syncState stateService stop Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::syncState currentStatus stop Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: No code Oct 17 11:24:07 volumio volumio[1620]: info: CoreStateMachine::pushState Oct 17 11:24:07 volumio volumio[1620]: info: CorePlayQueue::getTrack 0 Oct 17 11:24:07 volumio volumio[1620]: info: CoreCommandRouter::volumioPushState Oct 17 11:24:07 volumio volumio[1620]: info: ------------------------------ 190ms Oct 17 11:24:07 volumio volumio[1620]: info: ------------------------------ 162ms Oct 17 11:24:07 volumio volumio[1620]: info: ------------------------------ 161ms Oct 17 11:24:07 volumio volumio[1620]: info: ------------------------------ 162ms Oct 17 11:24:16 volumio volumio[1620]: info: Preload queue cleared Oct 17 11:24:16 volumio volumio[1620]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 17 11:24:16 volumio volumio[1620]: info: CoreStateMachine::ClearQueue Oct 17 11:24:16 volumio volumio[1620]: info: CoreStateMachine::stop Oct 17 11:24:16 volumio volumio[1620]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:24:16 volumio volumio[1620]: info: CorePlayQueue::clearPlayQueue Oct 17 11:24:16 volumio volumio[1620]: info: CorePlayQueue::saveQueue Oct 17 11:24:16 volumio volumio[1620]: info: CoreCommandRouter::volumioPushQueue Oct 17 11:24:16 volumio volumio[1620]: info: CoreStateMachine::addQueueItems Oct 17 11:24:16 volumio volumio[1620]: info: CorePlayQueue::addQueueItems Oct 17 11:24:16 volumio volumio[1620]: info: Preload queue cleared Oct 17 11:24:16 volumio volumio[1620]: info: Adding Item to queue: music-library/NAS/music/《“黄碟”Wilson Audiophile贝多芬和埃奈斯库的小提琴奏鸣曲-》-24-176Hz [FLAC+CUE] Oct 17 11:24:16 volumio volumio[1620]: info: Exploding uri music-library/NAS/music/《“黄碟”Wilson Audiophile贝多芬和埃奈斯库的小提琴奏鸣曲-》-24-176Hz [FLAC+CUE] in service mpd Oct 17 11:24:16 volumio volumio[1620]: info: ALBUMART /albumart?cacheid=409&web=David%20Abel%2FJulie%20Steinberg/Beethoven%3A%20Violin%20Sonata%2C%20Op.%2096%20-%20Enescu%3A%20Violin%20Sonata%2C%20Op.%2025/extralarge&path=%2Fmnt%2FNAS%2Fmusic%2F%E3%80%8A%E2%80%9C%E9%BB%84%E7%A2%9F%E2%80%9DWilson%20Audiophile%E8%B4%9D%E5%A4%9A%E8%8A%AC%E5%92%8C%E5%9F%83%E5%A5%88%E6%96%AF%E5%BA%93%E7%9A%84%E5%B0%8F%E6%8F%90%E7%90%B4%E5%A5%8F%E9%B8%A3%E6%9B%B2-%E3%80%8B-24-176Hz%20%5BFLAC%2BCUE%5D%2F01%20-%20Beethoven%20-%20Violin%20Sonata%20No.%2010%20in%20G%20Major%2C%20Op.%2096%20-%20I.%20Allegro%20moderato.flac&metadata=false Oct 17 11:24:16 volumio volumio[1620]: info: URI /mnt/NAS/music/《“黄碟”Wilson Audiophile贝多芬和埃奈斯库的小提琴奏鸣曲-》-24-176Hz [FLAC+CUE]/01 - Beethoven - Violin Sonata No. 10 in G Major, Op. 96 - I. Allegro moderato.flac Oct 17 11:24:16 volumio volumio[1620]: info: ALBUMART /albumart?cacheid=409&web=David%20Abel%2FJulie%20Steinberg/Beethoven%3A%20Violin%20Sonata%2C%20Op.%2096%20-%20Enescu%3A%20Violin%20Sonata%2C%20Op.%2025/extralarge&path=%2Fmnt%2FNAS%2Fmusic%2F%E3%80%8A%E2%80%9C%E9%BB%84%E7%A2%9F%E2%80%9DWilson%20Audiophile%E8%B4%9D%E5%A4%9A%E8%8A%AC%E5%92%8C%E5%9F%83%E5%A5%88%E6%96%AF%E5%BA%93%E7%9A%84%E5%B0%8F%E6%8F%90%E7%90%B4%E5%A5%8F%E9%B8%A3%E6%9B%B2-%E3%80%8B-24-176Hz%20%5BFLAC%2BCUE%5D%2F02%20-%20Beethoven%20-%20Violin%20Sonata%20No.%2010%20in%20G%20Major%2C%20Op.%2096%20-%20II.%20Adagio%20espressivo.flac&metadata=false Oct 17 11:24:16 volumio volumio[1620]: info: URI /mnt/NAS/music/《“黄碟”Wilson Audiophile贝多芬和埃奈斯库的小提琴奏鸣曲-》-24-176Hz [FLAC+CUE]/02 - Beethoven - Violin Sonata No. 10 in G Major, Op. 96 - II. Adagio espressivo.flac Oct 17 11:24:16 volumio volumio[1620]: info: ALBUMART /albumart?cacheid=409&web=David%20Abel%2FJulie%20Steinberg/Beethoven%3A%20Violin%20Sonata%2C%20Op.%2096%20-%20Enescu%3A%20Violin%20Sonata%2C%20Op.%2025/extralarge&path=%2Fmnt%2FNAS%2Fmusic%2F%E3%80%8A%E2%80%9C%E9%BB%84%E7%A2%9F%E2%80%9DWilson%20Audiophile%E8%B4%9D%E5%A4%9A%E8%8A%AC%E5%92%8C%E5%9F%83%E5%A5%88%E6%96%AF%E5%BA%93%E7%9A%84%E5%B0%8F%E6%8F%90%E7%90%B4%E5%A5%8F%E9%B8%A3%E6%9B%B2-%E3%80%8B-24-176Hz%20%5BFLAC%2BCUE%5D%2F03%20-%20Beethoven%20-%20Violin%20Sonata%20No.%2010%20in%20G%20Major%2C%20Op.%2096%20-%20III.%20Scherzo%20-%20Allegro.flac&metadata=false Oct 17 11:24:16 volumio volumio[1620]: info: URI /mnt/NAS/music/《“黄碟”Wilson Audiophile贝多芬和埃奈斯库的小提琴奏鸣曲-》-24-176Hz [FLAC+CUE]/03 - Beethoven - Violin Sonata No. 10 in G Major, Op. 96 - III. Scherzo - Allegro.flac Oct 17 11:24:16 volumio volumio[1620]: info: ALBUMART /albumart?cacheid=409&web=David%20Abel%2FJulie%20Steinberg/Beethoven%3A%20Violin%20Sonata%2C%20Op.%2096%20-%20Enescu%3A%20Violin%20Sonata%2C%20Op.%2025/extralarge&path=%2Fmnt%2FNAS%2Fmusic%2F%E3%80%8A%E2%80%9C%E9%BB%84%E7%A2%9F%E2%80%9DWilson%20Audiophile%E8%B4%9D%E5%A4%9A%E8%8A%AC%E5%92%8C%E5%9F%83%E5%A5%88%E6%96%AF%E5%BA%93%E7%9A%84%E5%B0%8F%E6%8F%90%E7%90%B4%E5%A5%8F%E9%B8%A3%E6%9B%B2-%E3%80%8B-24-176Hz%20%5BFLAC%2BCUE%5D%2F04%20-%20Beethoven%20-%20Violin%20Sonata%20No.%2010%20in%20G%20Major%2C%20Op.%2096%20-%20IV.%20Poco%20allegretto.flac&metadata=false Oct 17 11:24:16 volumio volumio[1620]: info: URI /mnt/NAS/music/《“黄碟”Wilson Audiophile贝多芬和埃奈斯库的小提琴奏鸣曲-》-24-176Hz [FLAC+CUE]/04 - Beethoven - Violin Sonata No. 10 in G Major, Op. 96 - IV. Poco allegretto.flac Oct 17 11:24:16 volumio volumio[1620]: info: ALBUMART /albumart?cacheid=409&web=David%20Abel%2FJulie%20Steinberg/Beethoven%3A%20Violin%20Sonata%2C%20Op.%2096%20-%20Enescu%3A%20Violin%20Sonata%2C%20Op.%2025/extralarge&path=%2Fmnt%2FNAS%2Fmusic%2F%E3%80%8A%E2%80%9C%E9%BB%84%E7%A2%9F%E2%80%9DWilson%20Audiophile%E8%B4%9D%E5%A4%9A%E8%8A%AC%E5%92%8C%E5%9F%83%E5%A5%88%E6%96%AF%E5%BA%93%E7%9A%84%E5%B0%8F%E6%8F%90%E7%90%B4%E5%A5%8F%E9%B8%A3%E6%9B%B2-%E3%80%8B-24-176Hz%20%5BFLAC%2BCUE%5D%2F05%20-%20Enescu%20-%20Violin%20Sonata%20No.%203%20in%20A%20Minor%2C%20Op.%2025%2C%20Dans%20le%20caractere%20populaire%20roumain%20-%20I.flac&metadata=false Oct 17 11:24:16 volumio volumio[1620]: info: URI /mnt/NAS/music/《“黄碟”Wilson Audiophile贝多芬和埃奈斯库的小提琴奏鸣曲-》-24-176Hz [FLAC+CUE]/05 - Enescu - Violin Sonata No. 3 in A Minor, Op. 25, Dans le caractere populaire roumain - I.flac Oct 17 11:24:16 volumio volumio[1620]: info: ALBUMART /albumart?cacheid=409&web=David%20Abel%2FJulie%20Steinberg/Beethoven%3A%20Violin%20Sonata%2C%20Op.%2096%20-%20Enescu%3A%20Violin%20Sonata%2C%20Op.%2025/extralarge&path=%2Fmnt%2FNAS%2Fmusic%2F%E3%80%8A%E2%80%9C%E9%BB%84%E7%A2%9F%E2%80%9DWilson%20Audiophile%E8%B4%9D%E5%A4%9A%E8%8A%AC%E5%92%8C%E5%9F%83%E5%A5%88%E6%96%AF%E5%BA%93%E7%9A%84%E5%B0%8F%E6%8F%90%E7%90%B4%E5%A5%8F%E9%B8%A3%E6%9B%B2-%E3%80%8B-24-176Hz%20%5BFLAC%2BCUE%5D%2F06%20-%20Enescu%20-%20Violin%20Sonata%20No.%203%20in%20A%20Minor%2C%20Op.%2025%2C%20Dans%20le%20caractere%20populaire%20roumain%20-%20II.flac&metadata=false Oct 17 11:24:16 volumio volumio[1620]: info: URI /mnt/NAS/music/《“黄碟”Wilson Audiophile贝多芬和埃奈斯库的小提琴奏鸣曲-》-24-176Hz [FLAC+CUE]/06 - Enescu - Violin Sonata No. 3 in A Minor, Op. 25, Dans le caractere populaire roumain - II.flac Oct 17 11:24:16 volumio volumio[1620]: info: ALBUMART /albumart?cacheid=409&web=David%20Abel%2FJulie%20Steinberg/Beethoven%3A%20Violin%20Sonata%2C%20Op.%2096%20-%20Enescu%3A%20Violin%20Sonata%2C%20Op.%2025/extralarge&path=%2Fmnt%2FNAS%2Fmusic%2F%E3%80%8A%E2%80%9C%E9%BB%84%E7%A2%9F%E2%80%9DWilson%20Audiophile%E8%B4%9D%E5%A4%9A%E8%8A%AC%E5%92%8C%E5%9F%83%E5%A5%88%E6%96%AF%E5%BA%93%E7%9A%84%E5%B0%8F%E6%8F%90%E7%90%B4%E5%A5%8F%E9%B8%A3%E6%9B%B2-%E3%80%8B-24-176Hz%20%5BFLAC%2BCUE%5D%2F07%20-%20Enescu%20-%20Violin%20Sonata%20No.%203%20in%20A%20Minor%2C%20Op.%2025%2C%20Dans%20le%20caractere%20populaire%20roumain%20-%20III.flac&metadata=false Oct 17 11:24:16 volumio volumio[1620]: info: URI /mnt/NAS/music/《“黄碟”Wilson Audiophile贝多芬和埃奈斯库的小提琴奏鸣曲-》-24-176Hz [FLAC+CUE]/07 - Enescu - Violin Sonata No. 3 in A Minor, Op. 25, Dans le caractere populaire roumain - III.flac Oct 17 11:24:16 volumio volumio[1620]: info: ALBUMART /albumart?cacheid=409&web=/Beethoven%20(Sonato%20in%20G%20Major)%2C%20Enescu%20(Sonata%20No.%203)/extralarge&path=%2Fmnt%2FNAS%2Fmusic%2F%E3%80%8A%E2%80%9C%E9%BB%84%E7%A2%9F%E2%80%9DWilson%20Audiophile%E8%B4%9D%E5%A4%9A%E8%8A%AC%E5%92%8C%E5%9F%83%E5%A5%88%E6%96%AF%E5%BA%93%E7%9A%84%E5%B0%8F%E6%8F%90%E7%90%B4%E5%A5%8F%E9%B8%A3%E6%9B%B2-%E3%80%8B-24-176Hz%20%5BFLAC%2BCUE%5D%2FBeethoven%20Sonata%20in%20G%20Op.96%20For%20Piano%20and%20Violin-Enescu%20Sonata%20No.3%20in%20Rumanian%20Polkstyle.cue&metadata=false Oct 17 11:24:16 volumio volumio[1620]: info: URI /mnt/NAS/music/《“黄碟”Wilson Audiophile贝多芬和埃奈斯库的小提琴奏鸣曲-》-24-176Hz [FLAC+CUE]/Beethoven Sonata in G Op.96 For Piano and Violin-Enescu Sonata No.3 in Rumanian Polkstyle.cue Oct 17 11:24:16 volumio volumio[1620]: info: ALBUMART /albumart?cacheid=409&web=/Beethoven%20(Sonato%20in%20G%20Major)%2C%20Enescu%20(Sonata%20No.%203)/extralarge&path=%2Fmnt%2FNAS%2Fmusic%2F%E3%80%8A%E2%80%9C%E9%BB%84%E7%A2%9F%E2%80%9DWilson%20Audiophile%E8%B4%9D%E5%A4%9A%E8%8A%AC%E5%92%8C%E5%9F%83%E5%A5%88%E6%96%AF%E5%BA%93%E7%9A%84%E5%B0%8F%E6%8F%90%E7%90%B4%E5%A5%8F%E9%B8%A3%E6%9B%B2-%E3%80%8B-24-176Hz%20%5BFLAC%2BCUE%5D%2FBeethoven%20Sonata%20in%20G%20Op.96%20For%20Piano%20and%20Violin-Enescu%20Sonata%20No.3%20in%20Rumanian%20Polkstyle.cue&metadata=false Oct 17 11:24:16 volumio volumio[1620]: info: URI /mnt/NAS/music/《“黄碟”Wilson Audiophile贝多芬和埃奈斯库的小提琴奏鸣曲-》-24-176Hz [FLAC+CUE]/Beethoven Sonata in G Op.96 For Piano and Violin-Enescu Sonata No.3 in Rumanian Polkstyle.cue Oct 17 11:24:16 volumio volumio[1620]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 11:24:16 volumio volumio[1620]: Error: Unable to resolve or reject the same promise twice Oct 17 11:24:16 volumio volumio[1620]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Oct 17 11:24:16 volumio volumio[1620]: at /volumio/app/plugins/music_service/mpd/index.js:2582:21 Oct 17 11:24:16 volumio volumio[1620]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Oct 17 11:24:16 volumio volumio[1620]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Oct 17 11:24:16 volumio volumio[1620]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Oct 17 11:24:16 volumio volumio[1620]: at Socket.emit (node:events:514:28) Oct 17 11:24:16 volumio volumio[1620]: at addChunk (node:internal/streams/readable:343:12) Oct 17 11:24:16 volumio volumio[1620]: at readableAddChunk (node:internal/streams/readable:312:11) Oct 17 11:24:16 volumio volumio[1620]: at Readable.push (node:internal/streams/readable:253:10) Oct 17 11:24:16 volumio volumio[1620]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Oct 17 11:24:16 volumio volumio[1620]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 11:24:16 volumio sudo[2631]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-17 11:23' Oct 17 11:24:16 volumio sudo[2631]: 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"