Mar 24 22:54:00 volumio volumio5-onboarding[3241]: time=2026-03-24T22:54:00.220+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:54:00.220+03:00 Mar 24 22:54:01 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:01 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:01 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:01 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:54:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:54:01 volumio volumio5-onboarding[3241]: time=2026-03-24T22:54:01.354+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:54:01 volumio volumio5-onboarding[3241]: time=2026-03-24T22:54:01.373+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:54:01 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:54:01 volumio volumio5-onboarding[3241]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:54:01 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:54:01 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:54:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:54:01 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 58. Mar 24 22:54:01 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:01 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:01 volumio volumio5-onboarding[3254]: time=2026-03-24T22:54:01.795+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:54:01 volumio volumio[1208]: 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 24 22:54:01 volumio volumio[1208]: 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 24 22:54:01 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:01 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:01 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:01 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:01 volumio volumio5-onboarding[3254]: time=2026-03-24T22:54:01.862+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:54:01 volumio volumio5-onboarding[3254]: time=2026-03-24T22:54:01.910+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:54:01 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:01 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:01 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:01 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:01 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:54:01 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:54:01 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:54:02 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:54:02 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:54:02 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:02 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:02 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:03 volumio volumio5-onboarding[3254]: time=2026-03-24T22:54:03.035+03: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 24 22:54:03 volumio volumio5-onboarding[3254]: time=2026-03-24T22:54:03.038+03: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 24 22:54:03 volumio volumio5-onboarding[3254]: time=2026-03-24T22:54:03.038+03: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 24 22:54:03 volumio volumio5-onboarding[3254]: time=2026-03-24T22:54:03.038+03: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 24 22:54:03 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:03 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:03 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:03 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:03 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:04 volumio volumio5-onboarding[3254]: time=2026-03-24T22:54:04.922+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:54:04.922+03:00 Mar 24 22:54:05 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:54:06 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:06 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:06 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:06 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:06 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:06 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:06 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:06 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:54:06 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:54:06 volumio volumio5-onboarding[3254]: time=2026-03-24T22:54:06.499+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:54:06 volumio volumio5-onboarding[3254]: time=2026-03-24T22:54:06.534+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:54:06 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:54:06 volumio volumio5-onboarding[3254]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:54:06 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:54:06 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:54:06 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.223s CPU time. Mar 24 22:54:06 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 59. Mar 24 22:54:06 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:06 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.223s CPU time. Mar 24 22:54:06 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:07 volumio volumio5-onboarding[3281]: time=2026-03-24T22:54:07.037+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:54:07 volumio volumio[1208]: 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 24 22:54:07 volumio volumio[1208]: 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 24 22:54:07 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:07 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:07 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:07 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:07 volumio volumio5-onboarding[3281]: time=2026-03-24T22:54:07.106+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:54:07 volumio volumio5-onboarding[3281]: time=2026-03-24T22:54:07.153+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:54:07 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:07 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:07 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:07 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:07 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:54:07 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:54:07 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:54:07 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:54:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:54:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:09 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:54:12 volumio kernel: hwmon hwmon1: Voltage normalised Mar 24 22:54:13 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:54:14 volumio kernel: hwmon hwmon1: Undervoltage detected! Mar 24 22:54:17 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:54:17 volumio volumio5-onboarding[3281]: time=2026-03-24T22:54:17.826+03: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 24 22:54:17 volumio volumio5-onboarding[3281]: time=2026-03-24T22:54:17.836+03: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 24 22:54:17 volumio volumio5-onboarding[3281]: time=2026-03-24T22:54:17.836+03: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 24 22:54:17 volumio volumio5-onboarding[3281]: time=2026-03-24T22:54:17.836+03: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 24 22:54:17 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:17 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:17 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:18 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:18 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:19 volumio volumio5-onboarding[3281]: time=2026-03-24T22:54:19.815+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:54:19.815+03:00 Mar 24 22:54:21 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:21 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:21 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:21 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:54:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:54:21 volumio volumio5-onboarding[3281]: time=2026-03-24T22:54:21.282+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:54:21 volumio volumio5-onboarding[3281]: time=2026-03-24T22:54:21.302+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:54:21 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:54:21 volumio volumio5-onboarding[3281]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:54:21 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:54:21 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:54:21 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.357s CPU time. Mar 24 22:54:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:54:21 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 60. Mar 24 22:54:21 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:21 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.357s CPU time. Mar 24 22:54:21 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:21 volumio volumio5-onboarding[3312]: time=2026-03-24T22:54:21.797+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:54:21 volumio volumio[1208]: 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 24 22:54:21 volumio volumio[1208]: 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 24 22:54:21 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:21 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:21 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:21 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:21 volumio volumio5-onboarding[3312]: time=2026-03-24T22:54:21.863+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:54:21 volumio volumio5-onboarding[3312]: time=2026-03-24T22:54:21.915+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:54:21 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:21 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:21 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:21 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:21 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:54:21 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:54:21 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:54:22 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:54:22 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:54:22 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:22 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:22 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:23 volumio volumio5-onboarding[3312]: time=2026-03-24T22:54:23.628+03: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 24 22:54:23 volumio volumio5-onboarding[3312]: time=2026-03-24T22:54:23.633+03: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 24 22:54:23 volumio volumio5-onboarding[3312]: time=2026-03-24T22:54:23.633+03: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 24 22:54:23 volumio volumio5-onboarding[3312]: time=2026-03-24T22:54:23.633+03: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 24 22:54:23 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:23 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:23 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:24 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:24 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:25 volumio volumio5-onboarding[3312]: time=2026-03-24T22:54:25.238+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:54:25.238+03:00 Mar 24 22:54:25 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:54:26 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:26 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:26 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:26 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:26 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:26 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:26 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:26 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:54:26 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:54:26 volumio volumio5-onboarding[3312]: time=2026-03-24T22:54:26.672+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:54:26 volumio volumio5-onboarding[3312]: time=2026-03-24T22:54:26.709+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:54:26 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:54:26 volumio volumio5-onboarding[3312]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:54:26 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:54:26 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:54:26 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.207s CPU time. Mar 24 22:54:26 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 61. Mar 24 22:54:26 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:26 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.207s CPU time. Mar 24 22:54:27 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:27 volumio volumio5-onboarding[3339]: time=2026-03-24T22:54:27.054+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:54:27 volumio volumio[1208]: 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 24 22:54:27 volumio volumio[1208]: 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 24 22:54:27 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:27 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:27 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:27 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:27 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:27 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:27 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:27 volumio volumio5-onboarding[3339]: time=2026-03-24T22:54:27.120+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:54:27 volumio volumio5-onboarding[3339]: time=2026-03-24T22:54:27.167+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:54:27 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:27 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:27 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:27 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:27 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:27 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:27 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:27 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:54:27 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:54:27 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:54:27 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:54:27 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:54:27 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:27 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:27 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:28 volumio volumio5-onboarding[3339]: time=2026-03-24T22:54:28.362+03: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 24 22:54:28 volumio volumio5-onboarding[3339]: time=2026-03-24T22:54:28.369+03: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 24 22:54:28 volumio volumio5-onboarding[3339]: time=2026-03-24T22:54:28.372+03: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 24 22:54:28 volumio volumio5-onboarding[3339]: time=2026-03-24T22:54:28.372+03: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 24 22:54:28 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:28 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:28 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:28 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:28 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:29 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:54:29 volumio volumio5-onboarding[3339]: time=2026-03-24T22:54:29.832+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:54:29.832+03:00 Mar 24 22:54:30 volumio kernel: hwmon hwmon1: Voltage normalised Mar 24 22:54:30 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:30 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:30 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:30 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:30 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:30 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:30 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:30 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:54:30 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:54:30 volumio volumio5-onboarding[3339]: time=2026-03-24T22:54:30.948+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:54:30 volumio volumio5-onboarding[3339]: time=2026-03-24T22:54:30.967+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:54:31 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:54:31 volumio volumio5-onboarding[3339]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:54:31 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:54:31 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:54:31 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 62. Mar 24 22:54:31 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:31 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:31 volumio volumio5-onboarding[3353]: time=2026-03-24T22:54:31.304+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:54:31 volumio volumio[1208]: 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 24 22:54:31 volumio volumio[1208]: 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 24 22:54:31 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:31 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:31 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:31 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:31 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:31 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:31 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:31 volumio volumio5-onboarding[3353]: time=2026-03-24T22:54:31.369+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:54:31 volumio volumio5-onboarding[3353]: time=2026-03-24T22:54:31.416+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:54:31 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:31 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:31 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:31 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:31 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:31 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:31 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:31 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:54:31 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:54:31 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:54:32 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:54:32 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:54:32 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:32 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:32 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:32 volumio volumio5-onboarding[3353]: time=2026-03-24T22:54:32.557+03: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 24 22:54:32 volumio volumio5-onboarding[3353]: time=2026-03-24T22:54:32.563+03: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 24 22:54:32 volumio volumio5-onboarding[3353]: time=2026-03-24T22:54:32.564+03: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 24 22:54:32 volumio volumio5-onboarding[3353]: time=2026-03-24T22:54:32.564+03: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 24 22:54:32 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:32 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:32 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:32 volumio kernel: hwmon hwmon1: Undervoltage detected! Mar 24 22:54:33 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:33 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:33 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:54:34 volumio volumio5-onboarding[3353]: time=2026-03-24T22:54:34.313+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:54:34.312+03:00 Mar 24 22:54:35 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:35 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:35 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:35 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:35 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:35 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:35 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:35 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:54:35 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:54:35 volumio volumio5-onboarding[3353]: time=2026-03-24T22:54:35.479+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:54:35 volumio volumio5-onboarding[3353]: time=2026-03-24T22:54:35.501+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:54:35 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:54:35 volumio volumio5-onboarding[3353]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:54:35 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:54:35 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:54:35 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.052s CPU time. Mar 24 22:54:35 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 63. Mar 24 22:54:35 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:35 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.052s CPU time. Mar 24 22:54:35 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:35 volumio volumio5-onboarding[3381]: time=2026-03-24T22:54:35.814+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:54:35 volumio volumio[1208]: 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 24 22:54:35 volumio volumio[1208]: 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 24 22:54:35 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:35 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:35 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:35 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:35 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:35 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:35 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:35 volumio volumio5-onboarding[3381]: time=2026-03-24T22:54:35.881+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:54:35 volumio volumio5-onboarding[3381]: time=2026-03-24T22:54:35.934+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:54:35 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:35 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:35 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:35 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:35 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:35 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:35 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:35 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:54:35 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:54:35 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:54:36 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:54:36 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:54:36 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:36 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:36 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:37 volumio volumio5-onboarding[3381]: time=2026-03-24T22:54:37.146+03: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 24 22:54:37 volumio volumio5-onboarding[3381]: time=2026-03-24T22:54:37.152+03: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 24 22:54:37 volumio volumio5-onboarding[3381]: time=2026-03-24T22:54:37.152+03: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 24 22:54:37 volumio volumio5-onboarding[3381]: time=2026-03-24T22:54:37.153+03: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 24 22:54:37 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:37 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:37 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:37 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:54:37 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:37 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:38 volumio volumio5-onboarding[3381]: time=2026-03-24T22:54:38.881+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:54:38.881+03:00 Mar 24 22:54:40 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:40 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:40 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:40 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:40 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:40 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:40 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:40 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:54:40 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:54:40 volumio volumio5-onboarding[3381]: time=2026-03-24T22:54:40.885+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:54:40 volumio volumio5-onboarding[3381]: time=2026-03-24T22:54:40.920+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:54:40 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:54:40 volumio volumio5-onboarding[3381]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:54:41 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:54:41 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:54:41 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.371s CPU time. Mar 24 22:54:41 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 64. Mar 24 22:54:41 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:41 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.371s CPU time. Mar 24 22:54:41 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:41 volumio volumio5-onboarding[3395]: time=2026-03-24T22:54:41.314+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:54:41 volumio volumio[1208]: 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 24 22:54:41 volumio volumio[1208]: 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 24 22:54:41 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:41 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:41 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:41 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:41 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:41 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:41 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:41 volumio volumio5-onboarding[3395]: time=2026-03-24T22:54:41.380+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:54:41 volumio volumio5-onboarding[3395]: time=2026-03-24T22:54:41.429+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:54:41 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:41 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:41 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:41 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:41 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:41 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:41 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:41 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:54:41 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:54:41 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:54:41 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:54:42 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:54:42 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:54:42 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:42 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:42 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:42 volumio volumio5-onboarding[3395]: time=2026-03-24T22:54:42.531+03: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 24 22:54:42 volumio volumio5-onboarding[3395]: time=2026-03-24T22:54:42.533+03: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 24 22:54:42 volumio volumio5-onboarding[3395]: time=2026-03-24T22:54:42.534+03: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 24 22:54:42 volumio volumio5-onboarding[3395]: time=2026-03-24T22:54:42.534+03: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 24 22:54:42 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:42 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:42 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:43 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:43 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:44 volumio volumio5-onboarding[3395]: time=2026-03-24T22:54:44.532+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:54:44.532+03:00 Mar 24 22:54:45 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:54:46 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:46 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:46 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:46 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:46 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:46 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:46 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:46 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:54:46 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:54:46 volumio volumio5-onboarding[3395]: time=2026-03-24T22:54:46.045+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:54:46 volumio volumio5-onboarding[3395]: time=2026-03-24T22:54:46.064+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:54:46 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:54:46 volumio volumio5-onboarding[3395]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:54:46 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:54:46 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:54:46 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.370s CPU time. Mar 24 22:54:46 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 65. Mar 24 22:54:46 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:46 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.370s CPU time. Mar 24 22:54:46 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:46 volumio volumio5-onboarding[3423]: time=2026-03-24T22:54:46.544+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:54:46 volumio volumio[1208]: 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 24 22:54:46 volumio volumio[1208]: 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 24 22:54:46 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:46 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:46 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:46 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:46 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:46 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:46 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:46 volumio volumio5-onboarding[3423]: time=2026-03-24T22:54:46.610+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:54:46 volumio volumio5-onboarding[3423]: time=2026-03-24T22:54:46.659+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:54:46 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:46 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:46 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:46 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:46 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:46 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:46 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:46 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:54:46 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:54:46 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:54:47 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:54:47 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:54:47 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:47 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:47 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:47 volumio volumio5-onboarding[3423]: time=2026-03-24T22:54:47.791+03: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 24 22:54:47 volumio volumio5-onboarding[3423]: time=2026-03-24T22:54:47.793+03: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 24 22:54:47 volumio volumio5-onboarding[3423]: time=2026-03-24T22:54:47.794+03: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 24 22:54:47 volumio volumio5-onboarding[3423]: time=2026-03-24T22:54:47.794+03: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 24 22:54:47 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:47 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:47 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:48 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:48 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:49 volumio volumio5-onboarding[3423]: time=2026-03-24T22:54:49.480+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:54:49.480+03:00 Mar 24 22:54:49 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:54:50 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:50 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:50 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:50 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:50 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:50 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:50 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:50 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:54:50 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:54:50 volumio volumio5-onboarding[3423]: time=2026-03-24T22:54:50.611+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:54:50 volumio volumio5-onboarding[3423]: time=2026-03-24T22:54:50.630+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:54:50 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:54:50 volumio volumio5-onboarding[3423]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:54:50 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:54:50 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:54:50 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.015s CPU time. Mar 24 22:54:50 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 66. Mar 24 22:54:50 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:50 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.015s CPU time. Mar 24 22:54:51 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:51 volumio volumio5-onboarding[3436]: time=2026-03-24T22:54:51.054+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:54:51 volumio volumio[1208]: 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 24 22:54:51 volumio volumio[1208]: 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 24 22:54:51 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:51 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:51 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:51 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:51 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:51 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:51 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:51 volumio volumio5-onboarding[3436]: time=2026-03-24T22:54:51.119+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:54:51 volumio volumio5-onboarding[3436]: time=2026-03-24T22:54:51.168+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:54:51 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:51 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:51 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:51 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:51 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:51 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:51 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:51 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:54:51 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:54:51 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:54:51 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:54:51 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:54:51 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:51 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:51 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:52 volumio volumio5-onboarding[3436]: time=2026-03-24T22:54:52.329+03: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 24 22:54:52 volumio volumio5-onboarding[3436]: time=2026-03-24T22:54:52.332+03: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 24 22:54:52 volumio volumio5-onboarding[3436]: time=2026-03-24T22:54:52.332+03: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 24 22:54:52 volumio volumio5-onboarding[3436]: time=2026-03-24T22:54:52.332+03: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 24 22:54:52 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:52 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:52 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:52 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:52 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:53 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:54:54 volumio volumio5-onboarding[3436]: time=2026-03-24T22:54:54.053+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:54:54.053+03:00 Mar 24 22:54:55 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:55 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:55 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:55 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:55 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:55 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:55 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:55 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:54:55 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:54:55 volumio volumio5-onboarding[3436]: time=2026-03-24T22:54:55.513+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:54:55 volumio volumio5-onboarding[3436]: time=2026-03-24T22:54:55.552+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:54:55 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:54:55 volumio volumio5-onboarding[3436]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:54:55 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:54:55 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:54:55 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.419s CPU time. Mar 24 22:54:55 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 67. Mar 24 22:54:55 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:55 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.419s CPU time. Mar 24 22:54:55 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:54:56 volumio volumio5-onboarding[3465]: time=2026-03-24T22:54:56.034+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:54:56 volumio volumio[1208]: 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 24 22:54:56 volumio volumio[1208]: 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 24 22:54:56 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:56 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:56 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:56 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:56 volumio volumio5-onboarding[3465]: time=2026-03-24T22:54:56.100+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:54:56 volumio volumio5-onboarding[3465]: time=2026-03-24T22:54:56.147+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:54:56 volumio volumio[1208]: info: Received Get System Info Mar 24 22:54:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:54:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:54:56 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:54:56 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:54:56 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:54:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:54:56 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:54:56 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:54:56 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:54:56 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:54:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:54:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:57 volumio volumio5-onboarding[3465]: time=2026-03-24T22:54:57.288+03: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 24 22:54:57 volumio volumio5-onboarding[3465]: time=2026-03-24T22:54:57.292+03: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 24 22:54:57 volumio volumio5-onboarding[3465]: time=2026-03-24T22:54:57.293+03: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 24 22:54:57 volumio volumio5-onboarding[3465]: time=2026-03-24T22:54:57.294+03: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 24 22:54:57 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:57 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:57 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:57 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:54:57 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:54:57 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:54:58 volumio volumio5-onboarding[3465]: time=2026-03-24T22:54:58.927+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:54:58.927+03:00 Mar 24 22:55:00 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:00 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:00 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:00 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:00 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:00 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:00 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:00 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:55:00 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:55:00 volumio volumio5-onboarding[3465]: time=2026-03-24T22:55:00.447+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:55:00 volumio volumio5-onboarding[3465]: time=2026-03-24T22:55:00.482+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:55:00 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:55:00 volumio volumio5-onboarding[3465]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:55:00 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:55:00 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:55:00 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.373s CPU time. Mar 24 22:55:00 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 68. Mar 24 22:55:00 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:00 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.373s CPU time. Mar 24 22:55:00 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:00 volumio volumio5-onboarding[3478]: time=2026-03-24T22:55:00.804+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:55:00 volumio volumio[1208]: 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 24 22:55:00 volumio volumio[1208]: 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 24 22:55:00 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:00 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:00 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:00 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:00 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:00 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:00 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:00 volumio volumio5-onboarding[3478]: time=2026-03-24T22:55:00.874+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:55:00 volumio volumio5-onboarding[3478]: time=2026-03-24T22:55:00.923+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:55:00 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:00 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:00 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:00 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:00 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:00 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:00 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:00 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:55:00 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:55:00 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:55:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:55:01 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:55:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:55:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:01 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:02 volumio volumio5-onboarding[3478]: time=2026-03-24T22:55:02.036+03: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 24 22:55:02 volumio volumio5-onboarding[3478]: time=2026-03-24T22:55:02.037+03: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 24 22:55:02 volumio volumio5-onboarding[3478]: time=2026-03-24T22:55:02.037+03: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 24 22:55:02 volumio volumio5-onboarding[3478]: time=2026-03-24T22:55:02.037+03: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 24 22:55:02 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:02 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:02 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:02 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:02 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:03 volumio volumio5-onboarding[3478]: time=2026-03-24T22:55:03.725+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:55:03.725+03:00 Mar 24 22:55:05 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:05 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:05 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:05 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:05 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:05 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:05 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:05 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:55:05 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:55:05 volumio volumio5-onboarding[3478]: time=2026-03-24T22:55:05.217+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:55:05 volumio volumio5-onboarding[3478]: time=2026-03-24T22:55:05.255+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:55:05 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:55:05 volumio volumio5-onboarding[3478]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:55:05 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:55:05 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:55:05 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.385s CPU time. Mar 24 22:55:05 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:55:05 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 69. Mar 24 22:55:05 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:05 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.385s CPU time. Mar 24 22:55:05 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:05 volumio volumio5-onboarding[3506]: time=2026-03-24T22:55:05.804+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:55:05 volumio volumio[1208]: 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 24 22:55:05 volumio volumio[1208]: 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 24 22:55:05 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:05 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:05 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:05 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:05 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:05 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:05 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:05 volumio volumio5-onboarding[3506]: time=2026-03-24T22:55:05.874+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:55:05 volumio volumio5-onboarding[3506]: time=2026-03-24T22:55:05.921+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:55:05 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:05 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:05 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:05 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:05 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:05 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:05 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:05 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:55:05 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:55:05 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:55:06 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:55:06 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:55:06 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:06 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:06 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:06 volumio volumio5-onboarding[3506]: time=2026-03-24T22:55:06.996+03: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 24 22:55:06 volumio volumio5-onboarding[3506]: time=2026-03-24T22:55:06.997+03: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 24 22:55:06 volumio volumio5-onboarding[3506]: time=2026-03-24T22:55:06.997+03: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 24 22:55:06 volumio volumio5-onboarding[3506]: time=2026-03-24T22:55:06.998+03: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 24 22:55:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:07 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:08 volumio volumio5-onboarding[3506]: time=2026-03-24T22:55:08.667+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:55:08.667+03:00 Mar 24 22:55:09 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:55:10 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:10 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:10 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:10 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:10 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:10 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:10 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:10 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:55:10 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:55:10 volumio volumio5-onboarding[3506]: time=2026-03-24T22:55:10.165+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:55:10 volumio volumio5-onboarding[3506]: time=2026-03-24T22:55:10.200+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:55:10 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:55:10 volumio volumio5-onboarding[3506]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:55:10 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:55:10 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:55:10 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.413s CPU time. Mar 24 22:55:10 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 70. Mar 24 22:55:10 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:10 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.413s CPU time. Mar 24 22:55:10 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:10 volumio volumio5-onboarding[3520]: time=2026-03-24T22:55:10.522+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:55:10 volumio volumio[1208]: 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 24 22:55:10 volumio volumio[1208]: 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 24 22:55:10 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:10 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:10 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:10 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:10 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:10 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:10 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:10 volumio volumio5-onboarding[3520]: time=2026-03-24T22:55:10.578+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:55:10 volumio volumio5-onboarding[3520]: time=2026-03-24T22:55:10.628+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:55:10 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:10 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:10 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:10 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:10 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:10 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:10 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:10 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:55:10 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:55:10 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:55:11 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:55:11 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:55:11 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:11 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:11 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:12 volumio volumio5-onboarding[3520]: time=2026-03-24T22:55:12.465+03: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 24 22:55:12 volumio volumio5-onboarding[3520]: time=2026-03-24T22:55:12.468+03: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 24 22:55:12 volumio volumio5-onboarding[3520]: time=2026-03-24T22:55:12.469+03: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 24 22:55:12 volumio volumio5-onboarding[3520]: time=2026-03-24T22:55:12.469+03: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 24 22:55:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:12 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:13 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:55:14 volumio volumio5-onboarding[3520]: time=2026-03-24T22:55:14.169+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:55:14.169+03:00 Mar 24 22:55:15 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:15 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:15 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:15 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:15 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:15 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:15 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:15 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:55:15 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:55:15 volumio volumio5-onboarding[3520]: time=2026-03-24T22:55:15.624+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:55:15 volumio volumio5-onboarding[3520]: time=2026-03-24T22:55:15.659+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:55:15 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:55:15 volumio volumio5-onboarding[3520]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:55:15 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:55:15 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:55:15 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.355s CPU time. Mar 24 22:55:15 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 71. Mar 24 22:55:15 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:15 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.355s CPU time. Mar 24 22:55:15 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:16 volumio volumio5-onboarding[3549]: time=2026-03-24T22:55:16.035+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:55:16 volumio volumio[1208]: 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 24 22:55:16 volumio volumio[1208]: 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 24 22:55:16 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:16 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:16 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:16 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:16 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:16 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:16 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:16 volumio volumio5-onboarding[3549]: time=2026-03-24T22:55:16.101+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:55:16 volumio volumio5-onboarding[3549]: time=2026-03-24T22:55:16.148+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:55:16 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:16 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:16 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:16 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:16 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:16 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:16 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:16 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:55:16 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:55:16 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:55:16 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:55:16 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:55:16 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:16 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:16 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:17 volumio volumio5-onboarding[3549]: time=2026-03-24T22:55:17.282+03: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 24 22:55:17 volumio volumio5-onboarding[3549]: time=2026-03-24T22:55:17.287+03: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 24 22:55:17 volumio volumio5-onboarding[3549]: time=2026-03-24T22:55:17.290+03: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 24 22:55:17 volumio volumio5-onboarding[3549]: time=2026-03-24T22:55:17.291+03: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 24 22:55:17 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:17 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:17 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:17 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:55:17 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:17 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:18 volumio volumio5-onboarding[3549]: time=2026-03-24T22:55:18.802+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:55:18.802+03:00 Mar 24 22:55:20 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:20 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:20 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:20 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:20 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:20 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:20 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:20 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:55:20 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:55:20 volumio volumio5-onboarding[3549]: time=2026-03-24T22:55:20.286+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:55:20 volumio volumio5-onboarding[3549]: time=2026-03-24T22:55:20.323+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:55:20 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:55:20 volumio volumio5-onboarding[3549]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:55:20 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:55:20 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:55:20 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.287s CPU time. Mar 24 22:55:20 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 72. Mar 24 22:55:20 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:20 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.287s CPU time. Mar 24 22:55:20 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:20 volumio volumio5-onboarding[3563]: time=2026-03-24T22:55:20.785+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:55:20 volumio volumio[1208]: 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 24 22:55:20 volumio volumio[1208]: 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 24 22:55:20 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:20 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:20 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:20 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:20 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:20 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:20 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:20 volumio volumio5-onboarding[3563]: time=2026-03-24T22:55:20.854+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:55:20 volumio volumio5-onboarding[3563]: time=2026-03-24T22:55:20.902+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:55:20 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:20 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:20 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:20 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:20 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:20 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:20 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:20 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:55:20 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:55:20 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:55:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: networkfs , addShare Mar 24 22:55:21 volumio volumio[1208]: info: Adding a new share Mar 24 22:55:21 volumio volumio[1208]: info: No correspondence found in configuration for share Music on IP 192.168.1.11 Mar 24 22:55:21 volumio volumio[1208]: info: Executing SMB command: smbclient --debuglevel=4 -L 192.168.1.11 -N -m SMB3_11 Mar 24 22:55:21 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:55:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:55:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:55:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:21 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:22 volumio volumio[1208]: info: Error browsing device Music for shares: Command failed: smbclient --debuglevel=4 -L 192.168.1.11 -N -m SMB3_11 Mar 24 22:55:22 volumio volumio[1208]: lp_load_ex: refreshing parameters Mar 24 22:55:22 volumio volumio[1208]: Initialising global parameters Mar 24 22:55:22 volumio volumio[1208]: Processing section "[global]" Mar 24 22:55:22 volumio volumio[1208]: doing parameter netbios name = Volumio Mar 24 22:55:22 volumio volumio[1208]: doing parameter server string = Volumio Audiophile Music Player Mar 24 22:55:22 volumio volumio[1208]: doing parameter workgroup = WORKGROUP Mar 24 22:55:22 volumio volumio[1208]: doing parameter security = user Mar 24 22:55:22 volumio volumio[1208]: doing parameter map to guest = Bad User Mar 24 22:55:22 volumio volumio[1208]: doing parameter encrypt passwords = yes Mar 24 22:55:22 volumio volumio[1208]: lpcfg_do_global_parameter: WARNING: The "encrypt passwords" option is deprecated Mar 24 22:55:22 volumio volumio[1208]: doing parameter wins support = yes Mar 24 22:55:22 volumio volumio[1208]: doing parameter local master = no Mar 24 22:55:22 volumio volumio[1208]: doing parameter preferred master = no Mar 24 22:55:22 volumio volumio[1208]: doing parameter os level = 30 Mar 24 22:55:22 volumio volumio[1208]: doing parameter fruit:model = AirPort Mar 24 22:55:22 volumio volumio[1208]: pm_process() returned Yes Mar 24 22:55:22 volumio volumio[1208]: added interface eth0 ip=192.168.1.83 bcast=192.168.1.255 netmask=255.255.255.0 Mar 24 22:55:22 volumio volumio[1208]: Client started (version 4.17.8-Raspbian). Mar 24 22:55:22 volumio volumio[1208]: Connecting to 192.168.1.11 at port 445 Mar 24 22:55:22 volumio volumio[1208]: session request ok Mar 24 22:55:22 volumio volumio[1208]: negotiated dialect[SMB3_11] against server[192.168.1.11] Mar 24 22:55:22 volumio volumio[1208]: GENSEC backend 'gssapi_spnego' registered Mar 24 22:55:22 volumio volumio[1208]: GENSEC backend 'gssapi_krb5' registered Mar 24 22:55:22 volumio volumio[1208]: GENSEC backend 'gssapi_krb5_sasl' registered Mar 24 22:55:22 volumio volumio[1208]: GENSEC backend 'spnego' registered Mar 24 22:55:22 volumio volumio[1208]: GENSEC backend 'schannel' registered Mar 24 22:55:22 volumio volumio[1208]: GENSEC backend 'ncalrpc_as_system' registered Mar 24 22:55:22 volumio volumio[1208]: GENSEC backend 'sasl-EXTERNAL' registered Mar 24 22:55:22 volumio volumio[1208]: GENSEC backend 'ntlmssp' registered Mar 24 22:55:22 volumio volumio[1208]: GENSEC backend 'ntlmssp_resume_ccache' registered Mar 24 22:55:22 volumio volumio[1208]: GENSEC backend 'http_basic' registered Mar 24 22:55:22 volumio volumio[1208]: GENSEC backend 'http_ntlm' registered Mar 24 22:55:22 volumio volumio[1208]: GENSEC backend 'http_negotiate' registered Mar 24 22:55:22 volumio volumio[1208]: GENSEC backend 'krb5' registered Mar 24 22:55:22 volumio volumio[1208]: GENSEC backend 'fake_gssapi_krb5' registered Mar 24 22:55:22 volumio volumio[1208]: Cannot do GSE to an IP address Mar 24 22:55:22 volumio volumio[1208]: Failed to start GENSEC client mech gse_krb5: NT_STATUS_INVALID_PARAMETER Mar 24 22:55:22 volumio volumio[1208]: Got challenge flags: Mar 24 22:55:22 volumio volumio[1208]: Got NTLMSSP neg_flags=0x628a8215 Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_UNICODE Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_REQUEST_TARGET Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_SIGN Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_NTLM Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_TARGET_TYPE_SERVER Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_TARGET_INFO Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_VERSION Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_128 Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_KEY_EXCH Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP: Set final flags: Mar 24 22:55:22 volumio volumio[1208]: Got NTLMSSP neg_flags=0x62008215 Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_UNICODE Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_REQUEST_TARGET Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_SIGN Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_NTLM Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_VERSION Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_128 Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_KEY_EXCH Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP Sign/Seal - Initialising with flags: Mar 24 22:55:22 volumio volumio[1208]: Got NTLMSSP neg_flags=0x62008215 Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_UNICODE Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_REQUEST_TARGET Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_SIGN Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_NTLM Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_VERSION Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_128 Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_KEY_EXCH Mar 24 22:55:22 volumio volumio[1208]: SPNEGO login failed: The attempted logon is invalid. This is either due to a bad username or authentication information. Mar 24 22:55:22 volumio volumio[1208]: Got challenge flags: Mar 24 22:55:22 volumio volumio[1208]: Got NTLMSSP neg_flags=0x628a8215 Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_UNICODE Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_REQUEST_TARGET Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_SIGN Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_NTLM Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_TARGET_TYPE_SERVER Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_TARGET_INFO Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_VERSION Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_128 Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_KEY_EXCH Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP: Set final flags: Mar 24 22:55:22 volumio volumio[1208]: Got NTLMSSP neg_flags=0x62008a15 Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_UNICODE Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_REQUEST_TARGET Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_SIGN Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_NTLM Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_ANONYMOUS Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_VERSION Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_128 Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_KEY_EXCH Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP Sign/Seal - Initialising with flags: Mar 24 22:55:22 volumio volumio[1208]: Got NTLMSSP neg_flags=0x62008a15 Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_UNICODE Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_REQUEST_TARGET Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_SIGN Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_NTLM Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_ANONYMOUS Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_VERSION Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_128 Mar 24 22:55:22 volumio volumio[1208]: NTLMSSP_NEGOTIATE_KEY_EXCH Mar 24 22:55:22 volumio volumio[1208]: SPNEGO login failed: {Access Denied} A process has requested access to an object but has not been granted those access rights. Mar 24 22:55:22 volumio volumio[1208]: info: Detected device Music with version null Mar 24 22:55:22 volumio volumio5-onboarding[3563]: time=2026-03-24T22:55:22.068+03: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 24 22:55:22 volumio volumio5-onboarding[3563]: time=2026-03-24T22:55:22.076+03: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 24 22:55:22 volumio volumio5-onboarding[3563]: time=2026-03-24T22:55:22.076+03: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 24 22:55:22 volumio volumio5-onboarding[3563]: time=2026-03-24T22:55:22.076+03: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 24 22:55:22 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:22 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:22 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:22 volumio sudo[3576]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.11/\\\\DESKTOP-E2SUV15\\Music /mnt/NAS/Music Mar 24 22:55:22 volumio sudo[3576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 22:55:22 volumio kernel: netfs: FS-Cache loaded Mar 24 22:55:22 volumio kernel: Key type cifs.spnego registered Mar 24 22:55:22 volumio kernel: Key type cifs.idmap registered Mar 24 22:55:22 volumio kernel: Malformed UNC in devname Mar 24 22:55:22 volumio kernel: CIFS: VFS: Malformed UNC in devname Mar 24 22:55:22 volumio sudo[3576]: pam_unix(sudo:session): session closed for user root Mar 24 22:55:22 volumio volumio[1208]: info: Error mounting Music on IP 192.168.1.11 : (22): Invalid argument Mar 24 22:55:22 volumio volumio[1208]: Refer to the mount.cifs(8) manual page (e.g. man mount.cifs) and kernel log messages (dmesg) Mar 24 22:55:22 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:22 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:23 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Mar 24 22:55:23 volumio volumio5-onboarding[3563]: time=2026-03-24T22:55:23.946+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:55:23.945+03:00 Mar 24 22:55:25 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:25 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:25 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:25 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:25 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:25 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:25 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:25 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:55:25 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:55:25 volumio volumio5-onboarding[3563]: time=2026-03-24T22:55:25.298+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:55:25 volumio volumio5-onboarding[3563]: time=2026-03-24T22:55:25.318+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:55:25 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:55:25 volumio volumio5-onboarding[3563]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:55:25 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:55:25 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:55:25 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.279s CPU time. Mar 24 22:55:25 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:55:25 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 73. Mar 24 22:55:25 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:25 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.279s CPU time. Mar 24 22:55:25 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:25 volumio volumio5-onboarding[3612]: time=2026-03-24T22:55:25.826+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:55:25 volumio volumio[1208]: 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 24 22:55:25 volumio volumio[1208]: 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 24 22:55:25 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:25 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:25 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:25 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:25 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:25 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:25 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:25 volumio volumio5-onboarding[3612]: time=2026-03-24T22:55:25.891+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:55:25 volumio volumio5-onboarding[3612]: time=2026-03-24T22:55:25.941+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:55:25 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:25 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:25 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:25 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:25 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:25 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:25 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:25 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:55:25 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:55:25 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:55:26 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:55:26 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:55:26 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:26 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:26 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:28 volumio volumio5-onboarding[3612]: time=2026-03-24T22:55:28.842+03: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 24 22:55:28 volumio volumio5-onboarding[3612]: time=2026-03-24T22:55:28.843+03: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 24 22:55:28 volumio volumio5-onboarding[3612]: time=2026-03-24T22:55:28.843+03: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 24 22:55:28 volumio volumio5-onboarding[3612]: time=2026-03-24T22:55:28.844+03: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 24 22:55:28 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:28 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:28 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:29 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:55:29 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:29 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:31 volumio volumio5-onboarding[3612]: time=2026-03-24T22:55:31.258+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:55:31.258+03:00 Mar 24 22:55:32 volumio nmbd[1076]: [2026/03/24 22:55:32.225071, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Mar 24 22:55:32 volumio nmbd[1076]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.83 for name WORKGROUP<1d>. Mar 24 22:55:32 volumio nmbd[1076]: This response was from IP 192.168.1.13, reporting an IP address of 192.168.1.13. Mar 24 22:55:32 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:32 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:32 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:32 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:32 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:32 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:32 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:32 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:55:32 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:55:32 volumio volumio5-onboarding[3612]: time=2026-03-24T22:55:32.747+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:55:32 volumio volumio5-onboarding[3612]: time=2026-03-24T22:55:32.783+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:55:32 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:55:32 volumio volumio5-onboarding[3612]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:55:32 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:55:32 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:55:32 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.353s CPU time. Mar 24 22:55:33 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 74. Mar 24 22:55:33 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:33 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.353s CPU time. Mar 24 22:55:33 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:33 volumio volumio5-onboarding[3626]: time=2026-03-24T22:55:33.285+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:55:33 volumio volumio[1208]: 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 24 22:55:33 volumio volumio[1208]: 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 24 22:55:33 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:33 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:33 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:33 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:33 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:33 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:33 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:33 volumio volumio5-onboarding[3626]: time=2026-03-24T22:55:33.341+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:55:33 volumio volumio5-onboarding[3626]: time=2026-03-24T22:55:33.387+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:55:33 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:33 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:33 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:33 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:33 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:33 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:33 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:33 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:55:33 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:55:33 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:55:33 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:55:34 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:55:34 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:55:34 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:34 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:34 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:34 volumio volumio5-onboarding[3626]: time=2026-03-24T22:55:34.714+03: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 24 22:55:34 volumio volumio5-onboarding[3626]: time=2026-03-24T22:55:34.720+03: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 24 22:55:34 volumio volumio5-onboarding[3626]: time=2026-03-24T22:55:34.720+03: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 24 22:55:34 volumio volumio5-onboarding[3626]: time=2026-03-24T22:55:34.720+03: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 24 22:55:34 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:34 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:34 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:35 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:35 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:36 volumio volumio5-onboarding[3626]: time=2026-03-24T22:55:36.771+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:55:36.771+03:00 Mar 24 22:55:37 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:55:38 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:38 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:38 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:38 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:38 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:38 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:38 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:38 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:55:38 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:55:38 volumio volumio5-onboarding[3626]: time=2026-03-24T22:55:38.228+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:55:38 volumio volumio5-onboarding[3626]: time=2026-03-24T22:55:38.264+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:55:38 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:55:38 volumio volumio5-onboarding[3626]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:55:38 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:55:38 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:55:38 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.353s CPU time. Mar 24 22:55:38 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 75. Mar 24 22:55:38 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:38 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.353s CPU time. Mar 24 22:55:38 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:38 volumio volumio5-onboarding[3655]: time=2026-03-24T22:55:38.794+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:55:38 volumio volumio[1208]: 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 24 22:55:38 volumio volumio[1208]: 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 24 22:55:38 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:38 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:38 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:38 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:38 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:38 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:38 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:38 volumio volumio5-onboarding[3655]: time=2026-03-24T22:55:38.861+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:55:38 volumio volumio5-onboarding[3655]: time=2026-03-24T22:55:38.913+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:55:38 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:38 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:38 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:38 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:38 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:38 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:38 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:38 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:55:38 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:55:38 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:55:39 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:55:39 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:55:39 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:39 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:39 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:40 volumio volumio5-onboarding[3655]: time=2026-03-24T22:55:40.683+03: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 24 22:55:40 volumio volumio5-onboarding[3655]: time=2026-03-24T22:55:40.687+03: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 24 22:55:40 volumio volumio5-onboarding[3655]: time=2026-03-24T22:55:40.687+03: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 24 22:55:40 volumio volumio5-onboarding[3655]: time=2026-03-24T22:55:40.687+03: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 24 22:55:40 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:40 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:40 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:41 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:41 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:41 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:55:42 volumio volumio5-onboarding[3655]: time=2026-03-24T22:55:42.475+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:55:42.475+03:00 Mar 24 22:55:44 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:44 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:44 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:44 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:44 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:44 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:44 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:44 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:55:44 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:55:44 volumio volumio5-onboarding[3655]: time=2026-03-24T22:55:44.153+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:55:44 volumio volumio5-onboarding[3655]: time=2026-03-24T22:55:44.172+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:55:44 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:55:44 volumio volumio5-onboarding[3655]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:55:44 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:55:44 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:55:44 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.346s CPU time. Mar 24 22:55:44 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 76. Mar 24 22:55:44 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:44 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.346s CPU time. Mar 24 22:55:44 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:44 volumio volumio5-onboarding[3682]: time=2026-03-24T22:55:44.554+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:55:44 volumio volumio[1208]: 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 24 22:55:44 volumio volumio[1208]: 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 24 22:55:44 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:44 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:44 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:44 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:44 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:44 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:44 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:44 volumio volumio5-onboarding[3682]: time=2026-03-24T22:55:44.619+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:55:44 volumio volumio5-onboarding[3682]: time=2026-03-24T22:55:44.665+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:55:44 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:44 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:44 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:44 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:44 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:44 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:44 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:44 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:55:44 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:55:44 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:55:45 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:55:45 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:55:45 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:45 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:45 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:45 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:55:45 volumio volumio5-onboarding[3682]: time=2026-03-24T22:55:45.846+03: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 24 22:55:45 volumio volumio5-onboarding[3682]: time=2026-03-24T22:55:45.848+03: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 24 22:55:45 volumio volumio5-onboarding[3682]: time=2026-03-24T22:55:45.849+03: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 24 22:55:45 volumio volumio5-onboarding[3682]: time=2026-03-24T22:55:45.849+03: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 24 22:55:45 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:45 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:45 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:46 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:46 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:47 volumio volumio5-onboarding[3682]: time=2026-03-24T22:55:47.607+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:55:47.607+03:00 Mar 24 22:55:47 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: networkfs , editShare Mar 24 22:55:48 volumio volumio[1208]: info: Share Music successfully unmounted Mar 24 22:55:48 volumio sudo[3694]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.11/\\\\DESKTOP-E2SUV15\\Music /mnt/NAS/Music Mar 24 22:55:48 volumio sudo[3694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 22:55:48 volumio sudo[3694]: pam_unix(sudo:session): session closed for user root Mar 24 22:55:48 volumio kernel: Malformed UNC in devname Mar 24 22:55:48 volumio kernel: CIFS: VFS: Malformed UNC in devname Mar 24 22:55:48 volumio volumio[1208]: info: An error occurred mounting the new share. Rolling back configuration Mar 24 22:55:49 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Mar 24 22:55:49 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:55:49 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:49 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:49 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:49 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:49 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:49 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:49 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:49 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:55:49 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:55:49 volumio volumio5-onboarding[3682]: time=2026-03-24T22:55:49.617+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:55:49 volumio volumio5-onboarding[3682]: time=2026-03-24T22:55:49.651+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:55:49 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:55:49 volumio volumio5-onboarding[3682]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:55:49 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:55:49 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:55:49 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.374s CPU time. Mar 24 22:55:49 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 77. Mar 24 22:55:49 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:49 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.374s CPU time. Mar 24 22:55:50 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:50 volumio volumio5-onboarding[3703]: time=2026-03-24T22:55:50.074+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:55:50 volumio volumio[1208]: 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 24 22:55:50 volumio volumio[1208]: 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 24 22:55:50 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:50 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:50 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:50 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:50 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:50 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:50 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:50 volumio volumio5-onboarding[3703]: time=2026-03-24T22:55:50.140+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:55:50 volumio volumio5-onboarding[3703]: time=2026-03-24T22:55:50.187+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:55:50 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:50 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:50 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:50 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:50 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:50 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:50 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:50 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:55:50 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:55:50 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:55:50 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:55:50 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:55:50 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:50 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:50 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:51 volumio volumio5-onboarding[3703]: time=2026-03-24T22:55:51.673+03: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 24 22:55:51 volumio volumio5-onboarding[3703]: time=2026-03-24T22:55:51.675+03: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 24 22:55:51 volumio volumio5-onboarding[3703]: time=2026-03-24T22:55:51.676+03: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 24 22:55:51 volumio volumio5-onboarding[3703]: time=2026-03-24T22:55:51.676+03: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 24 22:55:51 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:51 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:51 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:52 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:52 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:52 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Mar 24 22:55:53 volumio volumio5-onboarding[3703]: time=2026-03-24T22:55:53.353+03:00 level=INFO msg="authenticated Firebase client" component=volumio/firebase userId=LCOahZPP73c8z3IJvFopsciVoQp1 tokenExpiry=2026-03-24T23:55:53.352+03:00 Mar 24 22:55:53 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:55:54 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:54 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:54 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:54 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:54 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:54 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:54 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:55 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 24 22:55:55 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 24 22:55:55 volumio volumio5-onboarding[3703]: time=2026-03-24T22:55:55.012+03:00 level=INFO msg="enabling local network discovery" Mar 24 22:55:55 volumio volumio5-onboarding[3703]: time=2026-03-24T22:55:55.050+03:00 level=INFO msg="enabling BLE discovery" Mar 24 22:55:55 volumio bluetoothd[935]: src/advertising.c:add_client_complete() Failed to add advertisement: Rejected (0x0b) Mar 24 22:55:55 volumio volumio5-onboarding[3703]: failed to configure discovery: failed to enable BLE discovery: failed to start BLE advertiser: bluetooth: could not start advertisement: Failed to register advertisement Mar 24 22:55:55 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Mar 24 22:55:55 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Mar 24 22:55:55 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.383s CPU time. Mar 24 22:55:55 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 78. Mar 24 22:55:55 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:55 volumio systemd[1]: volumio5-onboarding.service: Consumed 1.383s CPU time. Mar 24 22:55:55 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Mar 24 22:55:55 volumio volumio5-onboarding[3747]: time=2026-03-24T22:55:55.545+03:00 level=INFO msg="running volumio5-device-gateway" version=10ca7e93+CHANGES buildDate=2026-03-06T14:30:20Z Mar 24 22:55:55 volumio volumio[1208]: 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 24 22:55:55 volumio volumio[1208]: 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 24 22:55:55 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:55 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:55 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:55 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:55 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:55 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:55 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:55 volumio volumio5-onboarding[3747]: time=2026-03-24T22:55:55.613+03:00 level=INFO msg="system info for 499b0c6b5afa88429d3d38dc6dcfb39b" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.103 Mar 24 22:55:55 volumio volumio5-onboarding[3747]: time=2026-03-24T22:55:55.661+03:00 level=INFO msg="bootstrapping state" hasInternet=true Mar 24 22:55:55 volumio volumio[1208]: info: Received Get System Info Mar 24 22:55:55 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 22:55:55 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 22:55:55 volumio volumio[1208]: info: Discovery: Getting this device information Mar 24 22:55:55 volumio volumio[1208]: info: CoreCommandRouter::volumioGetState Mar 24 22:55:55 volumio volumio[1208]: info: CorePlayQueue::getTrack 0 Mar 24 22:55:55 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 22:55:55 volumio volumio-remote-updater[718]: Test mode disabled Mar 24 22:55:55 volumio volumio-remote-updater[718]: Alpha mode disabled Mar 24 22:55:55 volumio volumio-remote-updater[718]: Alpha legacy test mode disabled Mar 24 22:55:55 volumio volumio[1208]: info: Disabling MyMusic plugin airplay_emulation Mar 24 22:55:55 volumio volumio[1208]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesShairport-Sync Mar 24 22:55:55 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 22:55:55 volumio volumio[1208]: Cannot find translation for source YouTube2 Mar 24 22:55:55 volumio volumio[1208]: info: Disabling plugin airplay_emulation Mar 24 22:55:55 volumio volumio[1208]: info: Done. Mar 24 22:55:55 volumio sudo[3759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop shairport-sync Mar 24 22:55:55 volumio sudo[3759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 22:55:55 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 22:55:55 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 22:55:55 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 22:55:55 volumio systemd[1]: shairport-sync.service: Consumed 5.079s CPU time. Mar 24 22:55:55 volumio sudo[3759]: pam_unix(sudo:session): session closed for user root Mar 24 22:55:55 volumio volumio[1208]: info: Shairport-Sync Stopped Mar 24 22:55:56 volumio volumio[1208]: info: Disabling MyMusic plugin upnp Mar 24 22:55:56 volumio volumio[1208]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 24 22:55:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 24 22:55:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:56 volumio sudo[3762]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Mar 24 22:55:56 volumio sudo[3762]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 22:55:56 volumio systemd[1]: Stopping upmpdcli.service - UPnP Renderer front-end to MPD... Mar 24 22:55:56 volumio volumio5-onboarding[3747]: time=2026-03-24T22:55:56.873+03: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 24 22:55:56 volumio volumio5-onboarding[3747]: time=2026-03-24T22:55:56.875+03: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 24 22:55:56 volumio volumio5-onboarding[3747]: time=2026-03-24T22:55:56.876+03: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 24 22:55:56 volumio volumio5-onboarding[3747]: time=2026-03-24T22:55:56.876+03: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 24 22:55:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:56 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:57 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 22:55:57 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 22:55:57 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 24 22:55:57 volumio volumio[1208]: info: Enabling MyMusic plugin upnp Mar 24 22:55:57 volumio volumio[1208]: info: Enabling plugin upnp Mar 24 22:55:57 volumio volumio[1208]: info: Loading plugin "upnp"... Mar 24 22:55:57 volumio volumio[1208]: info: [1774382157562] Starting Upmpd Daemon Mar 24 22:55:57 volumio volumio[1208]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 22:55:57 volumio volumio[1208]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 22:55:57 volumio volumio[1208]: Error: listen EADDRINUSE: address already in use :::6599 Mar 24 22:55:57 volumio volumio[1208]: at Server.setupListenHandle [as _listen2] (node:net:1872:16) Mar 24 22:55:57 volumio volumio[1208]: at listenInCluster (node:net:1920:12) Mar 24 22:55:57 volumio volumio[1208]: at Server.listen (node:net:2008:7) Mar 24 22:55:57 volumio volumio[1208]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Mar 24 22:55:57 volumio volumio[1208]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Mar 24 22:55:57 volumio volumio[1208]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Mar 24 22:55:57 volumio volumio[1208]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 24 22:55:57 volumio volumio[1208]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) { Mar 24 22:55:57 volumio volumio[1208]: code: 'EADDRINUSE', Mar 24 22:55:57 volumio volumio[1208]: errno: -98, Mar 24 22:55:57 volumio volumio[1208]: syscall: 'listen', Mar 24 22:55:57 volumio volumio[1208]: address: '::', Mar 24 22:55:57 volumio volumio[1208]: port: 6599 Mar 24 22:55:57 volumio volumio[1208]: } Mar 24 22:55:57 volumio volumio[1208]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 22:55:58 volumio sudo[3778]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 22:54' Mar 24 22:55:58 volumio sudo[3778]: 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"