-- Logs begin at Fri 2026-04-10 16:44:28 +04, end at Fri 2026-04-10 17:27:53 +04. -- Apr 10 17:26:00 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:26:04 volumiohdd volumio[1176]: error: Cannot download Available plugins list: Error: ESOCKETTIMEDOUT Apr 10 17:26:04 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:26:08 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:26:12 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:26:16 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:26:20 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:26:21 volumiohdd volumio5-onboarding[13094]: failed to bootstrap state: failed to get music providers: could not get available plugins: could not get available plugins: context deadline exceeded Apr 10 17:26:21 volumiohdd systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Apr 10 17:26:21 volumiohdd systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Apr 10 17:26:21 volumiohdd systemd[1]: volumio5-onboarding.service: Service RestartSec=100ms expired, scheduling restart. Apr 10 17:26:21 volumiohdd systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 82. Apr 10 17:26:21 volumiohdd systemd[1]: Stopped Volumio5 Onboarding Server. Apr 10 17:26:22 volumiohdd systemd[1]: Started Volumio5 Onboarding Server. Apr 10 17:26:22 volumiohdd volumio5-onboarding[13150]: time=2026-04-10T17:26:22.021+04:00 level=INFO msg="running volumio5-device-gateway" version=687ad144+CHANGES buildDate=2026-02-10T16:50:24Z Apr 10 17:26:22 volumiohdd volumio[1176]: 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 Apr 10 17:26:22 volumiohdd volumio[1176]: 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 Apr 10 17:26:22 volumiohdd volumio5-onboarding[13150]: time=2026-04-10T17:26:22.037+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci0 error="bluetooth: adapter /org/bluez/hci0 does not exist" Apr 10 17:26:22 volumiohdd volumio5-onboarding[13150]: time=2026-04-10T17:26:22.038+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci1 error="bluetooth: adapter /org/bluez/hci1 does not exist" Apr 10 17:26:22 volumiohdd volumio5-onboarding[13150]: time=2026-04-10T17:26:22.039+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci2 error="bluetooth: adapter /org/bluez/hci2 does not exist" Apr 10 17:26:22 volumiohdd volumio5-onboarding[13150]: time=2026-04-10T17:26:22.040+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci3 error="bluetooth: adapter /org/bluez/hci3 does not exist" Apr 10 17:26:22 volumiohdd volumio5-onboarding[13150]: time=2026-04-10T17:26:22.040+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci4 error="bluetooth: adapter /org/bluez/hci4 does not exist" Apr 10 17:26:22 volumiohdd volumio5-onboarding[13150]: time=2026-04-10T17:26:22.040+04:00 level=WARN msg="no Bluetooth adapter found, BLE discovery disabled" Apr 10 17:26:22 volumiohdd volumio[1176]: info: Received Get System Info Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 17:26:22 volumiohdd volumio[1176]: info: Discovery: Getting this device information Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioGetState Apr 10 17:26:22 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 17:26:22 volumiohdd volumio5-onboarding[13150]: time=2026-04-10T17:26:22.043+04:00 level=INFO msg="system info for 8c59d737415fb49491056a7c94aa88bd" deviceName=Volumio_HDD deviceVariant=volumio deviceModel= softwareVersion=3.912 Apr 10 17:26:22 volumiohdd volumio[1176]: info: Received Get System Info Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 17:26:22 volumiohdd volumio[1176]: info: Discovery: Getting this device information Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioGetState Apr 10 17:26:22 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 10 17:26:22 volumiohdd volumio5-onboarding[13150]: time=2026-04-10T17:26:22.049+04:00 level=INFO msg="enabling local network discovery" Apr 10 17:26:22 volumiohdd volumio5-onboarding[13150]: time=2026-04-10T17:26:22.094+04:00 level=INFO msg="bootstrapping state" hasInternet=true Apr 10 17:26:22 volumiohdd volumio[1176]: info: Received Get System Info Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 17:26:22 volumiohdd volumio[1176]: info: Discovery: Getting this device information Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioGetState Apr 10 17:26:22 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 17:26:22 volumiohdd volumio-remote-updater[763]: No test mode Apr 10 17:26:22 volumiohdd volumio-remote-updater[763]: No alpha test mode Apr 10 17:26:22 volumiohdd volumio[1176]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 10 17:26:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 10 17:26:24 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:26:28 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:26:32 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:26:32 volumiohdd volumio[1176]: error: Cannot download Available plugins list: Error: ESOCKETTIMEDOUT Apr 10 17:26:36 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:26:40 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:26:44 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:26:48 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:26:52 volumiohdd volumio5-onboarding[13150]: failed to bootstrap state: failed to get music providers: could not get available plugins: could not get available plugins: context deadline exceeded Apr 10 17:26:52 volumiohdd systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Apr 10 17:26:52 volumiohdd systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Apr 10 17:26:52 volumiohdd systemd[1]: volumio5-onboarding.service: Service RestartSec=100ms expired, scheduling restart. Apr 10 17:26:52 volumiohdd systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 83. Apr 10 17:26:52 volumiohdd systemd[1]: Stopped Volumio5 Onboarding Server. Apr 10 17:26:52 volumiohdd systemd[1]: Started Volumio5 Onboarding Server. Apr 10 17:26:52 volumiohdd volumio5-onboarding[13249]: time=2026-04-10T17:26:52.252+04:00 level=INFO msg="running volumio5-device-gateway" version=687ad144+CHANGES buildDate=2026-02-10T16:50:24Z Apr 10 17:26:52 volumiohdd volumio[1176]: 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 Apr 10 17:26:52 volumiohdd volumio[1176]: 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 Apr 10 17:26:52 volumiohdd volumio5-onboarding[13249]: time=2026-04-10T17:26:52.266+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci0 error="bluetooth: adapter /org/bluez/hci0 does not exist" Apr 10 17:26:52 volumiohdd volumio5-onboarding[13249]: time=2026-04-10T17:26:52.267+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci1 error="bluetooth: adapter /org/bluez/hci1 does not exist" Apr 10 17:26:52 volumiohdd volumio5-onboarding[13249]: time=2026-04-10T17:26:52.268+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci2 error="bluetooth: adapter /org/bluez/hci2 does not exist" Apr 10 17:26:52 volumiohdd volumio5-onboarding[13249]: time=2026-04-10T17:26:52.269+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci3 error="bluetooth: adapter /org/bluez/hci3 does not exist" Apr 10 17:26:52 volumiohdd volumio5-onboarding[13249]: time=2026-04-10T17:26:52.270+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci4 error="bluetooth: adapter /org/bluez/hci4 does not exist" Apr 10 17:26:52 volumiohdd volumio5-onboarding[13249]: time=2026-04-10T17:26:52.270+04:00 level=WARN msg="no Bluetooth adapter found, BLE discovery disabled" Apr 10 17:26:52 volumiohdd volumio[1176]: info: Received Get System Info Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 17:26:52 volumiohdd volumio[1176]: info: Discovery: Getting this device information Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioGetState Apr 10 17:26:52 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 17:26:52 volumiohdd volumio5-onboarding[13249]: time=2026-04-10T17:26:52.273+04:00 level=INFO msg="system info for 8c59d737415fb49491056a7c94aa88bd" deviceName=Volumio_HDD deviceVariant=volumio deviceModel= softwareVersion=3.912 Apr 10 17:26:52 volumiohdd volumio[1176]: info: Received Get System Info Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 17:26:52 volumiohdd volumio[1176]: info: Discovery: Getting this device information Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioGetState Apr 10 17:26:52 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 10 17:26:52 volumiohdd volumio5-onboarding[13249]: time=2026-04-10T17:26:52.278+04:00 level=INFO msg="enabling local network discovery" Apr 10 17:26:52 volumiohdd volumio5-onboarding[13249]: time=2026-04-10T17:26:52.325+04:00 level=INFO msg="bootstrapping state" hasInternet=true Apr 10 17:26:52 volumiohdd volumio[1176]: info: Received Get System Info Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 17:26:52 volumiohdd volumio[1176]: info: Discovery: Getting this device information Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioGetState Apr 10 17:26:52 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 17:26:52 volumiohdd volumio-remote-updater[763]: No test mode Apr 10 17:26:52 volumiohdd volumio-remote-updater[763]: No alpha test mode Apr 10 17:26:52 volumiohdd volumio[1176]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 10 17:26:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:26:56 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:27:00 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:27:03 volumiohdd volumio[1176]: error: Cannot download Available plugins list: Error: ESOCKETTIMEDOUT Apr 10 17:27:04 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:27:08 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand rescan Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:10 volumiohdd volumio[1176]: info: Apr 10 17:27:10 volumiohdd volumio[1176]: ---------------------------- MPD announces state update: update Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand rescan took 8 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::getState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:10 volumiohdd volumio[1176]: info: Apr 10 17:27:10 volumiohdd volumio[1176]: ---------------------------- MPD announces state update: update Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::getState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:10 volumiohdd volumio[1176]: info: Apr 10 17:27:10 volumiohdd volumio[1176]: ---------------------------- MPD announces state update: update Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::getState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand status took 12 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand status took 12 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand status took 11 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand status took 11 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand status took 10 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:10 volumiohdd volumio[1176]: info: Command Router : Notfying DB Updatetrue Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::Close All Modals sent Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:10 volumiohdd volumio[1176]: info: Command Router : Notfying DB Updatetrue Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::Close All Modals sent Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:10 volumiohdd volumio[1176]: info: Command Router : Notfying DB Updatetrue Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::Close All Modals sent Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 17:27:10 volumiohdd volumio[1176]: info: MPD Database updated - AlbumList cache refreshed Apr 10 17:27:10 volumiohdd volumio[1176]: info: Apr 10 17:27:10 volumiohdd volumio[1176]: ---------------------------- MPD announces state update: database Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:10 volumiohdd volumio[1176]: info: Apr 10 17:27:10 volumiohdd volumio[1176]: ---------------------------- MPD announces state update: update Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::getState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::getState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand playlistinfo took 61 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand playlistinfo took 35 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand playlistinfo took 14 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseTrackInfo Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseTrackInfo Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseTrackInfo Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::servicePushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9971,"duration":276,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cantare damore","artist":"Amedeo Minghi","album":null,"uri":"INTERNAL/Amedeo_Minghi_-_Cantare_damore_b128f0d276.mp3","trackType":"mp3"} Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: CURRENT POSITION 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState stateService pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState currentStatus pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::stPlaybackTimer Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::servicePushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9971,"duration":276,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cantare damore","artist":"Amedeo Minghi","album":null,"uri":"INTERNAL/Amedeo_Minghi_-_Cantare_damore_b128f0d276.mp3","trackType":"mp3"} Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: CURRENT POSITION 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState stateService pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState currentStatus pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::stPlaybackTimer Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::servicePushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9971,"duration":276,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cantare damore","artist":"Amedeo Minghi","album":null,"uri":"INTERNAL/Amedeo_Minghi_-_Cantare_damore_b128f0d276.mp3","trackType":"mp3"} Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: CURRENT POSITION 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState stateService pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState currentStatus pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::stPlaybackTimer Apr 10 17:27:10 volumiohdd volumio[1176]: info: ------------------------------ 150ms Apr 10 17:27:10 volumiohdd volumio[1176]: info: ------------------------------ 149ms Apr 10 17:27:10 volumiohdd volumio[1176]: info: ------------------------------ 149ms Apr 10 17:27:10 volumiohdd volumio[1176]: info: MPD Database updated - AlbumList cache refreshed Apr 10 17:27:10 volumiohdd volumio[1176]: info: Apr 10 17:27:10 volumiohdd volumio[1176]: ---------------------------- MPD announces state update: database Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:10 volumiohdd volumio[1176]: info: Apr 10 17:27:10 volumiohdd volumio[1176]: ---------------------------- MPD announces state update: update Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::getState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::getState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:10 volumiohdd volumio[1176]: info: MPD Database updated - AlbumList cache refreshed Apr 10 17:27:10 volumiohdd volumio[1176]: info: Apr 10 17:27:10 volumiohdd volumio[1176]: ---------------------------- MPD announces state update: database Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:10 volumiohdd volumio[1176]: info: Apr 10 17:27:10 volumiohdd volumio[1176]: ---------------------------- MPD announces state update: update Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::getState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::getState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand status took 48 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand status took 45 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand status took 29 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand status took 28 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand status took 29 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:10 volumiohdd volumio[1176]: info: Command Router : Notfying DB Updatefalse Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::Close All Modals sent Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:10 volumiohdd volumio[1176]: info: Command Router : Notfying DB Updatefalse Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::Close All Modals sent Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand status took 91 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand status took 90 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand status took 90 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand playlistinfo took 37 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand playlistinfo took 38 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand playlistinfo took 17 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand playlistinfo took 16 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:10 volumiohdd volumio[1176]: info: Command Router : Notfying DB Updatefalse Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::Close All Modals sent Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseTrackInfo Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseTrackInfo Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::servicePushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9971,"duration":276,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cantare damore","artist":"Amedeo Minghi","album":null,"uri":"INTERNAL/Amedeo_Minghi_-_Cantare_damore_b128f0d276.mp3","trackType":"mp3"} Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: CURRENT POSITION 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState stateService pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState currentStatus pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::stPlaybackTimer Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::servicePushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9971,"duration":276,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cantare damore","artist":"Amedeo Minghi","album":null,"uri":"INTERNAL/Amedeo_Minghi_-_Cantare_damore_b128f0d276.mp3","trackType":"mp3"} Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: CURRENT POSITION 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState stateService pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState currentStatus pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::stPlaybackTimer Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::servicePushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9971,"duration":276,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cantare damore","artist":"Amedeo Minghi","album":null,"uri":"INTERNAL/Amedeo_Minghi_-_Cantare_damore_b128f0d276.mp3","trackType":"mp3"} Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: CURRENT POSITION 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState stateService pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState currentStatus pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::stPlaybackTimer Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::servicePushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9971,"duration":276,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cantare damore","artist":"Amedeo Minghi","album":null,"uri":"INTERNAL/Amedeo_Minghi_-_Cantare_damore_b128f0d276.mp3","trackType":"mp3"} Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: CURRENT POSITION 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState stateService pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState currentStatus pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::stPlaybackTimer Apr 10 17:27:10 volumiohdd volumio[1176]: info: ------------------------------ 148ms Apr 10 17:27:10 volumiohdd volumio[1176]: info: ------------------------------ 149ms Apr 10 17:27:10 volumiohdd volumio[1176]: info: ------------------------------ 130ms Apr 10 17:27:10 volumiohdd volumio[1176]: info: ------------------------------ 131ms Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand playlistinfo took 23 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: info: sendMpdCommand playlistinfo took 22 milliseconds Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseTrackInfo Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: ControllerMpd::parseTrackInfo Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::servicePushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9971,"duration":276,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cantare damore","artist":"Amedeo Minghi","album":null,"uri":"INTERNAL/Amedeo_Minghi_-_Cantare_damore_b128f0d276.mp3","trackType":"mp3"} Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: CURRENT POSITION 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState stateService pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState currentStatus pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::stPlaybackTimer Apr 10 17:27:10 volumiohdd volumio[1176]: info: ControllerMpd::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::servicePushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9971,"duration":276,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cantare damore","artist":"Amedeo Minghi","album":null,"uri":"INTERNAL/Amedeo_Minghi_-_Cantare_damore_b128f0d276.mp3","trackType":"mp3"} Apr 10 17:27:10 volumiohdd volumio[1176]: verbose: CURRENT POSITION 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState stateService pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::syncState currentStatus pause Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::pushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 10 17:27:10 volumiohdd volumio[1176]: info: CoreStateMachine::stPlaybackTimer Apr 10 17:27:10 volumiohdd volumio[1176]: info: ------------------------------ 144ms Apr 10 17:27:10 volumiohdd volumio[1176]: info: ------------------------------ 145ms Apr 10 17:27:12 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:27:16 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand update Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:19 volumiohdd volumio[1176]: info: Apr 10 17:27:19 volumiohdd volumio[1176]: ---------------------------- MPD announces state update: update Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand update took 8 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: info: ControllerMpd::getState Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:19 volumiohdd volumio[1176]: info: Apr 10 17:27:19 volumiohdd volumio[1176]: ---------------------------- MPD announces state update: update Apr 10 17:27:19 volumiohdd volumio[1176]: info: ControllerMpd::getState Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:19 volumiohdd volumio[1176]: info: Apr 10 17:27:19 volumiohdd volumio[1176]: ---------------------------- MPD announces state update: update Apr 10 17:27:19 volumiohdd volumio[1176]: info: ControllerMpd::getState Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:19 volumiohdd volumio[1176]: info: Apr 10 17:27:19 volumiohdd volumio[1176]: ---------------------------- MPD announces state update: update Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand status took 18 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand status took 13 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand status took 11 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand status took 10 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: info: ControllerMpd::getState Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand status took 7 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand status took 5 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:19 volumiohdd volumio[1176]: info: Command Router : Notfying DB Updatetrue Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::Close All Modals sent Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:19 volumiohdd volumio[1176]: info: Command Router : Notfying DB Updatetrue Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::Close All Modals sent Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:19 volumiohdd volumio[1176]: info: Command Router : Notfying DB Updatefalse Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::Close All Modals sent Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:19 volumiohdd volumio[1176]: info: Apr 10 17:27:19 volumiohdd volumio[1176]: ---------------------------- MPD announces state update: update Apr 10 17:27:19 volumiohdd volumio[1176]: info: ControllerMpd::getState Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:19 volumiohdd volumio[1176]: info: Apr 10 17:27:19 volumiohdd volumio[1176]: ---------------------------- MPD announces state update: update Apr 10 17:27:19 volumiohdd volumio[1176]: info: ControllerMpd::getState Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand status Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand status took 86 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand status took 85 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand playlistinfo took 57 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand playlistinfo took 35 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand playlistinfo took 14 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand status took 9 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand status took 3 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand status took 3 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand status took 3 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:19 volumiohdd volumio[1176]: info: Command Router : Notfying DB Updatefalse Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::Close All Modals sent Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::parseTrackInfo Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:19 volumiohdd volumio[1176]: info: Command Router : Notfying DB Updatefalse Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::Close All Modals sent Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:19 volumiohdd volumio[1176]: info: Command Router : Notfying DB Updatefalse Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::Close All Modals sent Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::parseState Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 10 17:27:19 volumiohdd volumio[1176]: info: ControllerMpd::pushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::servicePushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9971,"duration":276,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cantare damore","artist":"Amedeo Minghi","album":null,"uri":"INTERNAL/Amedeo_Minghi_-_Cantare_damore_b128f0d276.mp3","trackType":"mp3"} Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: CURRENT POSITION 1 Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::syncState stateService pause Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::syncState currentStatus pause Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::pushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::stPlaybackTimer Apr 10 17:27:19 volumiohdd volumio[1176]: info: ControllerMpd::pushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::servicePushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9971,"duration":276,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cantare damore","artist":"Amedeo Minghi","album":null,"uri":"INTERNAL/Amedeo_Minghi_-_Cantare_damore_b128f0d276.mp3","trackType":"mp3"} Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: CURRENT POSITION 1 Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::syncState stateService pause Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::syncState currentStatus pause Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::pushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::stPlaybackTimer Apr 10 17:27:19 volumiohdd volumio[1176]: info: ControllerMpd::pushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::servicePushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9971,"duration":276,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cantare damore","artist":"Amedeo Minghi","album":null,"uri":"INTERNAL/Amedeo_Minghi_-_Cantare_damore_b128f0d276.mp3","trackType":"mp3"} Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: CURRENT POSITION 1 Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::syncState stateService pause Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::syncState currentStatus pause Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::pushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::stPlaybackTimer Apr 10 17:27:19 volumiohdd volumio[1176]: info: ------------------------------ 181ms Apr 10 17:27:19 volumiohdd volumio[1176]: info: ------------------------------ 175ms Apr 10 17:27:19 volumiohdd volumio[1176]: info: ------------------------------ 170ms Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand playlistinfo took 61 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand playlistinfo took 40 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: info: sendMpdCommand playlistinfo took 20 milliseconds Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::parseTrackInfo Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::parseTrackInfo Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: ControllerMpd::parseTrackInfo Apr 10 17:27:19 volumiohdd volumio[1176]: info: ControllerMpd::pushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::servicePushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9971,"duration":276,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cantare damore","artist":"Amedeo Minghi","album":null,"uri":"INTERNAL/Amedeo_Minghi_-_Cantare_damore_b128f0d276.mp3","trackType":"mp3"} Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: CURRENT POSITION 1 Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::syncState stateService pause Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::syncState currentStatus pause Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::pushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::stPlaybackTimer Apr 10 17:27:19 volumiohdd volumio[1176]: info: ControllerMpd::pushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::servicePushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9971,"duration":276,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cantare damore","artist":"Amedeo Minghi","album":null,"uri":"INTERNAL/Amedeo_Minghi_-_Cantare_damore_b128f0d276.mp3","trackType":"mp3"} Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: CURRENT POSITION 1 Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::syncState stateService pause Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::syncState currentStatus pause Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::pushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::stPlaybackTimer Apr 10 17:27:19 volumiohdd volumio[1176]: info: ControllerMpd::pushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::servicePushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9971,"duration":276,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Cantare damore","artist":"Amedeo Minghi","album":null,"uri":"INTERNAL/Amedeo_Minghi_-_Cantare_damore_b128f0d276.mp3","trackType":"mp3"} Apr 10 17:27:19 volumiohdd volumio[1176]: verbose: CURRENT POSITION 1 Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::syncState stateService pause Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::syncState currentStatus pause Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::pushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioPushState Apr 10 17:27:19 volumiohdd volumio[1176]: info: CoreStateMachine::stPlaybackTimer Apr 10 17:27:19 volumiohdd volumio[1176]: info: ------------------------------ 182ms Apr 10 17:27:19 volumiohdd volumio[1176]: info: ------------------------------ 105ms Apr 10 17:27:19 volumiohdd volumio[1176]: info: ------------------------------ 99ms Apr 10 17:27:20 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:27:22 volumiohdd volumio5-onboarding[13249]: failed to bootstrap state: failed to get music providers: could not get available plugins: could not get available plugins: context deadline exceeded Apr 10 17:27:22 volumiohdd systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Apr 10 17:27:22 volumiohdd systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Apr 10 17:27:22 volumiohdd systemd[1]: volumio5-onboarding.service: Service RestartSec=100ms expired, scheduling restart. Apr 10 17:27:22 volumiohdd systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 84. Apr 10 17:27:22 volumiohdd systemd[1]: Stopped Volumio5 Onboarding Server. Apr 10 17:27:22 volumiohdd systemd[1]: Started Volumio5 Onboarding Server. Apr 10 17:27:22 volumiohdd volumio5-onboarding[13334]: time=2026-04-10T17:27:22.504+04:00 level=INFO msg="running volumio5-device-gateway" version=687ad144+CHANGES buildDate=2026-02-10T16:50:24Z Apr 10 17:27:22 volumiohdd volumio[1176]: 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 Apr 10 17:27:22 volumiohdd volumio[1176]: 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 Apr 10 17:27:22 volumiohdd volumio5-onboarding[13334]: time=2026-04-10T17:27:22.519+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci0 error="bluetooth: adapter /org/bluez/hci0 does not exist" Apr 10 17:27:22 volumiohdd volumio5-onboarding[13334]: time=2026-04-10T17:27:22.520+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci1 error="bluetooth: adapter /org/bluez/hci1 does not exist" Apr 10 17:27:22 volumiohdd volumio5-onboarding[13334]: time=2026-04-10T17:27:22.521+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci2 error="bluetooth: adapter /org/bluez/hci2 does not exist" Apr 10 17:27:22 volumiohdd volumio5-onboarding[13334]: time=2026-04-10T17:27:22.522+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci3 error="bluetooth: adapter /org/bluez/hci3 does not exist" Apr 10 17:27:22 volumiohdd volumio5-onboarding[13334]: time=2026-04-10T17:27:22.523+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci4 error="bluetooth: adapter /org/bluez/hci4 does not exist" Apr 10 17:27:22 volumiohdd volumio5-onboarding[13334]: time=2026-04-10T17:27:22.523+04:00 level=WARN msg="no Bluetooth adapter found, BLE discovery disabled" Apr 10 17:27:22 volumiohdd volumio[1176]: info: Received Get System Info Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 17:27:22 volumiohdd volumio[1176]: info: Discovery: Getting this device information Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioGetState Apr 10 17:27:22 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 17:27:22 volumiohdd volumio5-onboarding[13334]: time=2026-04-10T17:27:22.526+04:00 level=INFO msg="system info for 8c59d737415fb49491056a7c94aa88bd" deviceName=Volumio_HDD deviceVariant=volumio deviceModel= softwareVersion=3.912 Apr 10 17:27:22 volumiohdd volumio[1176]: info: Received Get System Info Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 17:27:22 volumiohdd volumio[1176]: info: Discovery: Getting this device information Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioGetState Apr 10 17:27:22 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 10 17:27:22 volumiohdd volumio5-onboarding[13334]: time=2026-04-10T17:27:22.531+04:00 level=INFO msg="enabling local network discovery" Apr 10 17:27:22 volumiohdd volumio5-onboarding[13334]: time=2026-04-10T17:27:22.578+04:00 level=INFO msg="bootstrapping state" hasInternet=true Apr 10 17:27:22 volumiohdd volumio[1176]: info: Received Get System Info Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 17:27:22 volumiohdd volumio[1176]: info: Discovery: Getting this device information Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioGetState Apr 10 17:27:22 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 17:27:22 volumiohdd volumio-remote-updater[763]: No test mode Apr 10 17:27:22 volumiohdd volumio-remote-updater[763]: No alpha test mode Apr 10 17:27:22 volumiohdd volumio[1176]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 10 17:27:22 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 10 17:27:24 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 10 17:27:27 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioGetState Apr 10 17:27:27 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:33 volumiohdd volumio[1176]: error: Cannot download Available plugins list: Error: ESOCKETTIMEDOUT Apr 10 17:27:42 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Apr 10 17:27:42 volumiohdd volumio[1176]: info: CURURI: artists:// Apr 10 17:27:42 volumiohdd volumio[1176]: info: Preload queue cleared Apr 10 17:27:52 volumiohdd volumio5-onboarding[13334]: failed to bootstrap state: failed to get music providers: could not get available plugins: could not get available plugins: context deadline exceeded Apr 10 17:27:52 volumiohdd systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=1/FAILURE Apr 10 17:27:52 volumiohdd systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'. Apr 10 17:27:52 volumiohdd systemd[1]: volumio5-onboarding.service: Service RestartSec=100ms expired, scheduling restart. Apr 10 17:27:52 volumiohdd systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 85. Apr 10 17:27:52 volumiohdd systemd[1]: Stopped Volumio5 Onboarding Server. Apr 10 17:27:52 volumiohdd systemd[1]: Started Volumio5 Onboarding Server. Apr 10 17:27:52 volumiohdd volumio5-onboarding[13433]: time=2026-04-10T17:27:52.749+04:00 level=INFO msg="running volumio5-device-gateway" version=687ad144+CHANGES buildDate=2026-02-10T16:50:24Z Apr 10 17:27:52 volumiohdd volumio[1176]: 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 Apr 10 17:27:52 volumiohdd volumio[1176]: 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 Apr 10 17:27:52 volumiohdd volumio5-onboarding[13433]: time=2026-04-10T17:27:52.766+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci0 error="bluetooth: adapter /org/bluez/hci0 does not exist" Apr 10 17:27:52 volumiohdd volumio5-onboarding[13433]: time=2026-04-10T17:27:52.767+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci1 error="bluetooth: adapter /org/bluez/hci1 does not exist" Apr 10 17:27:52 volumiohdd volumio5-onboarding[13433]: time=2026-04-10T17:27:52.768+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci2 error="bluetooth: adapter /org/bluez/hci2 does not exist" Apr 10 17:27:52 volumiohdd volumio5-onboarding[13433]: time=2026-04-10T17:27:52.769+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci3 error="bluetooth: adapter /org/bluez/hci3 does not exist" Apr 10 17:27:52 volumiohdd volumio5-onboarding[13433]: time=2026-04-10T17:27:52.770+04:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci4 error="bluetooth: adapter /org/bluez/hci4 does not exist" Apr 10 17:27:52 volumiohdd volumio5-onboarding[13433]: time=2026-04-10T17:27:52.770+04:00 level=WARN msg="no Bluetooth adapter found, BLE discovery disabled" Apr 10 17:27:52 volumiohdd volumio[1176]: info: Received Get System Info Apr 10 17:27:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 17:27:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 17:27:52 volumiohdd volumio[1176]: info: Discovery: Getting this device information Apr 10 17:27:52 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioGetState Apr 10 17:27:52 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 17:27:52 volumiohdd volumio5-onboarding[13433]: time=2026-04-10T17:27:52.773+04:00 level=INFO msg="system info for 8c59d737415fb49491056a7c94aa88bd" deviceName=Volumio_HDD deviceVariant=volumio deviceModel= softwareVersion=3.912 Apr 10 17:27:52 volumiohdd volumio[1176]: info: Received Get System Info Apr 10 17:27:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 17:27:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 17:27:52 volumiohdd volumio[1176]: info: Discovery: Getting this device information Apr 10 17:27:52 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioGetState Apr 10 17:27:52 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 17:27:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 10 17:27:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 10 17:27:52 volumiohdd volumio5-onboarding[13433]: time=2026-04-10T17:27:52.779+04:00 level=INFO msg="enabling local network discovery" Apr 10 17:27:52 volumiohdd volumio5-onboarding[13433]: time=2026-04-10T17:27:52.825+04:00 level=INFO msg="bootstrapping state" hasInternet=true Apr 10 17:27:52 volumiohdd volumio[1176]: info: Received Get System Info Apr 10 17:27:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 10 17:27:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 10 17:27:52 volumiohdd volumio[1176]: info: Discovery: Getting this device information Apr 10 17:27:52 volumiohdd volumio[1176]: info: CoreCommandRouter::volumioGetState Apr 10 17:27:52 volumiohdd volumio[1176]: info: CorePlayQueue::getTrack 1 Apr 10 17:27:52 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 10 17:27:52 volumiohdd volumio-remote-updater[763]: No test mode Apr 10 17:27:52 volumiohdd volumio-remote-updater[763]: No alpha test mode Apr 10 17:27:53 volumiohdd volumio[1176]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 10 17:27:53 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 10 17:27:53 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 10 17:27:53 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 10 17:27:53 volumiohdd volumio[1176]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 10 17:27:53 volumiohdd volumio[1176]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 10 17:27:53 volumiohdd volumio[1176]: TypeError: Cannot read property 'slice' of null Apr 10 17:27:53 volumiohdd volumio[1176]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Apr 10 17:27:53 volumiohdd volumio[1176]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Apr 10 17:27:53 volumiohdd volumio[1176]: at Object.onceWrapper (events.js:520:26) Apr 10 17:27:53 volumiohdd volumio[1176]: at ClientRequest.emit (events.js:400:28) Apr 10 17:27:53 volumiohdd volumio[1176]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:647:27) Apr 10 17:27:53 volumiohdd volumio[1176]: at HTTPParser.parserOnHeadersComplete (_http_common.js:127:17) Apr 10 17:27:53 volumiohdd volumio[1176]: at TLSSocket.socketOnData (_http_client.js:515:22) Apr 10 17:27:53 volumiohdd volumio[1176]: at TLSSocket.emit (events.js:400:28) Apr 10 17:27:53 volumiohdd volumio[1176]: at addChunk (internal/streams/readable.js:293:12) Apr 10 17:27:53 volumiohdd volumio[1176]: at readableAddChunk (internal/streams/readable.js:267:9) Apr 10 17:27:53 volumiohdd volumio[1176]: at TLSSocket.Readable.push (internal/streams/readable.js:206:10) Apr 10 17:27:53 volumiohdd volumio[1176]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:188:23) Apr 10 17:27:53 volumiohdd volumio[1176]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 10 17:27:53 volumiohdd sudo[13454]: volumio : unable to resolve host volumiohdd Apr 10 17:27:53 volumiohdd sudo[13454]: volumio : problem with defaults entries ; TTY=unknown ; PWD=/ ; USER=root ; Apr 10 17:27:53 volumiohdd sudo[13454]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-04-10 17:26 Apr 10 17:27:53 volumiohdd sudo[13454]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="3dada8b1e619a5feb94867e0865ace17474d7bce" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="30045b259d1a704a832ca7c1460c1fdfa4b723f9" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 05 Mar 2026 09:58:18 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="54b3518c7dd8feba4753e0ad124ce801"