Oct 12 15:09:13 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:13.379+07:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=256.934426ms timeout=10s Oct 12 15:09:13 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 15:09:13 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 15:09:13 volumio23 volumio[1329]: info: Discovery: Getting this device information Oct 12 15:09:13 volumio23 volumio[1329]: info: CoreCommandRouter::volumioGetState Oct 12 15:09:13 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:13 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 15:09:13 volumio23 volumio[1329]: verbose: New Socket.io Connection to 192.168.1.123:3000 from 192.168.1.4 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Oct 12 15:09:13 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 15:09:13 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 15:09:13 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:13.614+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=256.934426ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=235.55568ms Oct 12 15:09:13 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:13.649+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=256.934426ms timeout=10s endpoint=https://www.googleapis.com duration=268.904266ms Oct 12 15:09:13 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:13.712+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=256.934426ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=333.538512ms Oct 12 15:09:13 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:13.738+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=256.934426ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=359.371584ms Oct 12 15:09:13 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:13.746+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=256.934426ms timeout=10s endpoint=https://securetoken.googleapis.com duration=365.786588ms Oct 12 15:09:13 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:13.750+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=256.934426ms timeout=10s endpoint=https://google.com duration=371.17573ms Oct 12 15:09:13 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:13.875+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=256.934426ms timeout=10s endpoint=https://functions.volumio.cloud duration=495.822235ms Oct 12 15:09:13 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:13.883+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=256.934426ms timeout=10s endpoint=https://functions.volumio.cloud duration=503.446528ms Oct 12 15:09:13 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:13.889+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=256.934426ms timeout=10s endpoint=http://pushupdates.volumio.org duration=509.974051ms Oct 12 15:09:13 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:13.963+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=256.934426ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=582.874226ms Oct 12 15:09:14 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:14.282+07:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=256.934426ms timeout=10s endpoint=http://cddb.volumio.org duration=903.508547ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 12 15:09:14 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:14.284+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=256.934426ms timeout=10s endpoint=https://database.volumio.cloud duration=904.268276ms Oct 12 15:09:14 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:14.332+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=256.934426ms timeout=10s endpoint=http://plugins.volumio.org duration=951.586177ms Oct 12 15:09:16 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 12 15:09:16 volumio23 volumio[1329]: info: CURURI: music-library/USB/MUZIK Oct 12 15:09:16 volumio23 volumio[1329]: info: Preload queue cleared Oct 12 15:09:21 volumio23 volumio[1329]: info: Preload queue cleared Oct 12 15:09:21 volumio23 volumio[1329]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 12 15:09:21 volumio23 volumio[1329]: info: CoreStateMachine::ClearQueue Oct 12 15:09:21 volumio23 volumio[1329]: info: CoreStateMachine::stop Oct 12 15:09:21 volumio23 volumio[1329]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 15:09:21 volumio23 volumio[1329]: info: CorePlayQueue::clearPlayQueue Oct 12 15:09:21 volumio23 volumio[1329]: info: CorePlayQueue::saveQueue Oct 12 15:09:21 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushQueue Oct 12 15:09:21 volumio23 volumio[1329]: info: CoreStateMachine::addQueueItems Oct 12 15:09:21 volumio23 volumio[1329]: info: CorePlayQueue::addQueueItems Oct 12 15:09:21 volumio23 volumio[1329]: info: Preload queue cleared Oct 12 15:09:21 volumio23 volumio[1329]: info: Adding Item to queue: music-library/USB/MUZIK/Focal JMlab 1 Oct 12 15:09:21 volumio23 volumio[1329]: info: Exploding uri music-library/USB/MUZIK/Focal JMlab 1 in service mpd Oct 12 15:09:22 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Juniot%20Wells/Focal%20Demo-Disc%20Nr.1/large&path=%2Fmnt%2FUSB%2FMUZIK%2FFocal%20JMlab%201%2F1%20-%20Sweet%20Sixteen.wav&metadata=false Oct 12 15:09:22 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav Oct 12 15:09:22 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Jeannie%20Bryson/Focal%20Demo-Disc%20Nr.1/large&path=%2Fmnt%2FUSB%2FMUZIK%2FFocal%20JMlab%201%2F10%20-%20Fever.wav&metadata=false Oct 12 15:09:22 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Focal JMlab 1/10 - Fever.wav Oct 12 15:09:22 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Rebecca%20Pidgeon/Focal%20Demo-Disc%20Nr.1/large&path=%2Fmnt%2FUSB%2FMUZIK%2FFocal%20JMlab%201%2F11%20-%20Spanish%20Harlem.wav&metadata=false Oct 12 15:09:22 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Focal JMlab 1/11 - Spanish Harlem.wav Oct 12 15:09:22 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Livingston%20Taylor/Focal%20Demo-Disc%20Nr.1/large&path=%2Fmnt%2FUSB%2FMUZIK%2FFocal%20JMlab%201%2F12%20-%20Grandma%C2%B4s%20Hands.wav&metadata=false Oct 12 15:09:22 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Focal JMlab 1/12 - Grandma´s Hands.wav Oct 12 15:09:22 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Henry%20Mancini/Focal%20Demo-Disc%20Nr.1/large&path=%2Fmnt%2FUSB%2FMUZIK%2FFocal%20JMlab%201%2F13%20-%20Pink%20Panther.wav&metadata=false Oct 12 15:09:22 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Focal JMlab 1/13 - Pink Panther.wav Oct 12 15:09:22 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Guiseppe%20Verdi/Focal%20Demo-Disc%20Nr.1/large&path=%2Fmnt%2FUSB%2FMUZIK%2FFocal%20JMlab%201%2F14%20-%20Requiem%20Dies%20Irae.wav&metadata=false Oct 12 15:09:22 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Focal JMlab 1/14 - Requiem Dies Irae.wav Oct 12 15:09:22 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Guiseppe%20Verdi/Focal%20Demo-Disc%20Nr.1/large&path=%2Fmnt%2FUSB%2FMUZIK%2FFocal%20JMlab%201%2F15%20-%20La%20Donna%20E%20Mobile.wav&metadata=false Oct 12 15:09:22 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Focal JMlab 1/15 - La Donna E Mobile.wav Oct 12 15:09:22 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Antonio%20Vivaldi/Focal%20Demo-Disc%20Nr.1/large&path=%2Fmnt%2FUSB%2FMUZIK%2FFocal%20JMlab%201%2F16%20-%20Flute%20Concerto%20In%20D.wav&metadata=false Oct 12 15:09:22 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Focal JMlab 1/16 - Flute Concerto In D.wav Oct 12 15:09:22 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Michael%20Ruff/Focal%20Demo-Disc%20Nr.1/large&path=%2Fmnt%2FUSB%2FMUZIK%2FFocal%20JMlab%201%2F2%20-%20Wishing%20Well.wav&metadata=false Oct 12 15:09:22 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Focal JMlab 1/2 - Wishing Well.wav Oct 12 15:09:22 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Harvey%20Mandel/Focal%20Demo-Disc%20Nr.1/large&path=%2Fmnt%2FUSB%2FMUZIK%2FFocal%20JMlab%201%2F3%20-%20Tears%20For%20Eric.wav&metadata=false Oct 12 15:09:22 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Focal JMlab 1/3 - Tears For Eric.wav Oct 12 15:09:22 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Thom%20Rotella/Focal%20Demo-Disc%20Nr.1/large&path=%2Fmnt%2FUSB%2FMUZIK%2FFocal%20JMlab%201%2F4%20-%20Naima.wav&metadata=false Oct 12 15:09:22 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Focal JMlab 1/4 - Naima.wav Oct 12 15:09:22 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=James%20Nowton%20Howard/Focal%20Demo-Disc%20Nr.1/large&path=%2Fmnt%2FUSB%2FMUZIK%2FFocal%20JMlab%201%2F5%20-%20Amuseum.wav&metadata=false Oct 12 15:09:22 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Focal JMlab 1/5 - Amuseum.wav Oct 12 15:09:22 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Ron%20Tutt/Focal%20Demo-Disc%20Nr.1/large&path=%2Fmnt%2FUSB%2FMUZIK%2FFocal%20JMlab%201%2F6%20-%20Improvisation.wav&metadata=false Oct 12 15:09:22 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Focal JMlab 1/6 - Improvisation.wav Oct 12 15:09:22 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Lincoln%20Mayorga/Focal%20Demo-Disc%20Nr.1/large&path=%2Fmnt%2FUSB%2FMUZIK%2FFocal%20JMlab%201%2F7%20-%20Dock%20Of%20The%20Bay.wav&metadata=false Oct 12 15:09:22 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Focal JMlab 1/7 - Dock Of The Bay.wav Oct 12 15:09:22 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Harry%20James/Focal%20Demo-Disc%20Nr.1/large&path=%2Fmnt%2FUSB%2FMUZIK%2FFocal%20JMlab%201%2F8%20-%20Sweet%20Georgia%20Brown.wav&metadata=false Oct 12 15:09:22 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Focal JMlab 1/8 - Sweet Georgia Brown.wav Oct 12 15:09:22 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Eddyston%20Light%20Luxon%20%26%20Crofut/Focal%20Demo-Disc%20Nr.1/large&path=%2Fmnt%2FUSB%2FMUZIK%2FFocal%20JMlab%201%2F9%20-%20Bold%20Nelson.wav&metadata=false Oct 12 15:09:22 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Focal JMlab 1/9 - Bold Nelson.wav Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushQueue Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::saveQueue Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::updateTrackBlock Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrackBlock Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPlay Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::play index 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::stop Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::play index undefined Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::startPlaybackTimer Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::clearAddPlayTracks USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand stop Oct 12 15:09:22 volumio23 volumio[1329]: info: sendMpdCommand stop took 1 milliseconds Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand clear Oct 12 15:09:22 volumio23 volumio[1329]: info: Oct 12 15:09:22 volumio23 volumio[1329]: ---------------------------- MPD announces system playlist update Oct 12 15:09:22 volumio23 volumio[1329]: info: Ignoring MPD Status Update Oct 12 15:09:22 volumio23 volumio[1329]: info: sendMpdCommand clear took 0 milliseconds Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand add "USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" Oct 12 15:09:22 volumio23 volumio[1329]: info: Oct 12 15:09:22 volumio23 volumio[1329]: ---------------------------- MPD announces system playlist update Oct 12 15:09:22 volumio23 volumio[1329]: info: Ignoring MPD Status Update Oct 12 15:09:22 volumio23 volumio[1329]: info: Oct 12 15:09:22 volumio23 volumio[1329]: ---------------------------- MPD announces system playlist update Oct 12 15:09:22 volumio23 volumio[1329]: info: Ignoring MPD Status Update Oct 12 15:09:22 volumio23 volumio[1329]: error: updateQueue error: null Oct 12 15:09:22 volumio23 volumio[1329]: info: Oct 12 15:09:22 volumio23 volumio[1329]: ---------------------------- MPD announces system playlist update Oct 12 15:09:22 volumio23 volumio[1329]: info: Ignoring MPD Status Update Oct 12 15:09:22 volumio23 volumio[1329]: info: ------------------------------ 2ms Oct 12 15:09:22 volumio23 volumio[1329]: info: sendMpdCommand add "USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" took 1 milliseconds Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand play Oct 12 15:09:22 volumio23 volumio[1329]: info: ------------------------------ 2ms Oct 12 15:09:22 volumio23 volumio[1329]: info: ------------------------------ 2ms Oct 12 15:09:22 volumio23 volumio[1329]: info: ------------------------------ 1ms Oct 12 15:09:22 volumio23 volumio[1329]: info: Oct 12 15:09:22 volumio23 volumio[1329]: ---------------------------- MPD announces system playlist update Oct 12 15:09:22 volumio23 volumio[1329]: info: Ignoring MPD Status Update Oct 12 15:09:22 volumio23 volumio[1329]: info: Oct 12 15:09:22 volumio23 volumio[1329]: ---------------------------- MPD announces system playlist update Oct 12 15:09:22 volumio23 volumio[1329]: info: Ignoring MPD Status Update Oct 12 15:09:22 volumio23 volumio[1329]: info: sendMpdCommand play took 2 milliseconds Oct 12 15:09:22 volumio23 volumio[1329]: info: ------------------------------ 2ms Oct 12 15:09:22 volumio23 volumio[1329]: info: ------------------------------ 2ms Oct 12 15:09:22 volumio23 volumio[1329]: info: Oct 12 15:09:22 volumio23 volumio[1329]: ---------------------------- MPD announces state update: player Oct 12 15:09:22 volumio23 volumio[1329]: info: ControllerMpd::getState Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand status Oct 12 15:09:22 volumio23 volumio[1329]: info: Oct 12 15:09:22 volumio23 volumio[1329]: ---------------------------- MPD announces state update: player Oct 12 15:09:22 volumio23 volumio[1329]: info: ControllerMpd::getState Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand status Oct 12 15:09:22 volumio23 volumio[1329]: info: Oct 12 15:09:22 volumio23 volumio[1329]: ---------------------------- MPD announces state update: player Oct 12 15:09:22 volumio23 volumio[1329]: info: ControllerMpd::getState Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand status Oct 12 15:09:22 volumio23 volumio[1329]: info: Oct 12 15:09:22 volumio23 volumio[1329]: ---------------------------- MPD announces state update: player Oct 12 15:09:22 volumio23 volumio[1329]: info: sendMpdCommand status took 20 milliseconds Oct 12 15:09:22 volumio23 volumio[1329]: info: ControllerMpd::getState Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand status Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::parseState Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 15:09:22 volumio23 volumio[1329]: info: Oct 12 15:09:22 volumio23 volumio[1329]: ---------------------------- MPD announces state update: player Oct 12 15:09:22 volumio23 volumio[1329]: info: ControllerMpd::getState Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand status Oct 12 15:09:22 volumio23 volumio[1329]: info: sendMpdCommand status took 20 milliseconds Oct 12 15:09:22 volumio23 volumio[1329]: info: sendMpdCommand status took 19 milliseconds Oct 12 15:09:22 volumio23 volumio[1329]: info: sendMpdCommand status took 0 milliseconds Oct 12 15:09:22 volumio23 volumio[1329]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 12 15:09:22 volumio23 volumio[1329]: info: sendMpdCommand status took 1 milliseconds Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::parseState Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::parseState Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::parseState Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::parseTrackInfo Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::parseState Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 15:09:22 volumio23 volumio[1329]: info: ControllerMpd::pushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::servicePushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"Sweet Sixteen","artist":"Juniot Wells","album":"Focal Demo-Disc Nr.1","uri":"USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav","trackType":"wav"} Oct 12 15:09:22 volumio23 volumio[1329]: verbose: CURRENT POSITION 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::syncState stateService play Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::syncState currentStatus stop Oct 12 15:09:22 volumio23 volumio[1329]: info: ------------------------------ 23ms Oct 12 15:09:22 volumio23 volumio[1329]: info: Oct 12 15:09:22 volumio23 volumio[1329]: ---------------------------- MPD announces state update: player Oct 12 15:09:22 volumio23 volumio[1329]: info: ControllerMpd::getState Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand status Oct 12 15:09:22 volumio23 volumio[1329]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 12 15:09:22 volumio23 volumio[1329]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 12 15:09:22 volumio23 volumio[1329]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 12 15:09:22 volumio23 volumio[1329]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 12 15:09:22 volumio23 volumio[1329]: info: sendMpdCommand status took 1 milliseconds Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::parseTrackInfo Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::parseTrackInfo Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::parseTrackInfo Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::parseTrackInfo Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::parseState Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 15:09:22 volumio23 volumio[1329]: info: ControllerMpd::pushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::servicePushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":298,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"Sweet Sixteen","artist":"Juniot Wells","album":"Focal Demo-Disc Nr.1","uri":"USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav","trackType":"wav"} Oct 12 15:09:22 volumio23 volumio[1329]: verbose: CURRENT POSITION 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::syncState stateService play Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::syncState currentStatus play Oct 12 15:09:22 volumio23 volumio[1329]: info: Received an update from plugin. extracting info from payload Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:09:22 volumio23 volumio[1329]: info: ControllerMpd::pushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::servicePushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":298,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"Sweet Sixteen","artist":"Juniot Wells","album":"Focal Demo-Disc Nr.1","uri":"USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav","trackType":"wav"} Oct 12 15:09:22 volumio23 volumio[1329]: verbose: CURRENT POSITION 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::syncState stateService play Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::syncState currentStatus play Oct 12 15:09:22 volumio23 volumio[1329]: info: Received an update from plugin. extracting info from payload Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:09:22 volumio23 volumio[1329]: info: ControllerMpd::pushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::servicePushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":298,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"Sweet Sixteen","artist":"Juniot Wells","album":"Focal Demo-Disc Nr.1","uri":"USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav","trackType":"wav"} Oct 12 15:09:22 volumio23 volumio[1329]: verbose: CURRENT POSITION 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::syncState stateService play Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::syncState currentStatus play Oct 12 15:09:22 volumio23 volumio[1329]: info: Received an update from plugin. extracting info from payload Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:09:22 volumio23 volumio[1329]: info: ControllerMpd::pushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::servicePushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":298,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"Sweet Sixteen","artist":"Juniot Wells","album":"Focal Demo-Disc Nr.1","uri":"USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav","trackType":"wav"} Oct 12 15:09:22 volumio23 volumio[1329]: verbose: CURRENT POSITION 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::syncState stateService play Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::syncState currentStatus play Oct 12 15:09:22 volumio23 volumio[1329]: info: Received an update from plugin. extracting info from payload Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.199+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=871 volume=67 Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.199+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.199+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=871 volume=67 Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.199+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.199+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=871 volume=67 Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.199+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.200+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=871 volume=67 Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.200+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.200+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=871 volume=67 Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.201+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.201+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=871 volume=67 Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.201+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.201+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=871 volume=67 Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.202+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.202+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=871 volume=67 Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.202+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:09:22 volumio23 volumio[1329]: info: ------------------------------ 55ms Oct 12 15:09:22 volumio23 volumio[1329]: info: ------------------------------ 56ms Oct 12 15:09:22 volumio23 volumio[1329]: info: ------------------------------ 37ms Oct 12 15:09:22 volumio23 volumio[1329]: info: ------------------------------ 36ms Oct 12 15:09:22 volumio23 volumio[1329]: info: sendMpdCommand playlistinfo took 34 milliseconds Oct 12 15:09:22 volumio23 volumio[1329]: verbose: ControllerMpd::parseTrackInfo Oct 12 15:09:22 volumio23 volumio[1329]: info: ControllerMpd::pushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::servicePushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":298,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":true,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"Sweet Sixteen","artist":"Juniot Wells","album":"Focal Demo-Disc Nr.1","uri":"USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav","trackType":"wav"} Oct 12 15:09:22 volumio23 volumio[1329]: verbose: CURRENT POSITION 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::syncState stateService play Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::syncState currentStatus play Oct 12 15:09:22 volumio23 volumio[1329]: info: Received an update from plugin. extracting info from payload Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:09:22 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.228+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=871 volume=67 Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.229+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.229+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=871 volume=67 Oct 12 15:09:22 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:22.229+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:09:22 volumio23 volumio[1329]: info: ------------------------------ 48ms Oct 12 15:09:22 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 12 15:09:23 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 12 15:09:36 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 12 15:09:50 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:50.797+07:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.654067ms timeout=10s Oct 12 15:09:50 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:50.841+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.654067ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=43.184927ms Oct 12 15:09:50 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:50.845+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.654067ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=47.330055ms Oct 12 15:09:50 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:50.853+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.654067ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=55.494347ms Oct 12 15:09:50 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:50.928+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.654067ms timeout=10s endpoint=https://www.googleapis.com duration=130.613048ms Oct 12 15:09:50 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:50.954+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.654067ms timeout=10s endpoint=https://google.com duration=157.060183ms Oct 12 15:09:50 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 15:09:50 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 15:09:50 volumio23 volumio[1329]: info: Discovery: Getting this device information Oct 12 15:09:50 volumio23 volumio[1329]: info: CoreCommandRouter::volumioGetState Oct 12 15:09:50 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:50 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 15:09:50 volumio23 volumio[1329]: verbose: New Socket.io Connection to 192.168.1.123:3000 from 192.168.1.4 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Oct 12 15:09:50 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 15:09:50 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 15:09:51 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:51.010+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.654067ms timeout=10s endpoint=http://pushupdates.volumio.org duration=212.217137ms Oct 12 15:09:51 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:51.019+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.654067ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=221.79059ms Oct 12 15:09:51 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:51.022+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.654067ms timeout=10s endpoint=https://securetoken.googleapis.com duration=224.470799ms Oct 12 15:09:51 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:51.039+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.654067ms timeout=10s endpoint=https://functions.volumio.cloud duration=241.63378ms Oct 12 15:09:51 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:51.041+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.654067ms timeout=10s endpoint=https://functions.volumio.cloud duration=243.476259ms Oct 12 15:09:51 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:51.087+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.654067ms timeout=10s endpoint=https://database.volumio.cloud duration=288.71124ms Oct 12 15:09:51 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:51.704+07:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.654067ms timeout=10s endpoint=http://cddb.volumio.org duration=905.937124ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 12 15:09:52 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:52.326+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.654067ms timeout=10s endpoint=http://plugins.volumio.org duration=1.527835402s Oct 12 15:09:54 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:54.694+07:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.134469ms timeout=10s Oct 12 15:09:54 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:54.738+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.134469ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=44.276531ms Oct 12 15:09:54 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:54.741+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.134469ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=46.637903ms Oct 12 15:09:54 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:54.748+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.134469ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=54.068504ms Oct 12 15:09:54 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 15:09:54 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 15:09:54 volumio23 volumio[1329]: info: Discovery: Getting this device information Oct 12 15:09:54 volumio23 volumio[1329]: info: CoreCommandRouter::volumioGetState Oct 12 15:09:54 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:09:54 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 15:09:54 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:54.813+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.134469ms timeout=10s endpoint=https://google.com duration=118.81723ms Oct 12 15:09:54 volumio23 volumio[1329]: verbose: New Socket.io Connection to 192.168.1.123:3000 from 192.168.1.4 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Oct 12 15:09:54 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:54.823+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.134469ms timeout=10s endpoint=https://www.googleapis.com duration=129.332357ms Oct 12 15:09:54 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 15:09:54 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 15:09:54 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:54.905+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.134469ms timeout=10s endpoint=http://pushupdates.volumio.org duration=211.097823ms Oct 12 15:09:54 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:54.913+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.134469ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=218.304385ms Oct 12 15:09:54 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:54.917+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.134469ms timeout=10s endpoint=https://securetoken.googleapis.com duration=222.708071ms Oct 12 15:09:54 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:54.928+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.134469ms timeout=10s endpoint=https://functions.volumio.cloud duration=234.669193ms Oct 12 15:09:54 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:54.935+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.134469ms timeout=10s endpoint=https://functions.volumio.cloud duration=240.396835ms Oct 12 15:09:54 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:54.976+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.134469ms timeout=10s endpoint=https://database.volumio.cloud duration=281.286743ms Oct 12 15:09:55 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:55.141+07:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.134469ms timeout=10s endpoint=http://plugins.volumio.org duration=447.014157ms Oct 12 15:09:55 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:09:55.381+07:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.1.4:48934 @ 0x2000c00" latency=245.134469ms timeout=10s endpoint=http://cddb.volumio.org duration=687.321754ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 12 15:10:01 volumio23 ntpd[1184]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 12 15:10:01 volumio23 ntpd[1184]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Oct 12 15:10:01 volumio23 ntpd[1184]: DNS: Pool skipping: 103.221.223.143 Oct 12 15:10:01 volumio23 ntpd[1184]: DNS: Pool skipping: 45.252.250.189 Oct 12 15:10:01 volumio23 ntpd[1184]: DNS: Pool skipping: 115.165.161.155 Oct 12 15:10:01 volumio23 ntpd[1184]: DNS: Pool skipping: 103.184.124.254 Oct 12 15:10:01 volumio23 ntpd[1184]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Oct 12 15:10:02 volumio23 ntpd[1184]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 12 15:10:02 volumio23 ntpd[1184]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Oct 12 15:10:02 volumio23 ntpd[1184]: DNS: Pool skipping: 103.221.223.143 Oct 12 15:10:02 volumio23 ntpd[1184]: DNS: Pool skipping: 45.252.250.189 Oct 12 15:10:02 volumio23 ntpd[1184]: DNS: Pool skipping: 103.184.124.254 Oct 12 15:10:02 volumio23 ntpd[1184]: DNS: Pool skipping: 115.165.161.155 Oct 12 15:10:02 volumio23 ntpd[1184]: DNS: Pool skipping: 2400:e920:0:5::14 Oct 12 15:10:02 volumio23 ntpd[1184]: DNS: Pool skipping: 2001:df7:c600:13:f816:3eff:fe1d:b3b5 Oct 12 15:10:02 volumio23 ntpd[1184]: DNS: Pool skipping: 2001:df4:bac0::e35b:f223 Oct 12 15:10:02 volumio23 ntpd[1184]: DNS: Pool skipping: 2400:d760:0:ff09::123 Oct 12 15:10:02 volumio23 ntpd[1184]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Oct 12 15:10:03 volumio23 ntpd[1184]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 12 15:10:03 volumio23 ntpd[1184]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Oct 12 15:10:03 volumio23 ntpd[1184]: DNS: Pool skipping: 103.221.223.143 Oct 12 15:10:03 volumio23 ntpd[1184]: DNS: Pool skipping: 45.252.250.189 Oct 12 15:10:03 volumio23 ntpd[1184]: DNS: Pool skipping: 103.184.124.254 Oct 12 15:10:03 volumio23 ntpd[1184]: DNS: Pool skipping: 115.165.161.155 Oct 12 15:10:03 volumio23 ntpd[1184]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Oct 12 15:10:04 volumio23 ntpd[1184]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 12 15:10:04 volumio23 ntpd[1184]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Oct 12 15:10:04 volumio23 ntpd[1184]: DNS: Pool skipping: 103.221.223.143 Oct 12 15:10:04 volumio23 ntpd[1184]: DNS: Pool skipping: 45.252.250.189 Oct 12 15:10:04 volumio23 ntpd[1184]: DNS: Pool skipping: 115.165.161.155 Oct 12 15:10:04 volumio23 ntpd[1184]: DNS: Pool skipping: 103.184.124.254 Oct 12 15:10:04 volumio23 ntpd[1184]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Oct 12 15:10:05 volumio23 volumio[1329]: info: MPD Database updated - AlbumList cache refreshed Oct 12 15:10:05 volumio23 volumio[1329]: info: Oct 12 15:10:05 volumio23 volumio[1329]: ---------------------------- MPD announces state update: database Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand status Oct 12 15:10:05 volumio23 volumio[1329]: info: Oct 12 15:10:05 volumio23 volumio[1329]: ---------------------------- MPD announces state update: update Oct 12 15:10:05 volumio23 volumio[1329]: info: ControllerMpd::getState Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand status Oct 12 15:10:05 volumio23 volumio[1329]: info: ControllerMpd::getState Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand status Oct 12 15:10:05 volumio23 volumio[1329]: info: MPD Database updated - AlbumList cache refreshed Oct 12 15:10:05 volumio23 volumio[1329]: info: Oct 12 15:10:05 volumio23 volumio[1329]: ---------------------------- MPD announces state update: database Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand status Oct 12 15:10:05 volumio23 volumio[1329]: info: Oct 12 15:10:05 volumio23 volumio[1329]: ---------------------------- MPD announces state update: update Oct 12 15:10:05 volumio23 volumio[1329]: info: ControllerMpd::getState Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand status Oct 12 15:10:05 volumio23 volumio[1329]: info: ControllerMpd::getState Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand status Oct 12 15:10:05 volumio23 volumio[1329]: info: MPD Database updated - AlbumList cache refreshed Oct 12 15:10:05 volumio23 volumio[1329]: info: Oct 12 15:10:05 volumio23 volumio[1329]: ---------------------------- MPD announces state update: database Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand status Oct 12 15:10:05 volumio23 volumio[1329]: info: Oct 12 15:10:05 volumio23 volumio[1329]: ---------------------------- MPD announces state update: update Oct 12 15:10:05 volumio23 volumio[1329]: info: ControllerMpd::getState Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand status Oct 12 15:10:05 volumio23 volumio[1329]: info: ControllerMpd::getState Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand status Oct 12 15:10:05 volumio23 volumio[1329]: info: sendMpdCommand status took 292 milliseconds Oct 12 15:10:05 volumio23 volumio[1329]: info: sendMpdCommand status took 291 milliseconds Oct 12 15:10:05 volumio23 volumio[1329]: info: sendMpdCommand status took 292 milliseconds Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::parseState Oct 12 15:10:05 volumio23 volumio[1329]: info: Command Router : Notfying DB Updatefalse Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::Close All Modals sent Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::parseState Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::parseState Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 15:10:05 volumio23 volumio[1329]: info: sendMpdCommand status took 492 milliseconds Oct 12 15:10:05 volumio23 volumio[1329]: info: sendMpdCommand status took 492 milliseconds Oct 12 15:10:05 volumio23 volumio[1329]: info: sendMpdCommand status took 491 milliseconds Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::parseState Oct 12 15:10:05 volumio23 volumio[1329]: info: Command Router : Notfying DB Updatefalse Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::Close All Modals sent Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::parseState Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::parseState Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 15:10:05 volumio23 volumio[1329]: info: sendMpdCommand status took 657 milliseconds Oct 12 15:10:05 volumio23 volumio[1329]: info: sendMpdCommand status took 658 milliseconds Oct 12 15:10:05 volumio23 volumio[1329]: info: sendMpdCommand status took 658 milliseconds Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::parseState Oct 12 15:10:05 volumio23 volumio[1329]: info: Command Router : Notfying DB Updatefalse Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::Close All Modals sent Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::parseState Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::parseState Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 12 15:10:05 volumio23 volumio[1329]: info: sendMpdCommand playlistinfo took 351 milliseconds Oct 12 15:10:05 volumio23 volumio[1329]: info: sendMpdCommand playlistinfo took 351 milliseconds Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::parseTrackInfo Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::parseTrackInfo Oct 12 15:10:05 volumio23 volumio[1329]: info: ControllerMpd::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::servicePushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: verbose: STATE SERVICE {"status":"play","position":0,"seek":43763,"duration":298,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"Sweet Sixteen","artist":"Juniot Wells","album":"Focal Demo-Disc Nr.1","uri":"USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav","trackType":"wav"} Oct 12 15:10:05 volumio23 volumio[1329]: verbose: CURRENT POSITION 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::syncState stateService play Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::syncState currentStatus play Oct 12 15:10:05 volumio23 volumio[1329]: info: Received an update from plugin. extracting info from payload Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:10:05 volumio23 volumio[1329]: info: ControllerMpd::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::servicePushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: verbose: STATE SERVICE {"status":"play","position":0,"seek":43763,"duration":298,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"Sweet Sixteen","artist":"Juniot Wells","album":"Focal Demo-Disc Nr.1","uri":"USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav","trackType":"wav"} Oct 12 15:10:05 volumio23 volumio[1329]: verbose: CURRENT POSITION 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::syncState stateService play Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::syncState currentStatus play Oct 12 15:10:05 volumio23 volumio[1329]: info: Received an update from plugin. extracting info from payload Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.784+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=43763 volume=67 Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.784+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=43763 volume=67 Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.784+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.784+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.784+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=43763 volume=67 Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.784+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.785+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=43763 volume=67 Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.785+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:10:05 volumio23 volumio[1329]: info: ------------------------------ 729ms Oct 12 15:10:05 volumio23 volumio[1329]: info: ------------------------------ 729ms Oct 12 15:10:05 volumio23 volumio[1329]: info: sendMpdCommand playlistinfo took 217 milliseconds Oct 12 15:10:05 volumio23 volumio[1329]: info: sendMpdCommand playlistinfo took 217 milliseconds Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::parseTrackInfo Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::parseTrackInfo Oct 12 15:10:05 volumio23 volumio[1329]: info: ControllerMpd::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::servicePushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: verbose: STATE SERVICE {"status":"play","position":0,"seek":43763,"duration":298,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"Sweet Sixteen","artist":"Juniot Wells","album":"Focal Demo-Disc Nr.1","uri":"USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav","trackType":"wav"} Oct 12 15:10:05 volumio23 volumio[1329]: verbose: CURRENT POSITION 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::syncState stateService play Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::syncState currentStatus play Oct 12 15:10:05 volumio23 volumio[1329]: info: Received an update from plugin. extracting info from payload Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:10:05 volumio23 volumio[1329]: info: ControllerMpd::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::servicePushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: verbose: STATE SERVICE {"status":"play","position":0,"seek":43763,"duration":298,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"Sweet Sixteen","artist":"Juniot Wells","album":"Focal Demo-Disc Nr.1","uri":"USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav","trackType":"wav"} Oct 12 15:10:05 volumio23 volumio[1329]: verbose: CURRENT POSITION 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::syncState stateService play Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::syncState currentStatus play Oct 12 15:10:05 volumio23 volumio[1329]: info: Received an update from plugin. extracting info from payload Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.807+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=43763 volume=67 Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.807+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.808+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=43763 volume=67 Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.808+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.808+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=43763 volume=67 Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.808+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.808+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=43763 volume=67 Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.809+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:10:05 volumio23 volumio[1329]: info: ------------------------------ 751ms Oct 12 15:10:05 volumio23 volumio[1329]: info: ------------------------------ 751ms Oct 12 15:10:05 volumio23 volumio[1329]: info: sendMpdCommand playlistinfo took 53 milliseconds Oct 12 15:10:05 volumio23 volumio[1329]: info: sendMpdCommand playlistinfo took 52 milliseconds Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::parseTrackInfo Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::parseTrackInfo Oct 12 15:10:05 volumio23 volumio[1329]: info: ControllerMpd::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::servicePushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: verbose: STATE SERVICE {"status":"play","position":0,"seek":43855,"duration":298,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"Sweet Sixteen","artist":"Juniot Wells","album":"Focal Demo-Disc Nr.1","uri":"USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav","trackType":"wav"} Oct 12 15:10:05 volumio23 volumio[1329]: verbose: CURRENT POSITION 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::syncState stateService play Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::syncState currentStatus play Oct 12 15:10:05 volumio23 volumio[1329]: info: Received an update from plugin. extracting info from payload Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:10:05 volumio23 volumio[1329]: info: ControllerMpd::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::servicePushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: verbose: STATE SERVICE {"status":"play","position":0,"seek":43855,"duration":298,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1411 Kbps","isStreaming":false,"title":"Sweet Sixteen","artist":"Juniot Wells","album":"Focal Demo-Disc Nr.1","uri":"USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav","trackType":"wav"} Oct 12 15:10:05 volumio23 volumio[1329]: verbose: CURRENT POSITION 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::syncState stateService play Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::syncState currentStatus play Oct 12 15:10:05 volumio23 volumio[1329]: info: Received an update from plugin. extracting info from payload Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.824+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=43855 volume=67 Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.824+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.824+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=43855 volume=67 Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.825+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.825+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=43855 volume=67 Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.825+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.825+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_PLAYING positionMs=43855 volume=67 Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.825+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:10:05 volumio23 volumio[1329]: info: ------------------------------ 766ms Oct 12 15:10:05 volumio23 volumio[1329]: info: ------------------------------ 766ms Oct 12 15:10:05 volumio23 volumio[1329]: info: Preload queue cleared Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::ClearQueue Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::stop Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::stPlaybackTimer Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::updateTrackBlock Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrackBlock Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::pushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushState Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::serviceStop Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::getTrack 0 Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::serviceStop Oct 12 15:10:05 volumio23 volumio[1329]: info: ControllerMpd::stop Oct 12 15:10:05 volumio23 volumio[1329]: verbose: ControllerMpd::sendMpdCommand stop Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::clearPlayQueue Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::saveQueue Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreCommandRouter::volumioPushQueue Oct 12 15:10:05 volumio23 volumio[1329]: info: CoreStateMachine::addQueueItems Oct 12 15:10:05 volumio23 volumio[1329]: info: CorePlayQueue::addQueueItems Oct 12 15:10:05 volumio23 volumio[1329]: info: Preload queue cleared Oct 12 15:10:05 volumio23 volumio[1329]: info: Adding Item to queue: music-library/USB/MUZIK/Apollo II Oct 12 15:10:05 volumio23 volumio[1329]: info: Exploding uri music-library/USB/MUZIK/Apollo II in service mpd Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.851+07:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" state=STATUS_STOPPED positionMs=0 volume=67 Oct 12 15:10:05 volumio23 volumio5-onboarding[1540]: time=2026-10-12T15:10:05.851+07:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.4:48934 @ 0x2000c00" id="mnt/USB/MUZIK/Focal JMlab 1/1 - Sweet Sixteen.wav" title="1 - Sweet Sixteen" Oct 12 15:10:05 volumio23 volumio[1329]: info: Oct 12 15:10:05 volumio23 volumio[1329]: ---------------------------- MPD announces state update: player Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F01%20-%20Air%20on%20a%20G%20String%20(Aria%20from%20Suite%20No.3).wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/01 - Air on a G String (Aria from Suite No.3).wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F02%20-%20E%20lucean%20le%20stelle%20(from%20Tosca).wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/02 - E lucean le stelle (from Tosca).wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F03%20-%20Chorus%20of%20the%20Gypsies%20(from%20La%20Traviata).wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/03 - Chorus of the Gypsies (from La Traviata).wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F04%20-%20Gypsy%20Song%20Op.55%2C%20No.4.wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/04 - Gypsy Song Op.55, No.4.wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F05%20-%20Pavane%2C%20Op.50.wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/05 - Pavane, Op.50.wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F06%20-%20Nocturne%20in%20E%20flat%20major.wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/06 - Nocturne in E flat major.wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F07%20-%20Prelude%20in%20E%20minor.wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/07 - Prelude in E minor.wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F08%20-%20Nocturne%20in%20C%20sharp%20minor.wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/08 - Nocturne in C sharp minor.wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F09%20-%20Playera%20(Spanish%20Dance)%2C%20Op.5%2C%20No.5.wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/09 - Playera (Spanish Dance), Op.5, No.5.wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F10%20-%20Malaguena%20Op.21.wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/10 - Malaguena Op.21.wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F11%20-%20El%20Choclo%20(Tango%20Argentine).wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/11 - El Choclo (Tango Argentine).wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F12%20-%20Tango%20in%20D.wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/12 - Tango in D.wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F13%20-%20More%20(Theme%20from%20Mondo%20Cane).wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/13 - More (Theme from Mondo Cane).wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F14%20-%20Spanish%20Eyes.wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/14 - Spanish Eyes.wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F15%20-%20Tu.wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/15 - Tu.wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F16%20-%20Il%20Postino%20(Theme%20from%20Il%20Postino).wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/16 - Il Postino (Theme from Il Postino).wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F17%20-%20Cumparsita.wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/17 - Cumparsita.wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F18%20-%20Love%20Story.wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/18 - Love Story.wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2F19%20-%20Eli%2C%20Eli.wav&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/19 - Eli, Eli.wav Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2FDaniel%20%26%20Carey%20Domb%20-%20Apollo%20II%20-%20Odyssey.cue&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/Daniel & Carey Domb - Apollo II - Odyssey.cue Oct 12 15:10:05 volumio23 volumio[1329]: info: ALBUMART /albumart?cacheid=1000&web=Daniel%20%26%20Carey%20Domb/Apollo%20II%20-%20Odyssey/large&path=%2Fmnt%2FUSB%2FMUZIK%2FApollo%20II%2FDaniel%20%26%20Carey%20Domb%20-%20Apollo%20II%20-%20Odyssey.cue&metadata=false Oct 12 15:10:05 volumio23 volumio[1329]: info: URI /mnt/USB/MUZIK/Apollo II/Daniel & Carey Domb - Apollo II - Odyssey.cue Oct 12 15:10:05 volumio23 volumio[1329]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 15:10:05 volumio23 volumio[1329]: Error: Unable to resolve or reject the same promise twice Oct 12 15:10:05 volumio23 volumio[1329]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Oct 12 15:10:05 volumio23 volumio[1329]: at /volumio/app/plugins/music_service/mpd/index.js:2582:21 Oct 12 15:10:05 volumio23 volumio[1329]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Oct 12 15:10:05 volumio23 volumio[1329]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Oct 12 15:10:05 volumio23 volumio[1329]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Oct 12 15:10:05 volumio23 volumio[1329]: at Socket.emit (node:events:514:28) Oct 12 15:10:05 volumio23 volumio[1329]: at addChunk (node:internal/streams/readable:343:12) Oct 12 15:10:05 volumio23 volumio[1329]: at readableAddChunk (node:internal/streams/readable:312:11) Oct 12 15:10:05 volumio23 volumio[1329]: at Readable.push (node:internal/streams/readable:253:10) Oct 12 15:10:05 volumio23 volumio[1329]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Oct 12 15:10:05 volumio23 volumio[1329]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 15:10:06 volumio23 sudo[2727]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-12 15:09' Oct 12 15:10:06 volumio23 sudo[2727]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"