Aug 31 18:18:01 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Aug 31 18:18:01 volumio-pi3b volumio[1146]: info: CURURI: music-library/USB/LaCie/Gidon Kremer Aug 31 18:18:02 volumio-pi3b volumio[1146]: info: Preload queue cleared Aug 31 18:18:03 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Aug 31 18:18:03 volumio-pi3b volumio[1146]: info: CURURI: music-library/USB/LaCie/Gidon Kremer/Hommage À Piazzolla Aug 31 18:18:03 volumio-pi3b volumio[1146]: info: Preload queue cleared Aug 31 18:18:03 volumio-pi3b volumio[1146]: info: Preloading song: music-library/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac Aug 31 18:18:03 volumio-pi3b volumio[1146]: info: Exploding uri music-library/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac in service mpd Aug 31 18:18:03 volumio-pi3b volumio[1146]: info: ALBUMART /albumart?cacheid=104&web=Gidon%20Kremer/High%20Fidelity%20Reference%20CD%20No.%2026/extralarge&path=%2Fmnt%2FUSB%2FLaCie%2FGidon%20Kremer%2FHommage%20%C3%80%20Piazzolla%2FPiazzolla-%20Buenos%20Aires%20Hora%20Cero%2008.flac&metadata=false Aug 31 18:18:03 volumio-pi3b volumio[1146]: info: URI /mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: Preload queue cleared Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::ClearQueue Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::stop Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::stPlaybackTimer Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::updateTrackBlock Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrackBlock Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 1 Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::serviceStop Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 1 Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreCommandRouter::serviceStop Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: ControllerMpd::stop Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CorePlayQueue::clearPlayQueue Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CorePlayQueue::saveQueue Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushQueue Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::addQueueItems Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CorePlayQueue::addQueueItems Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: Preload queue cleared Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: Adding Item to queue: music-library/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: Using cached record of: music-library/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac Aug 31 18:18:04 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:04.296+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_STOPPED positionMs=0 volume=100 Aug 31 18:18:04 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:04.296+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Genesis/Abacab/Me And Sarah Jane 03.flac" title="Me And Sarah Jane" Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushQueue Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CorePlayQueue::saveQueue Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::updateTrackBlock Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrackBlock Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPlay Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::play index 0 Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::stop Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::play index undefined Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::startPlaybackTimer Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioGetVisibleSources Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::clearAddPlayTracks USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: Aug 31 18:18:04 volumio-pi3b volumio[1146]: ---------------------------- MPD announces state update: player Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: sendMpdCommand stop took 25 milliseconds Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: ControllerMpd::getState Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand status Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: sendMpdCommand stop took 7 milliseconds Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand clear Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: Aug 31 18:18:04 volumio-pi3b volumio[1146]: ---------------------------- MPD announces system playlist update Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: Ignoring MPD Status Update Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: sendMpdCommand status took 2 milliseconds Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: sendMpdCommand clear took 1 milliseconds Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseState Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand add "USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" Aug 31 18:18:04 volumio-pi3b volumio[1146]: error: updateQueue error: null Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: Aug 31 18:18:04 volumio-pi3b volumio[1146]: ---------------------------- MPD announces system playlist update Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: Ignoring MPD Status Update Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: ------------------------------ 2ms Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: sendMpdCommand add "USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" took 2 milliseconds Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseTrackInfo Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand play Aug 31 18:18:04 volumio-pi3b volumio[1146]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: ------------------------------ 5ms Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: ------------------------------ 3ms Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: sendMpdCommand play took 1 milliseconds Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: Aug 31 18:18:04 volumio-pi3b volumio[1146]: ---------------------------- MPD announces state update: player Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: ControllerMpd::getState Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand status Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: Aug 31 18:18:04 volumio-pi3b volumio[1146]: ---------------------------- MPD announces state update: player Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: sendMpdCommand status took 7 milliseconds Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: ControllerMpd::getState Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand status Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseState Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: sendMpdCommand status took 2 milliseconds Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: sendMpdCommand playlistinfo took 3 milliseconds Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseState Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseTrackInfo Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: ControllerMpd::pushState Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreCommandRouter::servicePushState Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":394,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Buenos Aires Hora Cero","artist":"Gidon Kremer","album":"High Fidelity Reference CD No. 26","uri":"USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac","trackType":"flac"} Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: CURRENT POSITION 0 Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState stateService play Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState currentStatus stop Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: ------------------------------ 14ms Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseTrackInfo Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: ControllerMpd::pushState Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreCommandRouter::servicePushState Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1215,"duration":394,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"328 Kbps","isStreaming":false,"title":"Buenos Aires Hora Cero","artist":"Gidon Kremer","album":"High Fidelity Reference CD No. 26","uri":"USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac","trackType":"flac"} Aug 31 18:18:04 volumio-pi3b volumio[1146]: verbose: CURRENT POSITION 0 Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState stateService play Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState currentStatus play Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: Received an update from plugin. extracting info from payload Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:04 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:04.410+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_PLAYING positionMs=1215 volume=100 Aug 31 18:18:04 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:04.410+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_PLAYING positionMs=1215 volume=100 Aug 31 18:18:04 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:04.410+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:04 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:04.411+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:04 volumio-pi3b volumio[1146]: info: ------------------------------ 34ms Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: Preload queue cleared Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::ClearQueue Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::stop Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::stPlaybackTimer Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::updateTrackBlock Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrackBlock Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::serviceStop Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreCommandRouter::serviceStop Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: ControllerMpd::stop Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CorePlayQueue::clearPlayQueue Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CorePlayQueue::saveQueue Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushQueue Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::addQueueItems Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CorePlayQueue::addQueueItems Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: Preload queue cleared Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: Adding Item to queue: music-library/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: Using cached record of: music-library/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac Aug 31 18:18:11 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:11.335+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_STOPPED positionMs=0 volume=100 Aug 31 18:18:11 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:11.336+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushQueue Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CorePlayQueue::saveQueue Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::updateTrackBlock Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrackBlock Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPlay Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::play index 0 Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::stop Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::play index undefined Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::startPlaybackTimer Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioGetVisibleSources Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::clearAddPlayTracks USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: Aug 31 18:18:11 volumio-pi3b volumio[1146]: ---------------------------- MPD announces state update: player Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: sendMpdCommand stop took 21 milliseconds Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: ControllerMpd::getState Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand status Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: sendMpdCommand stop took 7 milliseconds Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand clear Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: Aug 31 18:18:11 volumio-pi3b volumio[1146]: ---------------------------- MPD announces system playlist update Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: Ignoring MPD Status Update Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: sendMpdCommand status took 2 milliseconds Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: sendMpdCommand clear took 1 milliseconds Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseState Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand add "USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" Aug 31 18:18:11 volumio-pi3b volumio[1146]: error: updateQueue error: null Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: Aug 31 18:18:11 volumio-pi3b volumio[1146]: ---------------------------- MPD announces system playlist update Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: Ignoring MPD Status Update Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: ------------------------------ 5ms Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: sendMpdCommand add "USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" took 4 milliseconds Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseTrackInfo Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand play Aug 31 18:18:11 volumio-pi3b volumio[1146]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: ------------------------------ 9ms Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: ------------------------------ 2ms Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: sendMpdCommand play took 2 milliseconds Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: Aug 31 18:18:11 volumio-pi3b volumio[1146]: ---------------------------- MPD announces state update: player Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: ControllerMpd::getState Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand status Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: Aug 31 18:18:11 volumio-pi3b volumio[1146]: ---------------------------- MPD announces state update: player Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: ControllerMpd::getState Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand status Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: sendMpdCommand status took 2 milliseconds Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseState Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: sendMpdCommand status took 3 milliseconds Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseState Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseTrackInfo Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: ControllerMpd::pushState Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreCommandRouter::servicePushState Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: STATE SERVICE {"status":"play","position":0,"seek":252,"duration":394,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"424 Kbps","isStreaming":false,"title":"Buenos Aires Hora Cero","artist":"Gidon Kremer","album":"High Fidelity Reference CD No. 26","uri":"USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac","trackType":"flac"} Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: CURRENT POSITION 0 Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState stateService play Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState currentStatus stop Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: ------------------------------ 7ms Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseTrackInfo Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: ControllerMpd::pushState Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreCommandRouter::servicePushState Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1215,"duration":394,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"404 Kbps","isStreaming":false,"title":"Buenos Aires Hora Cero","artist":"Gidon Kremer","album":"High Fidelity Reference CD No. 26","uri":"USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac","trackType":"flac"} Aug 31 18:18:11 volumio-pi3b volumio[1146]: verbose: CURRENT POSITION 0 Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState stateService play Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState currentStatus play Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: Received an update from plugin. extracting info from payload Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:11 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:11.389+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_PLAYING positionMs=1215 volume=100 Aug 31 18:18:11 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:11.390+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:11 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:11.391+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_PLAYING positionMs=1215 volume=100 Aug 31 18:18:11 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:11.392+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:11 volumio-pi3b volumio[1146]: info: ------------------------------ 28ms Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: Preload queue cleared Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::ClearQueue Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::stop Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::stPlaybackTimer Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::updateTrackBlock Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrackBlock Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::serviceStop Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreCommandRouter::serviceStop Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: ControllerMpd::stop Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CorePlayQueue::clearPlayQueue Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CorePlayQueue::saveQueue Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushQueue Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::addQueueItems Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CorePlayQueue::addQueueItems Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: Preload queue cleared Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: Adding Item to queue: music-library/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: Using cached record of: music-library/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac Aug 31 18:18:13 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:13.015+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_STOPPED positionMs=0 volume=100 Aug 31 18:18:13 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:13.016+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushQueue Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CorePlayQueue::saveQueue Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::updateTrackBlock Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrackBlock Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPlay Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::play index 0 Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::stop Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::play index undefined Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::startPlaybackTimer Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioGetVisibleSources Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::clearAddPlayTracks USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand stop Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: Aug 31 18:18:13 volumio-pi3b volumio[1146]: ---------------------------- MPD announces state update: player Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: sendMpdCommand stop took 24 milliseconds Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: ControllerMpd::getState Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand status Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: sendMpdCommand stop took 8 milliseconds Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand clear Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: Aug 31 18:18:13 volumio-pi3b volumio[1146]: ---------------------------- MPD announces system playlist update Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: Ignoring MPD Status Update Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: sendMpdCommand status took 3 milliseconds Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: sendMpdCommand clear took 2 milliseconds Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseState Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand add "USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" Aug 31 18:18:13 volumio-pi3b volumio[1146]: error: updateQueue error: null Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: Aug 31 18:18:13 volumio-pi3b volumio[1146]: ---------------------------- MPD announces system playlist update Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: Ignoring MPD Status Update Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: ------------------------------ 3ms Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: sendMpdCommand add "USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" took 2 milliseconds Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseTrackInfo Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand play Aug 31 18:18:13 volumio-pi3b volumio[1146]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: ------------------------------ 8ms Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: ------------------------------ 3ms Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: sendMpdCommand play took 2 milliseconds Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: Aug 31 18:18:13 volumio-pi3b volumio[1146]: ---------------------------- MPD announces state update: player Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: ControllerMpd::getState Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand status Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: Aug 31 18:18:13 volumio-pi3b volumio[1146]: ---------------------------- MPD announces state update: player Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: sendMpdCommand status took 7 milliseconds Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: ControllerMpd::getState Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand status Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseState Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: sendMpdCommand status took 2 milliseconds Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseState Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseTrackInfo Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: ControllerMpd::pushState Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreCommandRouter::servicePushState Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":394,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Buenos Aires Hora Cero","artist":"Gidon Kremer","album":"High Fidelity Reference CD No. 26","uri":"USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac","trackType":"flac"} Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: CURRENT POSITION 0 Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState stateService play Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState currentStatus stop Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: ------------------------------ 13ms Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseTrackInfo Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: ControllerMpd::pushState Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreCommandRouter::servicePushState Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1215,"duration":394,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"381 Kbps","isStreaming":false,"title":"Buenos Aires Hora Cero","artist":"Gidon Kremer","album":"High Fidelity Reference CD No. 26","uri":"USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac","trackType":"flac"} Aug 31 18:18:13 volumio-pi3b volumio[1146]: verbose: CURRENT POSITION 0 Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState stateService play Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState currentStatus play Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: Received an update from plugin. extracting info from payload Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:13 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:13.082+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_PLAYING positionMs=1215 volume=100 Aug 31 18:18:13 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:13.083+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:13 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:13.084+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_PLAYING positionMs=1215 volume=100 Aug 31 18:18:13 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:13.084+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:13 volumio-pi3b volumio[1146]: info: ------------------------------ 27ms Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioSeek Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: CoreStateMachine::seek Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: TRACKBLOCK {"uri":"mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac","service":"mpd","name":"Buenos Aires Hora Cero","artist":"Gidon Kremer","album":"High Fidelity Reference CD No. 26","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=104&web=Gidon%20Kremer/High%20Fidelity%20Reference%20CD%20No.%2026/extralarge&path=%2FUSB%2FLaCie%2FGidon%20Kremer%2FHommage%20%C3%80%20Piazzolla&metadata=false","duration":394,"samplerate":"44.1 kHz","bitdepth":"16 bit","trackType":"flac","channels":2} Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: CoreStateMachine::startPlaybackTimer Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioGetVisibleSources Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: ControllerMpd::seek Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:20 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:20 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:20.738+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_PLAYING positionMs=118000 volume=100 Aug 31 18:18:20 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:20.739+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:21 volumio-pi3b volumio[1146]: error: null Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: Aug 31 18:18:21 volumio-pi3b volumio[1146]: ---------------------------- MPD announces state update: player Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: ControllerMpd::getState Aug 31 18:18:21 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand status Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: sendMpdCommand status took 1 milliseconds Aug 31 18:18:21 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseState Aug 31 18:18:21 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 31 18:18:21 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseTrackInfo Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: ControllerMpd::pushState Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: CoreCommandRouter::servicePushState Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:21 volumio-pi3b volumio[1146]: verbose: STATE SERVICE {"status":"play","position":0,"seek":118000,"duration":394,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"609 Kbps","isStreaming":false,"title":"Buenos Aires Hora Cero","artist":"Gidon Kremer","album":"High Fidelity Reference CD No. 26","uri":"USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac","trackType":"flac"} Aug 31 18:18:21 volumio-pi3b volumio[1146]: verbose: CURRENT POSITION 0 Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState stateService play Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState currentStatus play Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: Received an update from plugin. extracting info from payload Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:21 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:21.234+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_PLAYING positionMs=118000 volume=100 Aug 31 18:18:21 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:21.234+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:21 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:21.236+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_PLAYING positionMs=118000 volume=100 Aug 31 18:18:21 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:21.237+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:21 volumio-pi3b volumio[1146]: info: ------------------------------ 31ms Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioSeek Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CoreStateMachine::seek Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: TRACKBLOCK {"uri":"mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac","service":"mpd","name":"Buenos Aires Hora Cero","artist":"Gidon Kremer","album":"High Fidelity Reference CD No. 26","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=104&web=Gidon%20Kremer/High%20Fidelity%20Reference%20CD%20No.%2026/extralarge&path=%2FUSB%2FLaCie%2FGidon%20Kremer%2FHommage%20%C3%80%20Piazzolla&metadata=false","duration":394,"samplerate":"44.1 kHz","bitdepth":"16 bit","trackType":"flac","channels":2} Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CoreStateMachine::startPlaybackTimer Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioGetVisibleSources Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: ControllerMpd::seek Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:22 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:22.684+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_PLAYING positionMs=263000 volume=100 Aug 31 18:18:22 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:22.685+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:22 volumio-pi3b volumio[1146]: error: null Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: Aug 31 18:18:22 volumio-pi3b volumio[1146]: ---------------------------- MPD announces state update: player Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: ControllerMpd::getState Aug 31 18:18:22 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand status Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: sendMpdCommand status took 2 milliseconds Aug 31 18:18:22 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseState Aug 31 18:18:22 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 31 18:18:22 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseTrackInfo Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: ControllerMpd::pushState Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CoreCommandRouter::servicePushState Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:22 volumio-pi3b volumio[1146]: verbose: STATE SERVICE {"status":"play","position":0,"seek":263000,"duration":394,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"884 Kbps","isStreaming":false,"title":"Buenos Aires Hora Cero","artist":"Gidon Kremer","album":"High Fidelity Reference CD No. 26","uri":"USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac","trackType":"flac"} Aug 31 18:18:22 volumio-pi3b volumio[1146]: verbose: CURRENT POSITION 0 Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState stateService play Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState currentStatus play Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: Received an update from plugin. extracting info from payload Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:22 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:22.749+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_PLAYING positionMs=263000 volume=100 Aug 31 18:18:22 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:22.749+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:22 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:22.751+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_PLAYING positionMs=263000 volume=100 Aug 31 18:18:22 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:22.752+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:22 volumio-pi3b volumio[1146]: info: ------------------------------ 24ms Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioSeek Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreStateMachine::seek Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: TRACKBLOCK {"uri":"mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac","service":"mpd","name":"Buenos Aires Hora Cero","artist":"Gidon Kremer","album":"High Fidelity Reference CD No. 26","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=104&web=Gidon%20Kremer/High%20Fidelity%20Reference%20CD%20No.%2026/extralarge&path=%2FUSB%2FLaCie%2FGidon%20Kremer%2FHommage%20%C3%80%20Piazzolla&metadata=false","duration":394,"samplerate":"44.1 kHz","bitdepth":"16 bit","trackType":"flac","channels":2} Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreStateMachine::startPlaybackTimer Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioGetVisibleSources Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: ControllerMpd::seek Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:24 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:24.441+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_PLAYING positionMs=340000 volume=100 Aug 31 18:18:24 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:24.442+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:24 volumio-pi3b volumio[1146]: error: null Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: Aug 31 18:18:24 volumio-pi3b volumio[1146]: ---------------------------- MPD announces state update: player Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: ControllerMpd::getState Aug 31 18:18:24 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand status Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: sendMpdCommand status took 10 milliseconds Aug 31 18:18:24 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseState Aug 31 18:18:24 volumio-pi3b volumio[1146]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 31 18:18:24 volumio-pi3b volumio[1146]: verbose: ControllerMpd::parseTrackInfo Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: ControllerMpd::pushState Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreCommandRouter::servicePushState Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:24 volumio-pi3b volumio[1146]: verbose: STATE SERVICE {"status":"play","position":0,"seek":341215,"duration":394,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"590 Kbps","isStreaming":false,"title":"Buenos Aires Hora Cero","artist":"Gidon Kremer","album":"High Fidelity Reference CD No. 26","uri":"USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac","trackType":"flac"} Aug 31 18:18:24 volumio-pi3b volumio[1146]: verbose: CURRENT POSITION 0 Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState stateService play Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreStateMachine::syncState currentStatus play Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: Received an update from plugin. extracting info from payload Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreStateMachine::pushState Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioPushState Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output update for this device Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: MRS: Pushing multiroomSync output Aug 31 18:18:24 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:24.484+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_PLAYING positionMs=341215 volume=100 Aug 31 18:18:24 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:24.485+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" state=STATUS_PLAYING positionMs=341215 volume=100 Aug 31 18:18:24 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:24.486+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:24 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:24.486+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" id="mnt/USB/LaCie/Gidon Kremer/Hommage À Piazzolla/Piazzolla- Buenos Aires Hora Cero 08.flac" title="Buenos Aires Hora Cero" Aug 31 18:18:24 volumio-pi3b volumio[1146]: info: ------------------------------ 42ms Aug 31 18:18:32 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:32.483+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.185:60248 @ 0x290e9f0" latency=5.585181ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_SETUP_V1_INTERNET Aug 31 18:18:32 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:32.532+02:00 level=INFO msg="run WiFi scan" component=server type=REQUEST_TYPE_RUN_WIFI_SCAN peer="192.168.1.185:60248 @ 0x290e9f0" latency=2.692095ms timeout=1m0s Aug 31 18:18:36 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:36.079+02:00 level=INFO msg="emitting wifi scan event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" networks=31 Aug 31 18:18:36 volumio-pi3b volumio[1146]: info: Received Get System Info Aug 31 18:18:36 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 18:18:36 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 18:18:36 volumio-pi3b volumio[1146]: info: Discovery: Getting this device information Aug 31 18:18:36 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioGetState Aug 31 18:18:36 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:36 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 18:18:36 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:36.590+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" available=true connected=true macAddress=b8:27:eb:c3:38:d3 ip4Address=192.168.1.105/24 ip6Address= ssid="Jutlandica Crew WIFI" Aug 31 18:18:36 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 31 18:18:36 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 31 18:18:37 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:37.556+02:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 31 18:18:41 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:41.367+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.185:60248 @ 0x290e9f0" latency=8.688371ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_SETUP_V1_INTERNET Aug 31 18:18:41 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:41.404+02:00 level=INFO msg="run WiFi scan" component=server type=REQUEST_TYPE_RUN_WIFI_SCAN peer="192.168.1.185:60248 @ 0x290e9f0" latency=2.848532ms timeout=1m0s Aug 31 18:18:44 volumio-pi3b systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 31 18:18:44 volumio-pi3b systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 31 18:18:44 volumio-pi3b systemd[1]: setdatetime-helper.service: Consumed 1.169s CPU time. Aug 31 18:18:44 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:44.988+02:00 level=INFO msg="emitting wifi scan event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" networks=32 Aug 31 18:18:45 volumio-pi3b volumio[1146]: info: Received Get System Info Aug 31 18:18:45 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 18:18:45 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 18:18:45 volumio-pi3b volumio[1146]: info: Discovery: Getting this device information Aug 31 18:18:45 volumio-pi3b volumio[1146]: info: CoreCommandRouter::volumioGetState Aug 31 18:18:45 volumio-pi3b volumio[1146]: info: CorePlayQueue::getTrack 0 Aug 31 18:18:45 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 18:18:45 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 31 18:18:45 volumio-pi3b volumio[1146]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 31 18:18:45 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:45.504+02:00 level=INFO msg="emitting wifi info changed event" component=server peer="192.168.1.185:60248 @ 0x290e9f0" available=true connected=true macAddress=b8:27:eb:c3:38:d3 ip4Address=192.168.1.105/24 ip6Address= ssid="Jutlandica Crew WIFI" Aug 31 18:18:46 volumio-pi3b volumio5-onboarding[1513]: time=2026-08-31T18:18:46.468+02:00 level=INFO msg="service successfully established" component=discovery/localnet Aug 31 18:19:04 volumio-pi3b volumio[1146]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 18:19:04 volumio-pi3b volumio[1146]: Error: connect ETIMEDOUT 199.232.42.79:443 Aug 31 18:19:04 volumio-pi3b volumio[1146]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 31 18:19:04 volumio-pi3b volumio[1146]: errno: -110, Aug 31 18:19:04 volumio-pi3b volumio[1146]: code: 'ETIMEDOUT', Aug 31 18:19:04 volumio-pi3b volumio[1146]: syscall: 'connect', Aug 31 18:19:04 volumio-pi3b volumio[1146]: address: '199.232.42.79', Aug 31 18:19:04 volumio-pi3b volumio[1146]: port: 443 Aug 31 18:19:04 volumio-pi3b volumio[1146]: } Aug 31 18:19:04 volumio-pi3b volumio[1146]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 18:19:05 volumio-pi3b sudo[7726]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-31 18:18' Aug 31 18:19:05 volumio-pi3b sudo[7726]: 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"