Mar 26 17:02:01 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:01 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:02 volumio4 volumio5-onboarding[11846]: time=2026-03-26T17:02:02.920+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:02:02.920+01:00 Mar 26 17:02:04 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:04 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:02:04 volumio4 volumio5-onboarding[11846]: time=2026-03-26T17:02:04.239+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:02:04 volumio4 volumio5-onboarding[11846]: time=2026-03-26T17:02:04.258+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:02:04 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:02:04 volumio4 volumio5-onboarding[11846]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:02:04 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:02:04 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:02:04 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 318. Mar 26 17:02:04 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:04 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:04 volumio4 volumio5-onboarding[11874]: time=2026-03-26T17:02:04.524+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:02:04 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:04 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:04 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:04 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:04 volumio4 volumio5-onboarding[11874]: time=2026-03-26T17:02:04.559+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:02:04 volumio4 volumio5-onboarding[11874]: time=2026-03-26T17:02:04.609+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:02:04 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:04 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:04 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:02:04 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:02:04 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:02:04 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:04 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:05 volumio4 volumio5-onboarding[11874]: time=2026-03-26T17:02:05.977+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 26 17:02:05 volumio4 volumio5-onboarding[11874]: time=2026-03-26T17:02:05.989+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 26 17:02:05 volumio4 volumio5-onboarding[11874]: time=2026-03-26T17:02:05.995+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 26 17:02:05 volumio4 volumio5-onboarding[11874]: time=2026-03-26T17:02:05.995+01: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" Mar 26 17:02:05 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:06 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:06 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:06 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:06 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:07 volumio4 kernel: hwmon hwmon1: Undervoltage detected! Mar 26 17:02:08 volumio4 volumio5-onboarding[11874]: time=2026-03-26T17:02:08.800+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:02:08.800+01:00 Mar 26 17:02:10 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:10 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:02:10 volumio4 volumio5-onboarding[11874]: time=2026-03-26T17:02:10.125+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:02:10 volumio4 volumio5-onboarding[11874]: time=2026-03-26T17:02:10.146+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:02:10 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:02:10 volumio4 volumio5-onboarding[11874]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:02:10 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:02:10 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:02:10 volumio4 systemd[1]: volumio5-onboarding.service: Consumed 1.016s CPU time. Mar 26 17:02:10 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 319. Mar 26 17:02:10 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:10 volumio4 systemd[1]: volumio5-onboarding.service: Consumed 1.016s CPU time. Mar 26 17:02:10 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:10 volumio4 volumio5-onboarding[11915]: time=2026-03-26T17:02:10.514+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:02:10 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:10 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:10 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:10 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:10 volumio4 volumio5-onboarding[11915]: time=2026-03-26T17:02:10.549+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:02:10 volumio4 volumio5-onboarding[11915]: time=2026-03-26T17:02:10.589+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:02:10 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:10 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:10 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:02:10 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:02:10 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:02:10 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:10 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:11 volumio4 volumio5-onboarding[11915]: time=2026-03-26T17:02:11.538+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 26 17:02:11 volumio4 volumio5-onboarding[11915]: time=2026-03-26T17:02:11.541+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 26 17:02:11 volumio4 volumio5-onboarding[11915]: time=2026-03-26T17:02:11.541+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 26 17:02:11 volumio4 volumio5-onboarding[11915]: time=2026-03-26T17:02:11.542+01: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" Mar 26 17:02:11 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:11 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:11 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:11 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:11 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:11 volumio4 kernel: hwmon hwmon1: Voltage normalised Mar 26 17:02:12 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:12 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:13 volumio4 volumio5-onboarding[11915]: time=2026-03-26T17:02:13.486+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:02:13.486+01:00 Mar 26 17:02:14 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:14 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:14 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:14 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:14 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:14 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:14 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:02:14 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:02:14 volumio4 volumio5-onboarding[11915]: time=2026-03-26T17:02:14.714+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:02:14 volumio4 volumio5-onboarding[11915]: time=2026-03-26T17:02:14.733+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:02:14 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:02:14 volumio4 volumio5-onboarding[11915]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:02:14 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:02:14 volumio4 volumio[1312]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 26 17:02:14 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:02:14 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 320. Mar 26 17:02:14 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:15 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:15 volumio4 volumio5-onboarding[11939]: time=2026-03-26T17:02:15.033+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:02:15 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:15 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:15 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:15 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:15 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:15 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:15 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:15 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:15 volumio4 volumio5-onboarding[11939]: time=2026-03-26T17:02:15.069+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:02:15 volumio4 volumio5-onboarding[11939]: time=2026-03-26T17:02:15.109+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:02:15 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:15 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:15 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:15 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:15 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:15 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:15 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:02:15 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:02:15 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:02:15 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:02:15 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:02:15 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:15 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:15 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:16 volumio4 volumio5-onboarding[11939]: time=2026-03-26T17:02:16.362+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 26 17:02:16 volumio4 volumio5-onboarding[11939]: time=2026-03-26T17:02:16.364+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 26 17:02:16 volumio4 volumio5-onboarding[11939]: time=2026-03-26T17:02:16.364+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 26 17:02:16 volumio4 volumio5-onboarding[11939]: time=2026-03-26T17:02:16.364+01: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" Mar 26 17:02:16 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:16 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:16 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:17 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:17 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:18 volumio4 volumio5-onboarding[11939]: time=2026-03-26T17:02:18.391+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:02:18.391+01:00 Mar 26 17:02:20 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:20 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:02:20 volumio4 volumio5-onboarding[11939]: time=2026-03-26T17:02:20.081+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:02:20 volumio4 volumio5-onboarding[11939]: time=2026-03-26T17:02:20.102+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:02:20 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:02:20 volumio4 volumio5-onboarding[11939]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:02:20 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:02:20 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:02:20 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 321. Mar 26 17:02:20 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:20 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:20 volumio4 volumio5-onboarding[11978]: time=2026-03-26T17:02:20.543+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:02:20 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:20 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:20 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:20 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:20 volumio4 volumio5-onboarding[11978]: time=2026-03-26T17:02:20.579+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:02:20 volumio4 volumio5-onboarding[11978]: time=2026-03-26T17:02:20.650+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:02:20 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:20 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:20 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:02:20 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:02:20 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:02:20 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:22 volumio4 volumio5-onboarding[11978]: time=2026-03-26T17:02:22.298+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 26 17:02:22 volumio4 volumio5-onboarding[11978]: time=2026-03-26T17:02:22.300+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 26 17:02:22 volumio4 volumio5-onboarding[11978]: time=2026-03-26T17:02:22.300+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 26 17:02:22 volumio4 volumio5-onboarding[11978]: time=2026-03-26T17:02:22.300+01: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" Mar 26 17:02:22 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:22 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:22 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:23 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:23 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:24 volumio4 volumio5-onboarding[11978]: time=2026-03-26T17:02:24.416+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:02:24.416+01:00 Mar 26 17:02:26 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:26 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:02:26 volumio4 volumio5-onboarding[11978]: time=2026-03-26T17:02:26.054+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:02:26 volumio4 volumio5-onboarding[11978]: time=2026-03-26T17:02:26.073+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:02:26 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:02:26 volumio4 volumio5-onboarding[11978]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:02:26 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:02:26 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:02:26 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 322. Mar 26 17:02:26 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:26 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:26 volumio4 volumio5-onboarding[12004]: time=2026-03-26T17:02:26.513+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:02:26 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:26 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:26 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:26 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:26 volumio4 volumio5-onboarding[12004]: time=2026-03-26T17:02:26.548+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:02:26 volumio4 volumio5-onboarding[12004]: time=2026-03-26T17:02:26.625+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:02:26 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:26 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:26 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:02:26 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:02:26 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:02:26 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:26 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:27 volumio4 volumio5-onboarding[12004]: time=2026-03-26T17:02:27.814+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 26 17:02:27 volumio4 volumio5-onboarding[12004]: time=2026-03-26T17:02:27.821+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 26 17:02:27 volumio4 volumio5-onboarding[12004]: time=2026-03-26T17:02:27.821+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 26 17:02:27 volumio4 volumio5-onboarding[12004]: time=2026-03-26T17:02:27.824+01: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" Mar 26 17:02:27 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:27 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:27 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:29 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:29 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:30 volumio4 volumio5-onboarding[12004]: time=2026-03-26T17:02:30.132+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:02:30.132+01:00 Mar 26 17:02:31 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:31 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:31 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:31 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:31 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:31 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:31 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:02:31 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:02:31 volumio4 volumio5-onboarding[12004]: time=2026-03-26T17:02:31.409+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:02:31 volumio4 volumio5-onboarding[12004]: time=2026-03-26T17:02:31.428+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:02:31 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:02:31 volumio4 volumio5-onboarding[12004]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:02:31 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:02:31 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:02:31 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 323. Mar 26 17:02:31 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:31 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:31 volumio4 volumio5-onboarding[12044]: time=2026-03-26T17:02:31.784+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:02:31 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:31 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:31 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:31 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:31 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:31 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:31 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:31 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:31 volumio4 volumio5-onboarding[12044]: time=2026-03-26T17:02:31.818+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:02:31 volumio4 volumio5-onboarding[12044]: time=2026-03-26T17:02:31.870+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:02:31 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:31 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:31 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:31 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:31 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:31 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:31 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:02:31 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:02:31 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:02:32 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:02:32 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:02:32 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:32 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:32 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:33 volumio4 volumio5-onboarding[12044]: time=2026-03-26T17:02:33.191+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 26 17:02:33 volumio4 volumio5-onboarding[12044]: time=2026-03-26T17:02:33.192+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 26 17:02:33 volumio4 volumio5-onboarding[12044]: time=2026-03-26T17:02:33.193+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 26 17:02:33 volumio4 volumio5-onboarding[12044]: time=2026-03-26T17:02:33.193+01: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" Mar 26 17:02:33 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:33 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:33 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:34 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:34 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:35 volumio4 volumio5-onboarding[12044]: time=2026-03-26T17:02:35.095+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:02:35.095+01:00 Mar 26 17:02:36 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:36 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:36 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:36 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:36 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:36 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:36 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:02:36 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:02:36 volumio4 volumio5-onboarding[12044]: time=2026-03-26T17:02:36.526+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:02:36 volumio4 volumio5-onboarding[12044]: time=2026-03-26T17:02:36.545+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:02:36 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:02:36 volumio4 volumio5-onboarding[12044]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:02:36 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:02:36 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:02:36 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 324. Mar 26 17:02:36 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:36 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:37 volumio4 volumio5-onboarding[12067]: time=2026-03-26T17:02:37.024+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:02:37 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:37 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:37 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:37 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:37 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:37 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:37 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:37 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:37 volumio4 volumio5-onboarding[12067]: time=2026-03-26T17:02:37.063+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:02:37 volumio4 volumio5-onboarding[12067]: time=2026-03-26T17:02:37.112+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:02:37 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:37 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:37 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:37 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:37 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:37 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:37 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:02:37 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:02:37 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:02:37 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:02:37 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:02:37 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:37 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:37 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:38 volumio4 volumio5-onboarding[12067]: time=2026-03-26T17:02:38.395+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 26 17:02:38 volumio4 volumio5-onboarding[12067]: time=2026-03-26T17:02:38.397+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 26 17:02:38 volumio4 volumio5-onboarding[12067]: time=2026-03-26T17:02:38.397+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 26 17:02:38 volumio4 volumio5-onboarding[12067]: time=2026-03-26T17:02:38.397+01: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" Mar 26 17:02:38 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:38 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:38 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:38 volumio4 kernel: hwmon hwmon1: Undervoltage detected! Mar 26 17:02:39 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:39 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:40 volumio4 volumio5-onboarding[12067]: time=2026-03-26T17:02:40.968+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:02:40.968+01:00 Mar 26 17:02:42 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:42 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:42 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:42 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:42 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:42 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:42 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:02:42 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:02:42 volumio4 volumio5-onboarding[12067]: time=2026-03-26T17:02:42.656+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:02:42 volumio4 volumio5-onboarding[12067]: time=2026-03-26T17:02:42.676+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:02:42 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:02:42 volumio4 volumio5-onboarding[12067]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:02:42 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:02:42 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:02:42 volumio4 systemd[1]: volumio5-onboarding.service: Consumed 1.144s CPU time. Mar 26 17:02:42 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 325. Mar 26 17:02:42 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:42 volumio4 systemd[1]: volumio5-onboarding.service: Consumed 1.144s CPU time. Mar 26 17:02:42 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:43 volumio4 volumio5-onboarding[12109]: time=2026-03-26T17:02:43.023+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:02:43 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:43 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:43 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:43 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:43 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:43 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:43 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:43 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:43 volumio4 volumio5-onboarding[12109]: time=2026-03-26T17:02:43.060+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:02:43 volumio4 volumio5-onboarding[12109]: time=2026-03-26T17:02:43.162+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:02:43 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:43 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:43 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:43 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:43 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:43 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:43 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:02:43 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:02:43 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:02:43 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:02:43 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:02:43 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:43 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:43 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:43 volumio4 volumio[1312]: info: CALLMETHOD: music_service ytcr configSaveOther [object Object] Mar 26 17:02:43 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: ytcr , configSaveOther Mar 26 17:02:44 volumio4 volumio5-onboarding[12109]: time=2026-03-26T17:02:44.578+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 26 17:02:44 volumio4 volumio5-onboarding[12109]: time=2026-03-26T17:02:44.580+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 26 17:02:44 volumio4 volumio5-onboarding[12109]: time=2026-03-26T17:02:44.581+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 26 17:02:44 volumio4 volumio5-onboarding[12109]: time=2026-03-26T17:02:44.581+01: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" Mar 26 17:02:44 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:44 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:44 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:45 volumio4 kernel: hwmon hwmon1: Voltage normalised Mar 26 17:02:45 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:45 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:46 volumio4 volumio[1312]: info: Mar 26 17:02:46 volumio4 volumio[1312]: ---------------------------- MPD announces system playlist update Mar 26 17:02:46 volumio4 volumio[1312]: info: Ignoring MPD Status Update Mar 26 17:02:46 volumio4 volumio[1312]: info: Mar 26 17:02:46 volumio4 volumio[1312]: ---------------------------- MPD announces state update: player Mar 26 17:02:46 volumio4 volumio[1312]: info: ControllerMpd::getState Mar 26 17:02:46 volumio4 volumio[1312]: verbose: ControllerMpd::sendMpdCommand status Mar 26 17:02:46 volumio4 volumio[1312]: info: Mar 26 17:02:46 volumio4 volumio[1312]: ---------------------------- MPD announces system playlist update Mar 26 17:02:46 volumio4 volumio[1312]: info: Ignoring MPD Status Update Mar 26 17:02:46 volumio4 volumio[1312]: info: Mar 26 17:02:46 volumio4 volumio[1312]: ---------------------------- MPD announces state update: player Mar 26 17:02:46 volumio4 volumio[1312]: info: ControllerMpd::getState Mar 26 17:02:46 volumio4 volumio[1312]: verbose: ControllerMpd::sendMpdCommand status Mar 26 17:02:46 volumio4 volumio[1312]: info: Mar 26 17:02:46 volumio4 volumio[1312]: ---------------------------- MPD announces system playlist update Mar 26 17:02:46 volumio4 volumio[1312]: info: Ignoring MPD Status Update Mar 26 17:02:46 volumio4 volumio[1312]: info: Mar 26 17:02:46 volumio4 volumio[1312]: ---------------------------- MPD announces state update: player Mar 26 17:02:46 volumio4 volumio[1312]: info: ControllerMpd::getState Mar 26 17:02:46 volumio4 volumio[1312]: verbose: ControllerMpd::sendMpdCommand status Mar 26 17:02:46 volumio4 volumio[1312]: info: ------------------------------ 4ms Mar 26 17:02:46 volumio4 volumio[1312]: info: sendMpdCommand status took 4 milliseconds Mar 26 17:02:46 volumio4 volumio[1312]: info: ------------------------------ 3ms Mar 26 17:02:46 volumio4 volumio[1312]: verbose: ControllerMpd::parseState Mar 26 17:02:46 volumio4 volumio[1312]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 17:02:46 volumio4 volumio[1312]: info: sendMpdCommand status took 5 milliseconds Mar 26 17:02:46 volumio4 volumio[1312]: info: ------------------------------ 5ms Mar 26 17:02:46 volumio4 volumio[1312]: info: sendMpdCommand status took 5 milliseconds Mar 26 17:02:46 volumio4 volumio[1312]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 26 17:02:46 volumio4 volumio[1312]: verbose: ControllerMpd::parseState Mar 26 17:02:46 volumio4 volumio[1312]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 17:02:46 volumio4 volumio[1312]: verbose: ControllerMpd::parseState Mar 26 17:02:46 volumio4 volumio[1312]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 26 17:02:46 volumio4 volumio[1312]: verbose: ControllerMpd::parseTrackInfo Mar 26 17:02:46 volumio4 volumio[1312]: info: ControllerMpd::pushState Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreCommandRouter::servicePushState Mar 26 17:02:46 volumio4 volumio[1312]: info: CorePlayQueue::getTrack 1 Mar 26 17:02:46 volumio4 volumio[1312]: verbose: STATE SERVICE {"status":"play","position":0,"seek":53613,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"127 Kbps","isStreaming":false,"title":"aut of orda - cinderella","artist":"Radio Rot Weiss Rot","album":null,"uri":"https://secureonair.krone.at/rwr.aac","trackType":"aac"} Mar 26 17:02:46 volumio4 volumio[1312]: verbose: CURRENT POSITION 1 Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreStateMachine::syncState stateService play Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreStateMachine::syncState currentStatus play Mar 26 17:02:46 volumio4 volumio[1312]: info: Received an update from plugin. extracting info from payload Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreStateMachine::pushState Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreCommandRouter::volumioPushState Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreStateMachine::pushState Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreCommandRouter::volumioPushState Mar 26 17:02:46 volumio4 volumio[1312]: info: ------------------------------ 21ms Mar 26 17:02:46 volumio4 volumio[1312]: info: sendMpdCommand playlistinfo took 13 milliseconds Mar 26 17:02:46 volumio4 volumio[1312]: info: sendMpdCommand playlistinfo took 13 milliseconds Mar 26 17:02:46 volumio4 volumio[1312]: verbose: ControllerMpd::parseTrackInfo Mar 26 17:02:46 volumio4 volumio[1312]: verbose: ControllerMpd::parseTrackInfo Mar 26 17:02:46 volumio4 volumio[1312]: info: ControllerMpd::pushState Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreCommandRouter::servicePushState Mar 26 17:02:46 volumio4 volumio[1312]: info: CorePlayQueue::getTrack 1 Mar 26 17:02:46 volumio4 volumio[1312]: verbose: STATE SERVICE {"status":"play","position":0,"seek":53613,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"127 Kbps","isStreaming":false,"title":"aut of orda - cinderella","artist":"Radio Rot Weiss Rot","album":null,"uri":"https://secureonair.krone.at/rwr.aac","trackType":"aac"} Mar 26 17:02:46 volumio4 volumio[1312]: verbose: CURRENT POSITION 1 Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreStateMachine::syncState stateService play Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreStateMachine::syncState currentStatus play Mar 26 17:02:46 volumio4 volumio[1312]: info: Received an update from plugin. extracting info from payload Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreStateMachine::pushState Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreCommandRouter::volumioPushState Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreStateMachine::pushState Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreCommandRouter::volumioPushState Mar 26 17:02:46 volumio4 volumio[1312]: info: ControllerMpd::pushState Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreCommandRouter::servicePushState Mar 26 17:02:46 volumio4 volumio[1312]: info: CorePlayQueue::getTrack 1 Mar 26 17:02:46 volumio4 volumio[1312]: verbose: STATE SERVICE {"status":"play","position":0,"seek":53613,"duration":0,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"127 Kbps","isStreaming":false,"title":"aut of orda - cinderella","artist":"Radio Rot Weiss Rot","album":null,"uri":"https://secureonair.krone.at/rwr.aac","trackType":"aac"} Mar 26 17:02:46 volumio4 volumio[1312]: verbose: CURRENT POSITION 1 Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreStateMachine::syncState stateService play Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreStateMachine::syncState currentStatus play Mar 26 17:02:46 volumio4 volumio[1312]: info: Received an update from plugin. extracting info from payload Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreStateMachine::pushState Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreCommandRouter::volumioPushState Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreStateMachine::pushState Mar 26 17:02:46 volumio4 volumio[1312]: info: CoreCommandRouter::volumioPushState Mar 26 17:02:46 volumio4 volumio[1312]: info: ------------------------------ 34ms Mar 26 17:02:46 volumio4 volumio[1312]: info: ------------------------------ 33ms Mar 26 17:02:46 volumio4 volumio5-onboarding[12109]: time=2026-03-26T17:02:46.821+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:02:46.821+01:00 Mar 26 17:02:48 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:48 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:02:48 volumio4 volumio5-onboarding[12109]: time=2026-03-26T17:02:48.136+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:02:48 volumio4 volumio5-onboarding[12109]: time=2026-03-26T17:02:48.156+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:02:48 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:02:48 volumio4 volumio5-onboarding[12109]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:02:48 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:02:48 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:02:48 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 326. Mar 26 17:02:48 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:48 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:48 volumio4 volumio5-onboarding[12150]: time=2026-03-26T17:02:48.513+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:02:48 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:48 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:48 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:48 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:48 volumio4 volumio5-onboarding[12150]: time=2026-03-26T17:02:48.548+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:02:48 volumio4 volumio5-onboarding[12150]: time=2026-03-26T17:02:48.593+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:02:48 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:48 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:48 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:02:48 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:02:48 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:02:48 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:48 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:49 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:49 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:49 volumio4 volumio5-onboarding[12150]: time=2026-03-26T17:02:49.656+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 26 17:02:49 volumio4 volumio5-onboarding[12150]: time=2026-03-26T17:02:49.662+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 26 17:02:49 volumio4 volumio5-onboarding[12150]: time=2026-03-26T17:02:49.662+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 26 17:02:49 volumio4 volumio5-onboarding[12150]: time=2026-03-26T17:02:49.662+01: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" Mar 26 17:02:49 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:49 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:49 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:51 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:51 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:52 volumio4 volumio5-onboarding[12150]: time=2026-03-26T17:02:52.843+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:02:52.843+01:00 Mar 26 17:02:54 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:54 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:54 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:54 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:54 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:54 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:54 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:02:54 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:02:54 volumio4 volumio5-onboarding[12150]: time=2026-03-26T17:02:54.259+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:02:54 volumio4 volumio5-onboarding[12150]: time=2026-03-26T17:02:54.278+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:02:54 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:02:54 volumio4 volumio5-onboarding[12150]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:02:54 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:02:54 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:02:54 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 327. Mar 26 17:02:54 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:54 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:02:54 volumio4 volumio5-onboarding[12178]: time=2026-03-26T17:02:54.783+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:02:54 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:54 volumio4 volumio[1312]: 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: 6 Mar 26 17:02:54 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:54 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:54 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:54 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:54 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:54 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:54 volumio4 volumio5-onboarding[12178]: time=2026-03-26T17:02:54.817+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:02:54 volumio4 volumio5-onboarding[12178]: time=2026-03-26T17:02:54.871+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:02:54 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:54 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:54 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:54 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:54 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:54 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:54 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:02:54 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:02:54 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:02:55 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:02:55 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:02:55 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:55 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:55 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:55 volumio4 volumio[1312]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 26 17:02:56 volumio4 volumio5-onboarding[12178]: time=2026-03-26T17:02:56.013+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 26 17:02:56 volumio4 volumio5-onboarding[12178]: time=2026-03-26T17:02:56.018+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 26 17:02:56 volumio4 volumio5-onboarding[12178]: time=2026-03-26T17:02:56.018+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 26 17:02:56 volumio4 volumio5-onboarding[12178]: time=2026-03-26T17:02:56.018+01: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" Mar 26 17:02:56 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:56 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:56 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:56 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:56 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:57 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:02:57 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:02:58 volumio4 volumio5-onboarding[12178]: time=2026-03-26T17:02:58.432+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:02:58.432+01:00 Mar 26 17:02:59 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:02:59 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:02:59 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:02:59 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:02:59 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:02:59 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:02:59 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:02:59 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:02:59 volumio4 volumio5-onboarding[12178]: time=2026-03-26T17:02:59.840+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:02:59 volumio4 volumio5-onboarding[12178]: time=2026-03-26T17:02:59.860+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:02:59 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:02:59 volumio4 volumio5-onboarding[12178]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:02:59 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:02:59 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:03:00 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 328. Mar 26 17:03:00 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:03:00 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:03:00 volumio4 volumio5-onboarding[12222]: time=2026-03-26T17:03:00.314+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:03:00 volumio4 volumio[1312]: 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: 6 Mar 26 17:03:00 volumio4 volumio[1312]: 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: 6 Mar 26 17:03:00 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:00 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:00 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:00 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:00 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:00 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:00 volumio4 volumio5-onboarding[12222]: time=2026-03-26T17:03:00.350+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:03:00 volumio4 volumio5-onboarding[12222]: time=2026-03-26T17:03:00.411+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:03:00 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:00 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:00 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:00 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:00 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:00 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:00 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:03:00 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:03:00 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:03:00 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:03:00 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:03:00 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:00 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:00 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:02 volumio4 volumio5-onboarding[12222]: time=2026-03-26T17:03:02.004+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 26 17:03:02 volumio4 volumio5-onboarding[12222]: time=2026-03-26T17:03:02.005+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 26 17:03:02 volumio4 volumio5-onboarding[12222]: time=2026-03-26T17:03:02.005+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 26 17:03:02 volumio4 volumio5-onboarding[12222]: time=2026-03-26T17:03:02.005+01: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" Mar 26 17:03:02 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:02 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:02 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:03 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:03 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:03 volumio4 kernel: hwmon hwmon1: Undervoltage detected! Mar 26 17:03:04 volumio4 volumio5-onboarding[12222]: time=2026-03-26T17:03:04.858+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:03:04.858+01:00 Mar 26 17:03:06 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:06 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:06 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:06 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:06 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:06 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:06 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:03:06 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:03:06 volumio4 volumio5-onboarding[12222]: time=2026-03-26T17:03:06.300+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:03:06 volumio4 volumio5-onboarding[12222]: time=2026-03-26T17:03:06.322+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:03:06 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:03:06 volumio4 volumio5-onboarding[12222]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:03:06 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:03:06 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:03:06 volumio4 systemd[1]: volumio5-onboarding.service: Consumed 1.018s CPU time. Mar 26 17:03:06 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 329. Mar 26 17:03:06 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:03:06 volumio4 systemd[1]: volumio5-onboarding.service: Consumed 1.018s CPU time. Mar 26 17:03:06 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:03:06 volumio4 volumio5-onboarding[12250]: time=2026-03-26T17:03:06.784+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:03:06 volumio4 volumio[1312]: 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: 6 Mar 26 17:03:06 volumio4 volumio[1312]: 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: 6 Mar 26 17:03:06 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:06 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:06 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:06 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:06 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:06 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:06 volumio4 volumio5-onboarding[12250]: time=2026-03-26T17:03:06.823+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:03:06 volumio4 volumio5-onboarding[12250]: time=2026-03-26T17:03:06.871+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:03:06 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:06 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:06 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:06 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:06 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:06 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:06 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:03:06 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:03:06 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:03:07 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:03:07 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:03:07 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:07 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:07 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:08 volumio4 kernel: hwmon hwmon1: Voltage normalised Mar 26 17:03:08 volumio4 volumio5-onboarding[12250]: time=2026-03-26T17:03:08.228+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 26 17:03:08 volumio4 volumio5-onboarding[12250]: time=2026-03-26T17:03:08.235+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 26 17:03:08 volumio4 volumio5-onboarding[12250]: time=2026-03-26T17:03:08.235+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 26 17:03:08 volumio4 volumio5-onboarding[12250]: time=2026-03-26T17:03:08.235+01: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" Mar 26 17:03:08 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:08 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:08 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:09 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:09 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:10 volumio4 volumio5-onboarding[12250]: time=2026-03-26T17:03:10.907+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:03:10.907+01:00 Mar 26 17:03:12 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:12 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:12 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:12 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:12 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:12 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:12 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:03:12 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:03:12 volumio4 volumio5-onboarding[12250]: time=2026-03-26T17:03:12.273+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:03:12 volumio4 volumio5-onboarding[12250]: time=2026-03-26T17:03:12.292+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:03:12 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:03:12 volumio4 volumio5-onboarding[12250]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:03:12 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:03:12 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:03:12 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 330. Mar 26 17:03:12 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:03:12 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:03:12 volumio4 volumio5-onboarding[12292]: time=2026-03-26T17:03:12.763+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:03:12 volumio4 volumio[1312]: 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: 6 Mar 26 17:03:12 volumio4 volumio[1312]: 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: 6 Mar 26 17:03:12 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:12 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:12 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:12 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:12 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:12 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:12 volumio4 volumio5-onboarding[12292]: time=2026-03-26T17:03:12.796+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:03:12 volumio4 volumio5-onboarding[12292]: time=2026-03-26T17:03:12.852+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:03:12 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:12 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:12 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:12 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:12 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:12 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:12 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:03:12 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:03:12 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:03:13 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:03:13 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:03:13 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:13 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:13 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:13 volumio4 volumio5-onboarding[12292]: time=2026-03-26T17:03:13.909+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 26 17:03:13 volumio4 volumio5-onboarding[12292]: time=2026-03-26T17:03:13.924+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 26 17:03:13 volumio4 volumio5-onboarding[12292]: time=2026-03-26T17:03:13.924+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 26 17:03:13 volumio4 volumio5-onboarding[12292]: time=2026-03-26T17:03:13.924+01: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" Mar 26 17:03:13 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:13 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:13 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:14 volumio4 kernel: hwmon hwmon1: Undervoltage detected! Mar 26 17:03:14 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:14 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:16 volumio4 volumio5-onboarding[12292]: time=2026-03-26T17:03:16.232+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:03:16.232+01:00 Mar 26 17:03:17 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:17 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:17 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:17 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:17 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:17 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:17 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:03:17 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:03:17 volumio4 volumio5-onboarding[12292]: time=2026-03-26T17:03:17.796+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:03:17 volumio4 volumio5-onboarding[12292]: time=2026-03-26T17:03:17.815+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:03:17 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:03:17 volumio4 volumio5-onboarding[12292]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:03:17 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:03:17 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:03:17 volumio4 systemd[1]: volumio5-onboarding.service: Consumed 1.239s CPU time. Mar 26 17:03:18 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 331. Mar 26 17:03:18 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:03:18 volumio4 systemd[1]: volumio5-onboarding.service: Consumed 1.239s CPU time. Mar 26 17:03:18 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:03:18 volumio4 volumio5-onboarding[12330]: time=2026-03-26T17:03:18.263+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:03:18 volumio4 volumio[1312]: 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: 6 Mar 26 17:03:18 volumio4 volumio[1312]: 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: 6 Mar 26 17:03:18 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:18 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:18 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:18 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:18 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:18 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:18 volumio4 volumio5-onboarding[12330]: time=2026-03-26T17:03:18.298+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:03:18 volumio4 volumio5-onboarding[12330]: time=2026-03-26T17:03:18.352+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:03:18 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:18 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:18 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:18 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:18 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:18 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:18 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:03:18 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:03:18 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:03:18 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:03:18 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:03:18 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:18 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:18 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:19 volumio4 volumio5-onboarding[12330]: time=2026-03-26T17:03:19.599+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 26 17:03:19 volumio4 volumio5-onboarding[12330]: time=2026-03-26T17:03:19.600+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 26 17:03:19 volumio4 volumio5-onboarding[12330]: time=2026-03-26T17:03:19.600+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 26 17:03:19 volumio4 volumio5-onboarding[12330]: time=2026-03-26T17:03:19.600+01: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" Mar 26 17:03:19 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:19 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:19 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:20 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:20 volumio4 kernel: hwmon hwmon1: Voltage normalised Mar 26 17:03:21 volumio4 volumio5-onboarding[12330]: time=2026-03-26T17:03:21.538+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:03:21.538+01:00 Mar 26 17:03:22 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:22 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:22 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:22 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:22 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:22 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:22 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:03:22 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:03:22 volumio4 volumio5-onboarding[12330]: time=2026-03-26T17:03:22.861+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:03:22 volumio4 volumio5-onboarding[12330]: time=2026-03-26T17:03:22.881+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:03:22 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:03:22 volumio4 volumio5-onboarding[12330]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:03:22 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:03:22 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:03:23 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 332. Mar 26 17:03:23 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:03:23 volumio4 volumio[1312]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/ytcr/volumio/bookworm/armhf Mar 26 17:03:23 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:03:23 volumio4 volumio5-onboarding[12356]: time=2026-03-26T17:03:23.286+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:03:23 volumio4 volumio[1312]: 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: 6 Mar 26 17:03:23 volumio4 volumio[1312]: 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: 6 Mar 26 17:03:23 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:23 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:23 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:23 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:23 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:23 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:23 volumio4 volumio5-onboarding[12356]: time=2026-03-26T17:03:23.327+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:03:23 volumio4 volumio5-onboarding[12356]: time=2026-03-26T17:03:23.373+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:03:23 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:23 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:23 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:23 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:23 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:23 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:23 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:03:23 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:03:23 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:03:23 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:03:23 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:03:23 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:23 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:23 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:24 volumio4 volumio5-onboarding[12356]: time=2026-03-26T17:03:24.359+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 26 17:03:24 volumio4 volumio5-onboarding[12356]: time=2026-03-26T17:03:24.360+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 26 17:03:24 volumio4 volumio5-onboarding[12356]: time=2026-03-26T17:03:24.360+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 26 17:03:24 volumio4 volumio5-onboarding[12356]: time=2026-03-26T17:03:24.360+01: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" Mar 26 17:03:24 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:24 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:24 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:25 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:25 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:27 volumio4 volumio5-onboarding[12356]: time=2026-03-26T17:03:27.187+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:03:27.187+01:00 Mar 26 17:03:28 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:28 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:28 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:28 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:28 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:28 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:28 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:03:28 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:03:28 volumio4 volumio5-onboarding[12356]: time=2026-03-26T17:03:28.772+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:03:28 volumio4 volumio5-onboarding[12356]: time=2026-03-26T17:03:28.794+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:03:28 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:03:28 volumio4 volumio5-onboarding[12356]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:03:28 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:03:28 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:03:29 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 333. Mar 26 17:03:29 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:03:29 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:03:29 volumio4 volumio5-onboarding[12398]: time=2026-03-26T17:03:29.297+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:03:29 volumio4 volumio[1312]: 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: 6 Mar 26 17:03:29 volumio4 volumio[1312]: 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: 6 Mar 26 17:03:29 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:29 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:29 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:29 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:29 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:29 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:29 volumio4 volumio5-onboarding[12398]: time=2026-03-26T17:03:29.340+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:03:29 volumio4 volumio[1312]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatest/ytcr/volumio/bookworm/armhf Mar 26 17:03:29 volumio4 volumio[1312]: info: [yt-cast-receiver] Player.reset() Mar 26 17:03:29 volumio4 volumio5-onboarding[12398]: time=2026-03-26T17:03:29.388+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:03:29 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:29 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:29 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:29 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:29 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:29 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:29 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:29 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:03:29 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:03:29 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:03:29 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:03:29 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:03:29 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:29 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:29 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:29 volumio4 volumio[1312]: info: [ytcr] Innertube support service: Stopping service... Mar 26 17:03:29 volumio4 volumio[1312]: info: [ytcr] Innertube support service: Received SIGTERM Mar 26 17:03:29 volumio4 volumio[1312]: info: [ytcr] Innertube support service: Process closed with code 0 Mar 26 17:03:29 volumio4 volumio[1312]: info: [ytcr] Innertube support service: Stopped Mar 26 17:03:29 volumio4 volumio5-onboarding[12398]: time=2026-03-26T17:03:29.781+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 26 17:03:29 volumio4 volumio5-onboarding[12398]: time=2026-03-26T17:03:29.782+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 26 17:03:30 volumio4 volumio5-onboarding[12398]: time=2026-03-26T17:03:30.604+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory" Mar 26 17:03:30 volumio4 volumio5-onboarding[12398]: time=2026-03-26T17:03:30.605+01:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory" Mar 26 17:03:30 volumio4 volumio5-onboarding[12398]: time=2026-03-26T17:03:30.605+01:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory" Mar 26 17:03:30 volumio4 volumio5-onboarding[12398]: time=2026-03-26T17:03:30.605+01: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" Mar 26 17:03:30 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:30 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:30 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:31 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:31 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 26 17:03:32 volumio4 volumio[1312]: info: Check plugin dependencies Mar 26 17:03:32 volumio4 volumio5-onboarding[12398]: time=2026-03-26T17:03:32.647+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 26 17:03:33 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 26 17:03:33 volumio4 volumio5-onboarding[12398]: time=2026-03-26T17:03:33.041+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 26 17:03:33 volumio4 volumio[1312]: info: Rename folder Mar 26 17:03:33 volumio4 kernel: hwmon hwmon1: Undervoltage detected! Mar 26 17:03:33 volumio4 volumio5-onboarding[12398]: time=2026-03-26T17:03:33.082+01:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=4e7SdMw9fqbYNVlFCPN3C1jblSp2 tokenExpiry=2026-03-26T18:03:33.082+01:00 Mar 26 17:03:33 volumio4 volumio[1312]: info: Folder /tmp/downloaded_plugin.zip removed Mar 26 17:03:33 volumio4 volumio5-onboarding[12398]: time=2026-03-26T17:03:33.127+01:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state Mar 26 17:03:33 volumio4 volumio[1312]: info: Move to category Mar 26 17:03:34 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:34 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:34 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:34 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:34 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:34 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:34 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 26 17:03:34 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 26 17:03:34 volumio4 volumio5-onboarding[12398]: time=2026-03-26T17:03:34.682+01:00 level=INFO msg="enabling local network discovery" Mar 26 17:03:34 volumio4 volumio5-onboarding[12398]: time=2026-03-26T17:03:34.720+01:00 level=INFO msg="enabling BLE discovery" Mar 26 17:03:34 volumio4 bluetoothd[983]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 26 17:03:34 volumio4 volumio5-onboarding[12398]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 26 17:03:34 volumio4 systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 26 17:03:34 volumio4 systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 26 17:03:34 volumio4 systemd[1]: volumio5-onboarding.service: Consumed 1.197s CPU time. Mar 26 17:03:35 volumio4 systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 334. Mar 26 17:03:35 volumio4 systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:03:35 volumio4 systemd[1]: volumio5-onboarding.service: Consumed 1.197s CPU time. Mar 26 17:03:35 volumio4 systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 26 17:03:35 volumio4 volumio5-onboarding[12449]: time=2026-03-26T17:03:35.348+01:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 26 17:03:35 volumio4 volumio[1312]: 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: 6 Mar 26 17:03:35 volumio4 volumio[1312]: 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: 6 Mar 26 17:03:35 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:35 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:35 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:35 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:35 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:35 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:35 volumio4 volumio5-onboarding[12449]: time=2026-03-26T17:03:35.427+01:00 level=INFO msg="system info for 1a0c7bf6bc9bbb4e5121560e754b39ff" deviceName=Volumio4 deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 26 17:03:35 volumio4 volumio5-onboarding[12449]: time=2026-03-26T17:03:35.473+01:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 26 17:03:35 volumio4 volumio[1312]: info: Received Get System Info Mar 26 17:03:35 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 26 17:03:35 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 26 17:03:35 volumio4 volumio[1312]: info: Discovery: Getting this device information Mar 26 17:03:35 volumio4 volumio[1312]: info: CoreCommandRouter::volumioGetState Mar 26 17:03:35 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 26 17:03:35 volumio4 volumio-remote-updater[731]: Test mode disabled Mar 26 17:03:35 volumio4 volumio-remote-updater[731]: Alpha mode disabled Mar 26 17:03:35 volumio4 volumio-remote-updater[731]: Alpha legacy test mode disabled Mar 26 17:03:37 volumio4 volumio[1312]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 26 17:03:37 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 26 17:03:37 volumio4 volumio[1312]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 26 17:03:37 volumio4 volumio[1312]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 17:03:37 volumio4 volumio[1312]: TypeError: Cannot read properties of undefined (reading 'plugin_type') Mar 26 17:03:37 volumio4 volumio[1312]: at PluginManager.getInstalledPlugins (/volumio/app/pluginmanager.js:1644:56) Mar 26 17:03:37 volumio4 volumio[1312]: at PluginManager.getAvailablePlugins (/volumio/app/pluginmanager.js:1691:24) Mar 26 17:03:37 volumio4 volumio[1312]: at CoreCommandRouter.getAvailablePlugins (/volumio/app/index.js:1544:29) Mar 26 17:03:37 volumio4 volumio[1312]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1365:45) Mar 26 17:03:37 volumio4 volumio[1312]: at Socket.emit (node:events:514:28) Mar 26 17:03:37 volumio4 volumio[1312]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Mar 26 17:03:37 volumio4 volumio[1312]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Mar 26 17:03:37 volumio4 volumio[1312]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 26 17:03:39 volumio4 sudo[12492]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-26 17:02' Mar 26 17:03:39 volumio4 sudo[12492]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"