Mar 30 00:37:01 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:01 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:01 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:01 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:01 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:01 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:01 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:01 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:01 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:01 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:03 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:03 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:03 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:03 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:03 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:03 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:03 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:03 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:03 volumio volumio5-onboarding[1910]: time=2026-03-30T00:37:03.191+09:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=wdkNTaHWt1dmIbnsUX9QFt9jfJj2 tokenExpiry=2026-03-30T01:37:03.191+09:00
Mar 30 00:37:04 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:04 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:04 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:04 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:04 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:04 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:04 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:04 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Mar 30 00:37:04 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Mar 30 00:37:04 volumio volumio5-onboarding[1910]: time=2026-03-30T00:37:04.727+09:00 level=INFO msg="enabling local network discovery"
Mar 30 00:37:04 volumio volumio5-onboarding[1910]: time=2026-03-30T00:37:04.773+09:00 level=INFO msg="enabling BLE discovery"
Mar 30 00:37:04 volumio bluetoothd[873]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b)
Mar 30 00:37:04 volumio volumio5-onboarding[1910]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement
Mar 30 00:37:04 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE
Mar 30 00:37:04 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
Mar 30 00:37:04 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 8.
Mar 30 00:37:04 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:37:05 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:37:05 volumio volumio5-onboarding[1951]: time=2026-03-30T00:37:05.230+09:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z
Mar 30 00:37:05 volumio volumio[1231]: 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 30 00:37:05 volumio volumio[1231]: 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 30 00:37:05 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:05 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:05 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:05 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:05 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:05 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:05 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:05 volumio volumio5-onboarding[1951]: time=2026-03-30T00:37:05.367+09:00 level=INFO msg="system info for 6968c06402f27a68f22631ba051bc31f" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103
Mar 30 00:37:05 volumio volumio5-onboarding[1951]: time=2026-03-30T00:37:05.376+09:00 level=INFO msg="bootstrapping state" hasInternet=true
Mar 30 00:37:05 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:05 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:05 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:05 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:05 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:05 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:05 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:05 volumio volumio-remote-updater[676]: Test mode disabled
Mar 30 00:37:05 volumio volumio-remote-updater[676]: Alpha mode disabled
Mar 30 00:37:05 volumio volumio-remote-updater[676]: Alpha legacy test mode disabled
Mar 30 00:37:05 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:05 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:05 volumio volumio[1231]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
- Fix for missing PWM backlight module
- Fix for crash loop on Onboarding plugin
NEW ADDITIONS
- Bump RPi/CM4 kernel to 6.12.74
","title":"Update v4.119","updateavailable":true}
Mar 30 00:37:06 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Mar 30 00:37:06 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:06 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:06 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:09 volumio volumio5-onboarding[1951]: time=2026-03-30T00:37:09.286+09: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 30 00:37:09 volumio volumio5-onboarding[1951]: time=2026-03-30T00:37:09.288+09: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 30 00:37:09 volumio volumio5-onboarding[1951]: time=2026-03-30T00:37:09.288+09: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 30 00:37:09 volumio volumio5-onboarding[1951]: time=2026-03-30T00:37:09.288+09:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=spotify error="could not open plugin config file for \"spop\": open /data/configuration/music_service/spop/config.json: no such file or directory"
Mar 30 00:37:09 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:09 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:09 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:11 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:11 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:12 volumio volumio5-onboarding[1951]: time=2026-03-30T00:37:12.959+09:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=wdkNTaHWt1dmIbnsUX9QFt9jfJj2 tokenExpiry=2026-03-30T01:37:12.959+09:00
Mar 30 00:37:14 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:14 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:14 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:14 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:14 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:14 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:14 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:14 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Mar 30 00:37:14 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Mar 30 00:37:14 volumio volumio5-onboarding[1951]: time=2026-03-30T00:37:14.530+09:00 level=INFO msg="enabling local network discovery"
Mar 30 00:37:14 volumio volumio5-onboarding[1951]: time=2026-03-30T00:37:14.579+09:00 level=INFO msg="enabling BLE discovery"
Mar 30 00:37:14 volumio bluetoothd[873]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b)
Mar 30 00:37:14 volumio volumio5-onboarding[1951]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement
Mar 30 00:37:14 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE
Mar 30 00:37:14 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
Mar 30 00:37:14 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 9.
Mar 30 00:37:14 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:37:15 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:37:15 volumio volumio5-onboarding[1979]: time=2026-03-30T00:37:15.240+09:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z
Mar 30 00:37:15 volumio volumio[1231]: 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 30 00:37:15 volumio volumio[1231]: 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 30 00:37:15 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:15 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:15 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:15 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:15 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:15 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:15 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:15 volumio volumio5-onboarding[1979]: time=2026-03-30T00:37:15.396+09:00 level=INFO msg="system info for 6968c06402f27a68f22631ba051bc31f" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103
Mar 30 00:37:15 volumio volumio5-onboarding[1979]: time=2026-03-30T00:37:15.402+09:00 level=INFO msg="bootstrapping state" hasInternet=true
Mar 30 00:37:15 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:15 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:15 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:15 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:15 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:15 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:15 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:15 volumio volumio-remote-updater[676]: Test mode disabled
Mar 30 00:37:15 volumio volumio-remote-updater[676]: Alpha mode disabled
Mar 30 00:37:15 volumio volumio-remote-updater[676]: Alpha legacy test mode disabled
Mar 30 00:37:16 volumio volumio[1231]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
- Fix for missing PWM backlight module
- Fix for crash loop on Onboarding plugin
NEW ADDITIONS
- Bump RPi/CM4 kernel to 6.12.74
","title":"Update v4.119","updateavailable":true}
Mar 30 00:37:16 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Mar 30 00:37:16 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Mar 30 00:37:16 volumio volumio[1231]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Mar 30 00:37:16 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Mar 30 00:37:16 volumio volumio[1231]: info: Received Get System Version
Mar 30 00:37:16 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 30 00:37:16 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:16 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:16 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:16 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:16 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:16 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:16 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:16 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:16 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:16 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:19 volumio volumio5-onboarding[1979]: time=2026-03-30T00:37:19.302+09: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 30 00:37:19 volumio volumio5-onboarding[1979]: time=2026-03-30T00:37:19.304+09: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 30 00:37:19 volumio volumio5-onboarding[1979]: time=2026-03-30T00:37:19.304+09: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 30 00:37:19 volumio volumio5-onboarding[1979]: time=2026-03-30T00:37:19.304+09:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=spotify error="could not open plugin config file for \"spop\": open /data/configuration/music_service/spop/config.json: no such file or directory"
Mar 30 00:37:19 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:19 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:19 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:21 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:21 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:23 volumio volumio5-onboarding[1979]: time=2026-03-30T00:37:23.221+09:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=wdkNTaHWt1dmIbnsUX9QFt9jfJj2 tokenExpiry=2026-03-30T01:37:23.221+09:00
Mar 30 00:37:24 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:24 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:24 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:24 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:24 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:24 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:24 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:24 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Mar 30 00:37:24 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Mar 30 00:37:24 volumio volumio5-onboarding[1979]: time=2026-03-30T00:37:24.846+09:00 level=INFO msg="enabling local network discovery"
Mar 30 00:37:24 volumio volumio5-onboarding[1979]: time=2026-03-30T00:37:24.901+09:00 level=INFO msg="enabling BLE discovery"
Mar 30 00:37:24 volumio bluetoothd[873]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b)
Mar 30 00:37:24 volumio volumio5-onboarding[1979]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement
Mar 30 00:37:24 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE
Mar 30 00:37:24 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
Mar 30 00:37:25 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 10.
Mar 30 00:37:25 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:37:25 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:37:25 volumio volumio5-onboarding[2006]: time=2026-03-30T00:37:25.571+09:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z
Mar 30 00:37:25 volumio volumio[1231]: 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 30 00:37:25 volumio volumio[1231]: 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 30 00:37:25 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:25 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:25 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:25 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:25 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:25 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:25 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:25 volumio volumio5-onboarding[2006]: time=2026-03-30T00:37:25.705+09:00 level=INFO msg="system info for 6968c06402f27a68f22631ba051bc31f" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103
Mar 30 00:37:25 volumio volumio5-onboarding[2006]: time=2026-03-30T00:37:25.719+09:00 level=INFO msg="bootstrapping state" hasInternet=true
Mar 30 00:37:25 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:25 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:25 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:25 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:25 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:25 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:25 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:25 volumio volumio-remote-updater[676]: Test mode disabled
Mar 30 00:37:25 volumio volumio-remote-updater[676]: Alpha mode disabled
Mar 30 00:37:25 volumio volumio-remote-updater[676]: Alpha legacy test mode disabled
Mar 30 00:37:26 volumio volumio[1231]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
- Fix for missing PWM backlight module
- Fix for crash loop on Onboarding plugin
NEW ADDITIONS
- Bump RPi/CM4 kernel to 6.12.74
","title":"Update v4.119","updateavailable":true}
Mar 30 00:37:26 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Mar 30 00:37:26 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:26 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:26 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:26 volumio volumio[1231]: info: CoreCommandRouter::getUIConfigOnPlugin
Mar 30 00:37:30 volumio volumio5-onboarding[2006]: time=2026-03-30T00:37:30.096+09: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 30 00:37:30 volumio volumio5-onboarding[2006]: time=2026-03-30T00:37:30.099+09: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 30 00:37:30 volumio volumio5-onboarding[2006]: time=2026-03-30T00:37:30.102+09: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 30 00:37:30 volumio volumio5-onboarding[2006]: time=2026-03-30T00:37:30.102+09:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=spotify error="could not open plugin config file for \"spop\": open /data/configuration/music_service/spop/config.json: no such file or directory"
Mar 30 00:37:30 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:30 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:30 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:32 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:32 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:33 volumio volumio5-onboarding[2006]: time=2026-03-30T00:37:33.572+09:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=wdkNTaHWt1dmIbnsUX9QFt9jfJj2 tokenExpiry=2026-03-30T01:37:33.572+09:00
Mar 30 00:37:35 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:35 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:35 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:35 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:35 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:35 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:35 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:35 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Mar 30 00:37:35 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Mar 30 00:37:35 volumio volumio5-onboarding[2006]: time=2026-03-30T00:37:35.306+09:00 level=INFO msg="enabling local network discovery"
Mar 30 00:37:35 volumio volumio5-onboarding[2006]: time=2026-03-30T00:37:35.357+09:00 level=INFO msg="enabling BLE discovery"
Mar 30 00:37:35 volumio bluetoothd[873]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b)
Mar 30 00:37:35 volumio volumio5-onboarding[2006]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement
Mar 30 00:37:35 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE
Mar 30 00:37:35 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
Mar 30 00:37:35 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 11.
Mar 30 00:37:35 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:37:35 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:37:35 volumio volumio5-onboarding[2036]: time=2026-03-30T00:37:35.894+09:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z
Mar 30 00:37:35 volumio volumio[1231]: 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 30 00:37:35 volumio volumio[1231]: 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 30 00:37:35 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:35 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:35 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:35 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:35 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:36 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:36 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:36 volumio volumio5-onboarding[2036]: time=2026-03-30T00:37:36.015+09:00 level=INFO msg="system info for 6968c06402f27a68f22631ba051bc31f" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103
Mar 30 00:37:36 volumio volumio5-onboarding[2036]: time=2026-03-30T00:37:36.026+09:00 level=INFO msg="bootstrapping state" hasInternet=true
Mar 30 00:37:36 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:36 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:36 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:36 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:36 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:36 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:36 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:36 volumio volumio-remote-updater[676]: Test mode disabled
Mar 30 00:37:36 volumio volumio-remote-updater[676]: Alpha mode disabled
Mar 30 00:37:36 volumio volumio-remote-updater[676]: Alpha legacy test mode disabled
Mar 30 00:37:36 volumio volumio[1231]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
- Fix for missing PWM backlight module
- Fix for crash loop on Onboarding plugin
NEW ADDITIONS
- Bump RPi/CM4 kernel to 6.12.74
","title":"Update v4.119","updateavailable":true}
Mar 30 00:37:36 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Mar 30 00:37:36 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:36 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:36 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:39 volumio volumio5-onboarding[2036]: time=2026-03-30T00:37:39.297+09: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 30 00:37:39 volumio volumio5-onboarding[2036]: time=2026-03-30T00:37:39.299+09: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 30 00:37:39 volumio volumio5-onboarding[2036]: time=2026-03-30T00:37:39.299+09: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 30 00:37:39 volumio volumio5-onboarding[2036]: time=2026-03-30T00:37:39.299+09:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=spotify error="could not open plugin config file for \"spop\": open /data/configuration/music_service/spop/config.json: no such file or directory"
Mar 30 00:37:39 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:39 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:39 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:41 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:41 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:43 volumio volumio5-onboarding[2036]: time=2026-03-30T00:37:43.030+09:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=wdkNTaHWt1dmIbnsUX9QFt9jfJj2 tokenExpiry=2026-03-30T01:37:43.030+09:00
Mar 30 00:37:44 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:44 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:44 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:44 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:44 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:44 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:44 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:44 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Mar 30 00:37:44 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Mar 30 00:37:44 volumio volumio5-onboarding[2036]: time=2026-03-30T00:37:44.561+09:00 level=INFO msg="enabling local network discovery"
Mar 30 00:37:44 volumio volumio5-onboarding[2036]: time=2026-03-30T00:37:44.603+09:00 level=INFO msg="enabling BLE discovery"
Mar 30 00:37:44 volumio bluetoothd[873]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b)
Mar 30 00:37:44 volumio volumio5-onboarding[2036]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement
Mar 30 00:37:44 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE
Mar 30 00:37:44 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
Mar 30 00:37:44 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 12.
Mar 30 00:37:44 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:37:45 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:37:45 volumio volumio5-onboarding[2064]: time=2026-03-30T00:37:45.236+09:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z
Mar 30 00:37:45 volumio volumio[1231]: 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 30 00:37:45 volumio volumio[1231]: 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 30 00:37:45 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:45 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:45 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:45 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:45 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:45 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:45 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:45 volumio volumio5-onboarding[2064]: time=2026-03-30T00:37:45.429+09:00 level=INFO msg="system info for 6968c06402f27a68f22631ba051bc31f" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103
Mar 30 00:37:45 volumio volumio5-onboarding[2064]: time=2026-03-30T00:37:45.438+09:00 level=INFO msg="bootstrapping state" hasInternet=true
Mar 30 00:37:45 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:45 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:45 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:45 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:45 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:45 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:45 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:45 volumio volumio-remote-updater[676]: Test mode disabled
Mar 30 00:37:45 volumio volumio-remote-updater[676]: Alpha mode disabled
Mar 30 00:37:45 volumio volumio-remote-updater[676]: Alpha legacy test mode disabled
Mar 30 00:37:46 volumio volumio[1231]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
- Fix for missing PWM backlight module
- Fix for crash loop on Onboarding plugin
NEW ADDITIONS
- Bump RPi/CM4 kernel to 6.12.74
","title":"Update v4.119","updateavailable":true}
Mar 30 00:37:46 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Mar 30 00:37:46 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:46 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:46 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:48 volumio volumio5-onboarding[2064]: time=2026-03-30T00:37:48.618+09: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 30 00:37:48 volumio volumio5-onboarding[2064]: time=2026-03-30T00:37:48.621+09: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 30 00:37:48 volumio volumio5-onboarding[2064]: time=2026-03-30T00:37:48.622+09: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 30 00:37:48 volumio volumio5-onboarding[2064]: time=2026-03-30T00:37:48.622+09:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=spotify error="could not open plugin config file for \"spop\": open /data/configuration/music_service/spop/config.json: no such file or directory"
Mar 30 00:37:48 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:48 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:48 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:50 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:50 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:51 volumio volumio5-onboarding[2064]: time=2026-03-30T00:37:51.672+09:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=wdkNTaHWt1dmIbnsUX9QFt9jfJj2 tokenExpiry=2026-03-30T01:37:51.671+09:00
Mar 30 00:37:53 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:53 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:53 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:53 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:53 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:53 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:53 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:53 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Mar 30 00:37:53 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Mar 30 00:37:53 volumio volumio5-onboarding[2064]: time=2026-03-30T00:37:53.122+09:00 level=INFO msg="enabling local network discovery"
Mar 30 00:37:53 volumio volumio5-onboarding[2064]: time=2026-03-30T00:37:53.166+09:00 level=INFO msg="enabling BLE discovery"
Mar 30 00:37:53 volumio bluetoothd[873]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b)
Mar 30 00:37:53 volumio volumio5-onboarding[2064]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement
Mar 30 00:37:53 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE
Mar 30 00:37:53 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
Mar 30 00:37:53 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 13.
Mar 30 00:37:53 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:37:53 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:37:53 volumio volumio5-onboarding[2091]: time=2026-03-30T00:37:53.678+09:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z
Mar 30 00:37:53 volumio volumio[1231]: 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 30 00:37:53 volumio volumio[1231]: 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 30 00:37:53 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:53 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:53 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:53 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:53 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:53 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:53 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:53 volumio volumio5-onboarding[2091]: time=2026-03-30T00:37:53.810+09:00 level=INFO msg="system info for 6968c06402f27a68f22631ba051bc31f" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103
Mar 30 00:37:53 volumio volumio5-onboarding[2091]: time=2026-03-30T00:37:53.817+09:00 level=INFO msg="bootstrapping state" hasInternet=true
Mar 30 00:37:53 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:37:53 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:37:53 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:37:53 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:37:53 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:37:53 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:37:53 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:37:53 volumio volumio-remote-updater[676]: Test mode disabled
Mar 30 00:37:53 volumio volumio-remote-updater[676]: Alpha mode disabled
Mar 30 00:37:53 volumio volumio-remote-updater[676]: Alpha legacy test mode disabled
Mar 30 00:37:54 volumio volumio[1231]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
- Fix for missing PWM backlight module
- Fix for crash loop on Onboarding plugin
NEW ADDITIONS
- Bump RPi/CM4 kernel to 6.12.74
","title":"Update v4.119","updateavailable":true}
Mar 30 00:37:54 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Mar 30 00:37:54 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:54 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:54 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:56 volumio volumio5-onboarding[2091]: time=2026-03-30T00:37:56.507+09: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 30 00:37:56 volumio volumio5-onboarding[2091]: time=2026-03-30T00:37:56.512+09: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 30 00:37:56 volumio volumio5-onboarding[2091]: time=2026-03-30T00:37:56.513+09: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 30 00:37:56 volumio volumio5-onboarding[2091]: time=2026-03-30T00:37:56.513+09:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=spotify error="could not open plugin config file for \"spop\": open /data/configuration/music_service/spop/config.json: no such file or directory"
Mar 30 00:37:56 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:56 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:56 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:58 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:37:58 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:37:59 volumio volumio5-onboarding[2091]: time=2026-03-30T00:37:59.856+09:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=wdkNTaHWt1dmIbnsUX9QFt9jfJj2 tokenExpiry=2026-03-30T01:37:59.856+09:00
Mar 30 00:38:00 volumio volumio[1231]: info: CALLMETHOD: user_interface peppymeterbasic savepeppy [object Object]
Mar 30 00:38:00 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , savepeppy
Mar 30 00:38:00 volumio volumio[1231]: aaaaaaaaaaa 800,480-test
Mar 30 00:38:00 volumio volumio[1231]: info: PeppyMeterBasic ---800480-test
Mar 30 00:38:00 volumio volumio[1231]: info: PeppyMeterBasic ---800480NaN
Mar 30 00:38:00 volumio volumio[1231]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'then')
Mar 30 00:38:00 volumio volumio[1231]: info: CoreCommandRouter::getUIConfigOnPlugin
Mar 30 00:38:00 volumio volumio[1231]: info: CoreCommandRouter::Close All Modals sent
Mar 30 00:38:01 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:38:01 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:38:01 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:38:01 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:38:01 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:38:01 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:38:01 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:38:01 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Mar 30 00:38:01 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Mar 30 00:38:01 volumio volumio5-onboarding[2091]: time=2026-03-30T00:38:01.389+09:00 level=INFO msg="enabling local network discovery"
Mar 30 00:38:01 volumio volumio5-onboarding[2091]: time=2026-03-30T00:38:01.437+09:00 level=INFO msg="enabling BLE discovery"
Mar 30 00:38:01 volumio bluetoothd[873]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b)
Mar 30 00:38:01 volumio volumio5-onboarding[2091]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement
Mar 30 00:38:01 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE
Mar 30 00:38:01 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
Mar 30 00:38:01 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 14.
Mar 30 00:38:01 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:38:01 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:38:02 volumio volumio5-onboarding[2119]: time=2026-03-30T00:38:02.080+09:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z
Mar 30 00:38:02 volumio volumio[1231]: 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 30 00:38:02 volumio volumio[1231]: 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 30 00:38:02 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:38:02 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:38:02 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:38:02 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:38:02 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:38:02 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:38:02 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:38:02 volumio volumio5-onboarding[2119]: time=2026-03-30T00:38:02.234+09:00 level=INFO msg="system info for 6968c06402f27a68f22631ba051bc31f" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103
Mar 30 00:38:02 volumio volumio5-onboarding[2119]: time=2026-03-30T00:38:02.242+09:00 level=INFO msg="bootstrapping state" hasInternet=true
Mar 30 00:38:02 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:38:02 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:38:02 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:38:02 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:38:02 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:38:02 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:38:02 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:38:02 volumio volumio-remote-updater[676]: Test mode disabled
Mar 30 00:38:02 volumio volumio-remote-updater[676]: Alpha mode disabled
Mar 30 00:38:02 volumio volumio-remote-updater[676]: Alpha legacy test mode disabled
Mar 30 00:38:02 volumio volumio[1231]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
- Fix for missing PWM backlight module
- Fix for crash loop on Onboarding plugin
NEW ADDITIONS
- Bump RPi/CM4 kernel to 6.12.74
","title":"Update v4.119","updateavailable":true}
Mar 30 00:38:02 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Mar 30 00:38:02 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:03 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:03 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:38:05 volumio volumio5-onboarding[2119]: time=2026-03-30T00:38:05.265+09: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 30 00:38:05 volumio volumio5-onboarding[2119]: time=2026-03-30T00:38:05.267+09: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 30 00:38:05 volumio volumio5-onboarding[2119]: time=2026-03-30T00:38:05.267+09: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 30 00:38:05 volumio volumio5-onboarding[2119]: time=2026-03-30T00:38:05.272+09:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=spotify error="could not open plugin config file for \"spop\": open /data/configuration/music_service/spop/config.json: no such file or directory"
Mar 30 00:38:05 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:05 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:05 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:38:07 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:07 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:38:09 volumio volumio5-onboarding[2119]: time=2026-03-30T00:38:09.490+09:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=wdkNTaHWt1dmIbnsUX9QFt9jfJj2 tokenExpiry=2026-03-30T01:38:09.490+09:00
Mar 30 00:38:10 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:38:10 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:38:10 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:38:10 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:38:10 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:38:10 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:38:10 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:38:10 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Mar 30 00:38:10 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Mar 30 00:38:10 volumio volumio5-onboarding[2119]: time=2026-03-30T00:38:10.989+09:00 level=INFO msg="enabling local network discovery"
Mar 30 00:38:11 volumio volumio5-onboarding[2119]: time=2026-03-30T00:38:11.036+09:00 level=INFO msg="enabling BLE discovery"
Mar 30 00:38:11 volumio bluetoothd[873]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b)
Mar 30 00:38:11 volumio volumio5-onboarding[2119]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement
Mar 30 00:38:11 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE
Mar 30 00:38:11 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
Mar 30 00:38:11 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 15.
Mar 30 00:38:11 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:38:11 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:38:11 volumio volumio5-onboarding[2147]: time=2026-03-30T00:38:11.748+09:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z
Mar 30 00:38:11 volumio volumio[1231]: 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 30 00:38:11 volumio volumio[1231]: 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 30 00:38:11 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:38:11 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:38:11 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:38:11 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:38:11 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:38:11 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:38:11 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:38:11 volumio volumio5-onboarding[2147]: time=2026-03-30T00:38:11.931+09:00 level=INFO msg="system info for 6968c06402f27a68f22631ba051bc31f" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103
Mar 30 00:38:11 volumio volumio5-onboarding[2147]: time=2026-03-30T00:38:11.939+09:00 level=INFO msg="bootstrapping state" hasInternet=true
Mar 30 00:38:11 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:38:11 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:38:11 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:38:11 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:38:11 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:38:11 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:38:11 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:38:11 volumio volumio-remote-updater[676]: Test mode disabled
Mar 30 00:38:11 volumio volumio-remote-updater[676]: Alpha mode disabled
Mar 30 00:38:11 volumio volumio-remote-updater[676]: Alpha legacy test mode disabled
Mar 30 00:38:12 volumio volumio[1231]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
- Fix for missing PWM backlight module
- Fix for crash loop on Onboarding plugin
NEW ADDITIONS
- Bump RPi/CM4 kernel to 6.12.74
","title":"Update v4.119","updateavailable":true}
Mar 30 00:38:12 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Mar 30 00:38:12 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:12 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:12 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:38:14 volumio volumio[1231]: info: CALLMETHOD: user_interface peppymeterbasic savepeppy1 [object Object]
Mar 30 00:38:14 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , savepeppy1
Mar 30 00:38:14 volumio volumio[1231]: error: Failed callmethod call: TypeError: Cannot read properties of undefined (reading 'then')
Mar 30 00:38:14 volumio volumio[1231]: info: CoreCommandRouter::getUIConfigOnPlugin
Mar 30 00:38:14 volumio volumio[1231]: info: CoreCommandRouter::Close All Modals sent
Mar 30 00:38:14 volumio sudo[2158]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart peppymeterbasic.service
Mar 30 00:38:14 volumio sudo[2158]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 30 00:38:14 volumio volumio[1231]: info: PeppyMeterBasic -----------------------metervintage
Mar 30 00:38:14 volumio volumio[1231]: info: PeppyMeterBasic -----------------------$basefolder/data/INTERNAL/PeppyMeterBasic/Templates
Mar 30 00:38:14 volumio volumio[1231]: info: PeppyMeterBasic -----------------------screensize800x480-test
Mar 30 00:38:14 volumio volumio[1231]: info: PeppyMeterBasic -----------------------screenwidth800
Mar 30 00:38:14 volumio volumio[1231]: info: PeppyMeterBasic -----------------------screenheight480
Mar 30 00:38:14 volumio volumio[1231]: info: PeppyMeterBasic -----------------------metersize30
Mar 30 00:38:15 volumio systemd[1]: Started peppymeterbasic.service - peppymeterbasic Daemon.
Mar 30 00:38:15 volumio sudo[2158]: pam_unix(sudo:session): session closed for user root
Mar 30 00:38:15 volumio volumio5-onboarding[2147]: time=2026-03-30T00:38:15.200+09: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 30 00:38:15 volumio volumio5-onboarding[2147]: time=2026-03-30T00:38:15.223+09: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 30 00:38:15 volumio volumio5-onboarding[2147]: time=2026-03-30T00:38:15.223+09: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 30 00:38:15 volumio volumio5-onboarding[2147]: time=2026-03-30T00:38:15.223+09:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=spotify error="could not open plugin config file for \"spop\": open /data/configuration/music_service/spop/config.json: no such file or directory"
Mar 30 00:38:15 volumio volumio[1231]: info: peppymeterbasic Daemon Started
Mar 30 00:38:15 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:15 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:15 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:38:15 volumio volumio[1231]: error: PeppyMeterBasic ---Error writing config null
Mar 30 00:38:17 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:17 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:38:19 volumio volumio5-onboarding[2147]: time=2026-03-30T00:38:19.175+09:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=wdkNTaHWt1dmIbnsUX9QFt9jfJj2 tokenExpiry=2026-03-30T01:38:19.175+09:00
Mar 30 00:38:20 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:38:20 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:38:20 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:38:20 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:38:20 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:38:20 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:38:20 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:38:20 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Mar 30 00:38:20 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Mar 30 00:38:20 volumio volumio5-onboarding[2147]: time=2026-03-30T00:38:20.836+09:00 level=INFO msg="enabling local network discovery"
Mar 30 00:38:20 volumio volumio5-onboarding[2147]: time=2026-03-30T00:38:20.883+09:00 level=INFO msg="enabling BLE discovery"
Mar 30 00:38:20 volumio bluetoothd[873]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b)
Mar 30 00:38:21 volumio volumio5-onboarding[2147]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement
Mar 30 00:38:21 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE
Mar 30 00:38:21 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
Mar 30 00:38:21 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 16.
Mar 30 00:38:21 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:38:21 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:38:21 volumio volumio5-onboarding[2180]: time=2026-03-30T00:38:21.434+09:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z
Mar 30 00:38:21 volumio volumio[1231]: 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 30 00:38:21 volumio volumio[1231]: 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 30 00:38:21 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:38:21 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:38:21 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:38:21 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:38:21 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:38:21 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:38:21 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:38:21 volumio volumio5-onboarding[2180]: time=2026-03-30T00:38:21.665+09:00 level=INFO msg="system info for 6968c06402f27a68f22631ba051bc31f" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103
Mar 30 00:38:21 volumio volumio5-onboarding[2180]: time=2026-03-30T00:38:21.673+09:00 level=INFO msg="bootstrapping state" hasInternet=true
Mar 30 00:38:21 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:38:21 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:38:21 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:38:21 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:38:21 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:38:21 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:38:21 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:38:21 volumio volumio-remote-updater[676]: Test mode disabled
Mar 30 00:38:21 volumio volumio-remote-updater[676]: Alpha mode disabled
Mar 30 00:38:21 volumio volumio-remote-updater[676]: Alpha legacy test mode disabled
Mar 30 00:38:22 volumio volumio[1231]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
- Fix for missing PWM backlight module
- Fix for crash loop on Onboarding plugin
NEW ADDITIONS
- Bump RPi/CM4 kernel to 6.12.74
","title":"Update v4.119","updateavailable":true}
Mar 30 00:38:22 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Mar 30 00:38:22 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:22 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:22 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:38:23 volumio volumio[2177]: error: XDG_RUNTIME_DIR is invalid or not set in the environment.
Mar 30 00:38:23 volumio volumio[2177]: failed to open /dev/dri/renderD128: Permission denied
Mar 30 00:38:23 volumio volumio[2177]: pygame 2.1.2 (SDL 2.26.5, Python 3.11.2)
Mar 30 00:38:23 volumio volumio[2177]: Hello from the pygame community. https://www.pygame.org/contribute.html
Mar 30 00:38:23 volumio volumio[2177]: Traceback (most recent call last):
Mar 30 00:38:23 volumio volumio[2177]: File "/data/plugins/user_interface/peppymeterbasic/BasicPeppyMeter/peppymeter.py", line 289, in
Mar 30 00:38:23 volumio volumio[2177]: pm.init_display()
Mar 30 00:38:23 volumio volumio[2177]: File "/data/plugins/user_interface/peppymeterbasic/BasicPeppyMeter/peppymeter.py", line 155, in init_display
Mar 30 00:38:23 volumio volumio[2177]: self.util.PYGAME_SCREEN = pygame.display.set_mode((screen_w, screen_h), pygame.DOUBLEBUF | pygame.NOFRAME, depth)
Mar 30 00:38:23 volumio volumio[2177]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Mar 30 00:38:23 volumio volumio[2177]: pygame.error: EGL not initialized
Mar 30 00:38:25 volumio volumio5-onboarding[2180]: time=2026-03-30T00:38:25.582+09: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 30 00:38:25 volumio volumio5-onboarding[2180]: time=2026-03-30T00:38:25.583+09: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 30 00:38:25 volumio volumio5-onboarding[2180]: time=2026-03-30T00:38:25.584+09: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 30 00:38:25 volumio volumio5-onboarding[2180]: time=2026-03-30T00:38:25.584+09:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=spotify error="could not open plugin config file for \"spop\": open /data/configuration/music_service/spop/config.json: no such file or directory"
Mar 30 00:38:25 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:25 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:25 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:38:27 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:27 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:38:29 volumio volumio5-onboarding[2180]: time=2026-03-30T00:38:29.414+09:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=wdkNTaHWt1dmIbnsUX9QFt9jfJj2 tokenExpiry=2026-03-30T01:38:29.414+09:00
Mar 30 00:38:31 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:38:31 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:38:31 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:38:31 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:38:31 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:38:31 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:38:31 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:38:31 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Mar 30 00:38:31 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Mar 30 00:38:31 volumio volumio5-onboarding[2180]: time=2026-03-30T00:38:31.147+09:00 level=INFO msg="enabling local network discovery"
Mar 30 00:38:31 volumio volumio5-onboarding[2180]: time=2026-03-30T00:38:31.190+09:00 level=INFO msg="enabling BLE discovery"
Mar 30 00:38:31 volumio bluetoothd[873]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b)
Mar 30 00:38:31 volumio volumio5-onboarding[2180]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement
Mar 30 00:38:31 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE
Mar 30 00:38:31 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
Mar 30 00:38:31 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 17.
Mar 30 00:38:31 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:38:31 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:38:31 volumio volumio5-onboarding[2211]: time=2026-03-30T00:38:31.716+09:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z
Mar 30 00:38:31 volumio volumio[1231]: 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 30 00:38:31 volumio volumio[1231]: 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 30 00:38:31 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:38:31 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:38:31 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:38:31 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:38:31 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:38:31 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:38:31 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:38:31 volumio volumio5-onboarding[2211]: time=2026-03-30T00:38:31.845+09:00 level=INFO msg="system info for 6968c06402f27a68f22631ba051bc31f" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103
Mar 30 00:38:31 volumio volumio5-onboarding[2211]: time=2026-03-30T00:38:31.856+09:00 level=INFO msg="bootstrapping state" hasInternet=true
Mar 30 00:38:31 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:38:31 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:38:31 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:38:31 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:38:31 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:38:31 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:38:31 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:38:31 volumio volumio-remote-updater[676]: Test mode disabled
Mar 30 00:38:31 volumio volumio-remote-updater[676]: Alpha mode disabled
Mar 30 00:38:31 volumio volumio-remote-updater[676]: Alpha legacy test mode disabled
Mar 30 00:38:32 volumio volumio[1231]: info: CALLMETHOD: user_interface peppymeterbasic updatelist
Mar 30 00:38:32 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , updatelist
Mar 30 00:38:32 volumio volumio[1231]: info: PeppyMeterBasic --- wget 'https://github.com/balbuze/Meter-peppymeter/raw/main/meterslist.txt'
Mar 30 00:38:33 volumio volumio[1231]: --2026-03-30 00:38:32-- https://github.com/balbuze/Meter-peppymeter/raw/main/meterslist.txt
Mar 30 00:38:33 volumio volumio[1231]: Resolving github.com (github.com)... 20.27.177.113
Mar 30 00:38:33 volumio volumio[1231]: Connecting to github.com (github.com)|20.27.177.113|:443... connected.
Mar 30 00:38:33 volumio volumio[1231]: HTTP request sent, awaiting response... 302 Found
Mar 30 00:38:33 volumio volumio[1231]: Location: https://raw.githubusercontent.com/balbuze/Meter-peppymeter/main/meterslist.txt [following]
Mar 30 00:38:33 volumio volumio[1231]: --2026-03-30 00:38:33-- https://raw.githubusercontent.com/balbuze/Meter-peppymeter/main/meterslist.txt
Mar 30 00:38:33 volumio volumio[1231]: Resolving raw.githubusercontent.com (raw.githubusercontent.com)... 185.199.109.133, 185.199.108.133, 185.199.110.133, ...
Mar 30 00:38:33 volumio volumio[1231]: Connecting to raw.githubusercontent.com (raw.githubusercontent.com)|185.199.109.133|:443... connected.
Mar 30 00:38:33 volumio volumio[1231]: HTTP request sent, awaiting response... 200 OK
Mar 30 00:38:33 volumio volumio[1231]: Length: 362 [text/plain]
Mar 30 00:38:33 volumio volumio[1231]: Saving to: ‘/data/plugins/user_interface/peppymeterbasic/meterslist.txt’
Mar 30 00:38:33 volumio volumio[1231]: 0K 100% 3.31M=0s
Mar 30 00:38:33 volumio volumio[1231]: 2026-03-30 00:38:33 (3.31 MB/s) - ‘/data/plugins/user_interface/peppymeterbasic/meterslist.txt’ saved [362/362]
Mar 30 00:38:33 volumio volumio[1231]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
- Fix for missing PWM backlight module
- Fix for crash loop on Onboarding plugin
NEW ADDITIONS
- Bump RPi/CM4 kernel to 6.12.74
","title":"Update v4.119","updateavailable":true}
Mar 30 00:38:33 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Mar 30 00:38:33 volumio volumio[1231]: info: CoreCommandRouter::getUIConfigOnPlugin
Mar 30 00:38:33 volumio volumio[1231]: info: CoreCommandRouter::Close All Modals sent
Mar 30 00:38:33 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:34 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:34 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:38:36 volumio volumio5-onboarding[2211]: time=2026-03-30T00:38:36.245+09: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 30 00:38:36 volumio volumio5-onboarding[2211]: time=2026-03-30T00:38:36.249+09: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 30 00:38:36 volumio volumio5-onboarding[2211]: time=2026-03-30T00:38:36.249+09: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 30 00:38:36 volumio volumio5-onboarding[2211]: time=2026-03-30T00:38:36.254+09:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=spotify error="could not open plugin config file for \"spop\": open /data/configuration/music_service/spop/config.json: no such file or directory"
Mar 30 00:38:36 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:36 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:36 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:38:38 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 30 00:38:38 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 30 00:38:39 volumio volumio5-onboarding[2211]: time=2026-03-30T00:38:39.395+09:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=wdkNTaHWt1dmIbnsUX9QFt9jfJj2 tokenExpiry=2026-03-30T01:38:39.395+09:00
Mar 30 00:38:41 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:38:41 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:38:41 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:38:41 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:38:41 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:38:41 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:38:41 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:38:41 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Mar 30 00:38:41 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Mar 30 00:38:41 volumio volumio5-onboarding[2211]: time=2026-03-30T00:38:41.419+09:00 level=INFO msg="enabling local network discovery"
Mar 30 00:38:41 volumio volumio5-onboarding[2211]: time=2026-03-30T00:38:41.456+09:00 level=INFO msg="enabling BLE discovery"
Mar 30 00:38:41 volumio bluetoothd[873]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b)
Mar 30 00:38:41 volumio volumio5-onboarding[2211]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement
Mar 30 00:38:41 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE
Mar 30 00:38:41 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
Mar 30 00:38:41 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 18.
Mar 30 00:38:41 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:38:41 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
Mar 30 00:38:41 volumio volumio5-onboarding[2241]: time=2026-03-30T00:38:41.878+09:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z
Mar 30 00:38:41 volumio volumio[1231]: 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 30 00:38:41 volumio volumio[1231]: 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 30 00:38:41 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:38:41 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:38:41 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:38:41 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:38:41 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:38:41 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:38:41 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:38:42 volumio volumio5-onboarding[2241]: time=2026-03-30T00:38:42.056+09:00 level=INFO msg="system info for 6968c06402f27a68f22631ba051bc31f" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103
Mar 30 00:38:42 volumio volumio5-onboarding[2241]: time=2026-03-30T00:38:42.065+09:00 level=INFO msg="bootstrapping state" hasInternet=true
Mar 30 00:38:42 volumio volumio[1231]: info: Received Get System Info
Mar 30 00:38:42 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 30 00:38:42 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 30 00:38:42 volumio volumio[1231]: info: Discovery: Getting this device information
Mar 30 00:38:42 volumio volumio[1231]: info: CoreCommandRouter::volumioGetState
Mar 30 00:38:42 volumio volumio[1231]: info: CorePlayQueue::getTrack 0
Mar 30 00:38:42 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 30 00:38:42 volumio volumio-remote-updater[676]: Test mode disabled
Mar 30 00:38:42 volumio volumio-remote-updater[676]: Alpha mode disabled
Mar 30 00:38:42 volumio volumio-remote-updater[676]: Alpha legacy test mode disabled
Mar 30 00:38:42 volumio volumio[1231]: info: CALLMETHOD: user_interface peppymeterbasic dlmeter [object Object]
Mar 30 00:38:42 volumio volumio[1231]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , dlmeter
Mar 30 00:38:49 volumio volumio[1231]: --2026-03-30 00:38:42-- https://github.com/balbuze/Meter-peppymeter/raw/main/Zipped-folders/Choose
Mar 30 00:38:49 volumio volumio[1231]: Resolving github.com (github.com)... 20.27.177.113
Mar 30 00:38:49 volumio volumio[1231]: Connecting to github.com (github.com)|20.27.177.113|:443... connected.
Mar 30 00:38:49 volumio volumio[1231]: HTTP request sent, awaiting response... 404 Not Found
Mar 30 00:38:49 volumio volumio[1231]: 2026-03-30 00:38:44 ERROR 404: Not Found.
Mar 30 00:38:49 volumio volumio[1231]: --2026-03-30 00:38:44-- http://a/
Mar 30 00:38:49 volumio volumio[1231]: Resolving a (a)... failed: Device or resource busy.
Mar 30 00:38:49 volumio volumio[1231]: wget: unable to resolve host address ‘a’
Mar 30 00:38:49 volumio volumio[1231]: --2026-03-30 00:38:44-- http://packet.zip/
Mar 30 00:38:49 volumio volumio[1231]: Resolving packet.zip (packet.zip)... 162.255.119.167
Mar 30 00:38:49 volumio volumio[1231]: Connecting to packet.zip (packet.zip)|162.255.119.167|:80... connected.
Mar 30 00:38:49 volumio volumio[1231]: HTTP request sent, awaiting response... 302 Found
Mar 30 00:38:49 volumio volumio[1231]: Location: http://www.packet.zip/ [following]
Mar 30 00:38:49 volumio volumio[1231]: --2026-03-30 00:38:44-- http://www.packet.zip/
Mar 30 00:38:49 volumio volumio[1231]: Resolving www.packet.zip (www.packet.zip)... 91.195.240.19
Mar 30 00:38:49 volumio volumio[1231]: Connecting to www.packet.zip (www.packet.zip)|91.195.240.19|:80... connected.
Mar 30 00:38:49 volumio volumio[1231]: HTTP request sent, awaiting response... Read error (Connection reset by peer) in headers.
Mar 30 00:38:49 volumio volumio[1231]: Retrying.
Mar 30 00:38:49 volumio volumio[1231]: --2026-03-30 00:38:46-- (try: 2) http://www.packet.zip/
Mar 30 00:38:49 volumio volumio[1231]: Connecting to www.packet.zip (www.packet.zip)|91.195.240.19|:80... connected.
Mar 30 00:38:49 volumio volumio[1231]: HTTP request sent, awaiting response... Read error (Connection reset by peer) in headers.
Mar 30 00:38:49 volumio volumio[1231]: Retrying.
Mar 30 00:38:49 volumio volumio[1231]: --2026-03-30 00:38:48-- (try: 3) http://www.packet.zip/
Mar 30 00:38:49 volumio volumio[1231]: Connecting to www.packet.zip (www.packet.zip)|91.195.240.19|:80... connected.
Mar 30 00:38:49 volumio volumio[1231]: HTTP request sent, awaiting response... 403 Forbidden
Mar 30 00:38:49 volumio volumio[1231]: 2026-03-30 00:38:49 ERROR 403: Forbidden.
Mar 30 00:38:49 volumio volumio[1231]: error: PeppyMeterBasic --- An error occurs while downloading or installing Meters
Mar 30 00:38:50 volumio volumio[1231]: /bin/rm: cannot remove '/tmp/Choose': No such file or directory
Mar 30 00:38:50 volumio volumio[1231]: /bin/rm: cannot remove 'a': No such file or directory
Mar 30 00:38:50 volumio volumio[1231]: /bin/rm: cannot remove 'packet.zip*': No such file or directory
Mar 30 00:38:50 volumio volumio[1231]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 30 00:38:50 volumio volumio[1231]: Error: Command failed: /bin/rm /tmp/Choose a packet.zip*
Mar 30 00:38:50 volumio volumio[1231]: /bin/rm: cannot remove '/tmp/Choose': No such file or directory
Mar 30 00:38:50 volumio volumio[1231]: /bin/rm: cannot remove 'a': No such file or directory
Mar 30 00:38:50 volumio volumio[1231]: /bin/rm: cannot remove 'packet.zip*': No such file or directory
Mar 30 00:38:50 volumio volumio[1231]: at checkExecSyncError (node:child_process:887:11)
Mar 30 00:38:50 volumio volumio[1231]: at execSync (node:child_process:959:15)
Mar 30 00:38:50 volumio volumio[1231]: at /data/plugins/user_interface/peppymeterbasic/index.js:710:19
Mar 30 00:38:50 volumio volumio[1231]: at new Promise ()
Mar 30 00:38:50 volumio volumio[1231]: at peppymeterbasic.dlmeter (/data/plugins/user_interface/peppymeterbasic/index.js:685:12)
Mar 30 00:38:50 volumio volumio[1231]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32)
Mar 30 00:38:50 volumio volumio[1231]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:337:42)
Mar 30 00:38:50 volumio volumio[1231]: at Socket.emit (node:events:514:28)
Mar 30 00:38:50 volumio volumio[1231]: at /volumio/node_modules/socket.io/lib/socket.js:503:12
Mar 30 00:38:50 volumio volumio[1231]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) {
Mar 30 00:38:50 volumio volumio[1231]: status: 1,
Mar 30 00:38:50 volumio volumio[1231]: signal: null,
Mar 30 00:38:50 volumio volumio[1231]: output: [
Mar 30 00:38:50 volumio volumio[1231]: null,
Mar 30 00:38:50 volumio volumio[1231]: ,
Mar 30 00:38:50 volumio volumio[1231]:
Mar 30 00:38:50 volumio volumio[1231]: ],
Mar 30 00:38:50 volumio volumio[1231]: pid: 2271,
Mar 30 00:38:50 volumio volumio[1231]: stdout: ,
Mar 30 00:38:50 volumio volumio[1231]: stderr:
Mar 30 00:38:50 volumio volumio[1231]: }
Mar 30 00:38:50 volumio volumio[1231]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 30 00:38:58 volumio sudo[2287]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-30 00:37'
Mar 30 00:38:58 volumio sudo[2287]: 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"