Oct 17 11:20:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:00.076Z level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" latency=-632.81977ms timeout=10s endpoint=https://database.volumio.cloud duration=689.16161ms Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 17 11:20:00 rivo volumio[3247]: info: Discovery: Getting this device information Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::volumioGetState Oct 17 11:20:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 1 Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 17 11:20:00 rivo volumio[3247]: verbose: New Socket.io Connection to 192.168.2.198:3000 from 192.168.2.132 UA: Dart/3.13 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 17 11:20:00 rivo volumio[3247]: verbose: New Socket.io Connection to 192.168.2.198 from 192.168.2.132 UA: Mozilla/5.0 (Linux; Android 15; 23013PC75G Build/AQ3A.250226.002; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/154.0.8037.107 Mobile Safari/537.36 VolumioApp/6.261014.0 Engine version: 3 Transport: polling Total Clients: 8 Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::volumioGetVisibleSources Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::volumioGetState Oct 17 11:20:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 1 Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::volumioGetQueue Oct 17 11:20:00 rivo volumio[3247]: info: CoreStateMachine::getQueue Oct 17 11:20:00 rivo volumio[3247]: info: CorePlayQueue::getQueue Oct 17 11:20:00 rivo volumio[3247]: info: Listing playlists Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 17 11:20:00 rivo volumio[3247]: info: Received Get System Info Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 17 11:20:00 rivo volumio[3247]: info: Discovery: Getting this device information Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::volumioGetState Oct 17 11:20:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 1 Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::volumioGetState Oct 17 11:20:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 1 Oct 17 11:20:00 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 17 11:20:06 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 17 11:20:06 rivo volumio[3247]: info: CURURI: music-library/USB/Elements/Mijn muziek/Gotye Oct 17 11:20:06 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:08 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 17 11:20:08 rivo volumio[3247]: info: CURURI: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood Oct 17 11:20:08 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:08 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 17 11:20:08 rivo volumio[3247]: info: CURURI: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue Oct 17 11:20:08 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:08 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0001 Oct 17 11:20:08 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0002 Oct 17 11:20:08 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0003 Oct 17 11:20:08 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0004 Oct 17 11:20:08 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0005 Oct 17 11:20:08 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0006 Oct 17 11:20:08 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0007 Oct 17 11:20:08 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0008 Oct 17 11:20:08 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0009 Oct 17 11:20:08 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0010 Oct 17 11:20:08 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0011 Oct 17 11:20:09 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0001 in service mpd Oct 17 11:20:09 rivo volumio[3247]: error: scanFolder - failure to stat '/mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0001' Oct 17 11:20:09 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0002 in service mpd Oct 17 11:20:09 rivo volumio[3247]: error: scanFolder - failure to stat '/mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0002' Oct 17 11:20:09 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0003 in service mpd Oct 17 11:20:09 rivo volumio[3247]: error: scanFolder - failure to stat '/mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0003' Oct 17 11:20:09 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0004 in service mpd Oct 17 11:20:09 rivo volumio[3247]: error: scanFolder - failure to stat '/mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0004' Oct 17 11:20:09 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0005 in service mpd Oct 17 11:20:09 rivo volumio[3247]: error: scanFolder - failure to stat '/mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0005' Oct 17 11:20:09 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0006 in service mpd Oct 17 11:20:09 rivo volumio[3247]: error: scanFolder - failure to stat '/mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0006' Oct 17 11:20:09 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0007 in service mpd Oct 17 11:20:09 rivo volumio[3247]: error: scanFolder - failure to stat '/mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0007' Oct 17 11:20:09 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0008 in service mpd Oct 17 11:20:09 rivo volumio[3247]: error: scanFolder - failure to stat '/mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0008' Oct 17 11:20:09 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0009 in service mpd Oct 17 11:20:09 rivo volumio[3247]: error: scanFolder - failure to stat '/mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0009' Oct 17 11:20:09 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0010 in service mpd Oct 17 11:20:09 rivo volumio[3247]: error: scanFolder - failure to stat '/mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0010' Oct 17 11:20:09 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0011 in service mpd Oct 17 11:20:09 rivo volumio[3247]: error: scanFolder - failure to stat '/mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0011' Oct 17 11:20:11 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 17 11:20:11 rivo volumio[3247]: info: CURURI: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue Oct 17 11:20:11 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:14 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::ClearQueue Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::stop Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::stPlaybackTimer Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::updateTrackBlock Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrackBlock Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrack 1 Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::serviceStop Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrack 1 Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::serviceStop Oct 17 11:20:14 rivo volumio[3247]: info: ControllerMpd::stop Oct 17 11:20:14 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand stop Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::clearPlayQueue Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::saveQueue Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::volumioPushQueue Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::addQueueItems Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::addQueueItems Oct 17 11:20:14 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:14 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0001 Oct 17 11:20:14 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0001 Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.767Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.768Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="mnt/USB/Elements/Mijn muziek/Go West - [1985] - Go West/02 - Don't Look Down.flac" title="Don't Look Down" Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::volumioPushQueue Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::saveQueue Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::updateTrackBlock Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrackBlock Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::volumioPlay Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::play index 0 Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::addQueueItems Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::addQueueItems Oct 17 11:20:14 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:14 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0002 Oct 17 11:20:14 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0002 Oct 17 11:20:14 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0003 Oct 17 11:20:14 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0003 Oct 17 11:20:14 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0004 Oct 17 11:20:14 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0004 Oct 17 11:20:14 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0005 Oct 17 11:20:14 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0005 Oct 17 11:20:14 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0006 Oct 17 11:20:14 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0006 Oct 17 11:20:14 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0007 Oct 17 11:20:14 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0007 Oct 17 11:20:14 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0008 Oct 17 11:20:14 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0008 Oct 17 11:20:14 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0009 Oct 17 11:20:14 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0009 Oct 17 11:20:14 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0010 Oct 17 11:20:14 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0010 Oct 17 11:20:14 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0011 Oct 17 11:20:14 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue/track0011 Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::stop Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::volumioPushQueue Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::saveQueue Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::play index undefined Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::updateTrackBlock Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrackBlock Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:14 rivo volumio[3247]: info: MCU Signalled Playback Inactive Oct 17 11:20:14 rivo volumio[3247]: info: Oct 17 11:20:14 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:20:14 rivo volumio[3247]: info: sendMpdCommand stop took 125 milliseconds Oct 17 11:20:14 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:20:14 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:20:14 rivo volumio[3247]: info: sendMpdCommand status took 0 milliseconds Oct 17 11:20:14 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:20:14 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:20:14 rivo volumio[3247]: info: Oct 17 11:20:14 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:20:14 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:20:14 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:20:14 rivo volumio[3247]: info: Oct 17 11:20:14 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:20:14 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:20:14 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:20:14 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 17 11:20:14 rivo volumio[3247]: info: sendMpdCommand status took 2 milliseconds Oct 17 11:20:14 rivo volumio[3247]: info: sendMpdCommand status took 2 milliseconds Oct 17 11:20:14 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:20:14 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:20:14 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:20:14 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:20:14 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:20:14 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:14 rivo volumio[3247]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Don't Look Down","artist":"Go West","album":"Go West","uri":"USB/Elements/Mijn muziek/Go West - [1985] - Go West/02 - Don't Look Down.flac","trackType":"flac"} Oct 17 11:20:14 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::syncState stateService stop Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus stop Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:14 rivo volumio[3247]: info: No code Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.906Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.906Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id= title= Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.906Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.907Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id= title= Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.907Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.908Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id= title= Oct 17 11:20:14 rivo volumio[3247]: info: ------------------------------ 29ms Oct 17 11:20:14 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 24 milliseconds Oct 17 11:20:14 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 25 milliseconds Oct 17 11:20:14 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:20:14 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:20:14 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:14 rivo volumio[3247]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Don't Look Down","artist":"Go West","album":"Go West","uri":"USB/Elements/Mijn muziek/Go West - [1985] - Go West/02 - Don't Look Down.flac","trackType":"flac"} Oct 17 11:20:14 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::syncState stateService stop Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus stop Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:14 rivo volumio[3247]: info: No code Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:14 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:14 rivo volumio[3247]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Don't Look Down","artist":"Go West","album":"Go West","uri":"USB/Elements/Mijn muziek/Go West - [1985] - Go West/02 - Don't Look Down.flac","trackType":"flac"} Oct 17 11:20:14 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::syncState stateService stop Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus stop Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:14 rivo volumio[3247]: info: No code Oct 17 11:20:14 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:14 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:14 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:14 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.942Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.942Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.943Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id= title= Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.943Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id= title= Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.944Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.945Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id= title= Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.945Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.946Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id= title= Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.947Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.948Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id= title= Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.948Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:14 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:14.949Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id= title= Oct 17 11:20:14 rivo volumio[3247]: info: ------------------------------ 65ms Oct 17 11:20:14 rivo volumio[3247]: info: ------------------------------ 65ms Oct 17 11:20:18 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:18 rivo volumio[3247]: info: Oct 17 11:20:18 rivo volumio[3247]: [1792236018522] ---------------------------- Client requests add and Play Volumio CUE entry Oct 17 11:20:18 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: mpd , addPlayCue Oct 17 11:20:18 rivo volumio[3247]: info: Adding CUE individual entry: 0 USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue Oct 17 11:20:18 rivo volumio[3247]: info: CoreCommandRouter::volumioAddQueueItems Oct 17 11:20:18 rivo volumio[3247]: info: CoreStateMachine::addQueueItems Oct 17 11:20:18 rivo volumio[3247]: info: CorePlayQueue::addQueueItems Oct 17 11:20:18 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:18 rivo volumio[3247]: info: Adding Item to queue: cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0 Oct 17 11:20:18 rivo volumio[3247]: info: Exploding uri cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0 in service mpd Oct 17 11:20:18 rivo volumio[3247]: info: CoreCommandRouter::volumioPlay Oct 17 11:20:18 rivo volumio[3247]: info: CoreStateMachine::play index 0 Oct 17 11:20:18 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:18 rivo volumio[3247]: info: CoreStateMachine::stop Oct 17 11:20:18 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:18 rivo volumio[3247]: info: CoreStateMachine::play index undefined Oct 17 11:20:18 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:18 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:18 rivo volumio[3247]: info: CoreCommandRouter::volumioPushQueue Oct 17 11:20:18 rivo volumio[3247]: info: CorePlayQueue::saveQueue Oct 17 11:20:18 rivo volumio[3247]: info: CoreStateMachine::updateTrackBlock Oct 17 11:20:18 rivo volumio[3247]: info: CorePlayQueue::getTrackBlock Oct 17 11:20:24 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 17 11:20:24 rivo volumio[3247]: info: CURURI: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue Oct 17 11:20:24 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:27 rivo volumio[3247]: info: CoreCommandRouter::volumioPlay Oct 17 11:20:27 rivo volumio[3247]: info: CoreStateMachine::play index undefined Oct 17 11:20:27 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:27 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:27 rivo volumio[3247]: info: CoreStateMachine::startPlaybackTimer Oct 17 11:20:27 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:27 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand stop Oct 17 11:20:27 rivo volumio[3247]: info: sendMpdCommand stop took 0 milliseconds Oct 17 11:20:27 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand clear Oct 17 11:20:27 rivo volumio[3247]: info: Oct 17 11:20:27 rivo volumio[3247]: ---------------------------- MPD announces system playlist update Oct 17 11:20:27 rivo volumio[3247]: info: Ignoring MPD Status Update Oct 17 11:20:27 rivo volumio[3247]: info: sendMpdCommand clear took 1 milliseconds Oct 17 11:20:27 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand load "USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue" Oct 17 11:20:27 rivo volumio[3247]: info: Oct 17 11:20:27 rivo volumio[3247]: ---------------------------- MPD announces system playlist update Oct 17 11:20:27 rivo volumio[3247]: info: Ignoring MPD Status Update Oct 17 11:20:27 rivo volumio[3247]: info: Oct 17 11:20:27 rivo volumio[3247]: ---------------------------- MPD announces system playlist update Oct 17 11:20:27 rivo volumio[3247]: info: Ignoring MPD Status Update Oct 17 11:20:27 rivo volumio[3247]: error: updateQueue error: null Oct 17 11:20:27 rivo volumio[3247]: info: ------------------------------ 4ms Oct 17 11:20:27 rivo volumio[3247]: info: Oct 17 11:20:27 rivo volumio[3247]: ---------------------------- MPD announces system playlist update Oct 17 11:20:27 rivo volumio[3247]: info: Ignoring MPD Status Update Oct 17 11:20:27 rivo volumio[3247]: info: sendMpdCommand load "USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue" took 4 milliseconds Oct 17 11:20:27 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand play Oct 17 11:20:27 rivo volumio[3247]: info: ------------------------------ 6ms Oct 17 11:20:27 rivo volumio[3247]: info: ------------------------------ 18ms Oct 17 11:20:27 rivo volumio[3247]: info: Oct 17 11:20:27 rivo volumio[3247]: ---------------------------- MPD announces system playlist update Oct 17 11:20:27 rivo volumio[3247]: info: Ignoring MPD Status Update Oct 17 11:20:27 rivo volumio[3247]: info: Oct 17 11:20:27 rivo volumio[3247]: ---------------------------- MPD announces system playlist update Oct 17 11:20:27 rivo volumio[3247]: info: Ignoring MPD Status Update Oct 17 11:20:27 rivo volumio[3247]: info: ------------------------------ 21ms Oct 17 11:20:27 rivo volumio[3247]: info: sendMpdCommand play took 20 milliseconds Oct 17 11:20:27 rivo volumio[3247]: info: ------------------------------ 4ms Oct 17 11:20:27 rivo volumio[3247]: info: ------------------------------ 4ms Oct 17 11:20:27 rivo volumio[3247]: info: Oct 17 11:20:27 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:20:27 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:20:27 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:20:27 rivo volumio[3247]: info: Oct 17 11:20:27 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:20:27 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:20:27 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:20:27 rivo volumio[3247]: info: Oct 17 11:20:27 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:20:27 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:20:27 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:20:28 rivo volumio[3247]: info: sendMpdCommand status took 424 milliseconds Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:20:28 rivo volumio[3247]: info: Oct 17 11:20:28 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:20:28 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:20:28 rivo volumio[3247]: info: sendMpdCommand status took 426 milliseconds Oct 17 11:20:28 rivo volumio[3247]: info: sendMpdCommand status took 423 milliseconds Oct 17 11:20:28 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:20:28 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:20:28 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:28 rivo volumio[3247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":22,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"346 Kbps","isStreaming":false,"title":"Like Drawing Blood","artist":"Gotye","album":"Like Drawing Blood","uri":"USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.flac","trackType":"flac"} Oct 17 11:20:28 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::syncState stateService play Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus stop Oct 17 11:20:28 rivo volumio[3247]: info: ------------------------------ 437ms Oct 17 11:20:28 rivo volumio[3247]: info: Oct 17 11:20:28 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:20:28 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:20:28 rivo volumio[3247]: info: Oct 17 11:20:28 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:20:28 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:20:28 rivo volumio[3247]: info: sendMpdCommand status took 14 milliseconds Oct 17 11:20:28 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 13 milliseconds Oct 17 11:20:28 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 12 milliseconds Oct 17 11:20:28 rivo volumio[3247]: info: sendMpdCommand status took 4 milliseconds Oct 17 11:20:28 rivo volumio[3247]: info: sendMpdCommand status took 3 milliseconds Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:20:28 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:20:28 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:28 rivo volumio[3247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":596,"duration":22,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"383 Kbps","isStreaming":false,"title":"Like Drawing Blood","artist":"Gotye","album":"Like Drawing Blood","uri":"USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.flac","trackType":"flac"} Oct 17 11:20:28 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::syncState stateService play Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus play Oct 17 11:20:28 rivo volumio[3247]: info: Received an update from plugin. extracting info from payload Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:28 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:28 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:28 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:20:28 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:28 rivo volumio[3247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":710,"duration":22,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"365 Kbps","isStreaming":false,"title":"Like Drawing Blood","artist":"Gotye","album":"Like Drawing Blood","uri":"USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.flac","trackType":"flac"} Oct 17 11:20:28 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::syncState stateService play Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus play Oct 17 11:20:28 rivo volumio[3247]: info: Received an update from plugin. extracting info from payload Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:28 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:28 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.100Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=596 volume=100 Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.100Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.101Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=596 volume=100 Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.101Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.102Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=710 volume=100 Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.103Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.108Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=710 volume=100 Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.109Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:28 rivo volumio[3247]: info: ------------------------------ 495ms Oct 17 11:20:28 rivo volumio[3247]: info: ------------------------------ 495ms Oct 17 11:20:28 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 56 milliseconds Oct 17 11:20:28 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 56 milliseconds Oct 17 11:20:28 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 55 milliseconds Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:20:28 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:20:28 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:20:28 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:28 rivo volumio[3247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":22,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"408 Kbps","isStreaming":false,"title":"Like Drawing Blood","artist":"Gotye","album":"Like Drawing Blood","uri":"USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.flac","trackType":"flac"} Oct 17 11:20:28 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::syncState stateService play Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus play Oct 17 11:20:28 rivo volumio[3247]: info: Received an update from plugin. extracting info from payload Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:28 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:28 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:28 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:20:28 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:28 rivo volumio[3247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":22,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"408 Kbps","isStreaming":false,"title":"Like Drawing Blood","artist":"Gotye","album":"Like Drawing Blood","uri":"USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.flac","trackType":"flac"} Oct 17 11:20:28 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::syncState stateService play Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus play Oct 17 11:20:28 rivo volumio[3247]: info: Received an update from plugin. extracting info from payload Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:28 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:28 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:28 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:20:28 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:28 rivo volumio[3247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":22,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"408 Kbps","isStreaming":false,"title":"Like Drawing Blood","artist":"Gotye","album":"Like Drawing Blood","uri":"USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.flac","trackType":"flac"} Oct 17 11:20:28 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::syncState stateService play Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus play Oct 17 11:20:28 rivo volumio[3247]: info: Received an update from plugin. extracting info from payload Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:28 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:28 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:28 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:28 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:28 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.166Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=848 volume=100 Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.167Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.168Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=848 volume=100 Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.169Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.171Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=848 volume=100 Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.172Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=848 volume=100 Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.174Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=848 volume=100 Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.176Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=848 volume=100 Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.176Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.177Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.177Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:28 rivo volumio[3247]: info: ------------------------------ 131ms Oct 17 11:20:28 rivo volumio[3247]: info: ------------------------------ 122ms Oct 17 11:20:28 rivo volumio[3247]: info: ------------------------------ 121ms Oct 17 11:20:28 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:28.178Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:28 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:20:28 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:20:28 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:20:28 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:20:28 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:20:28 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:20:28 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:20:28 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:20:28 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:20:28 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:20:28 rivo volumio[3247]: info: MCU Signalled Playback Active Oct 17 11:20:40 rivo volumio[3247]: info: CoreCommandRouter::volumioNext Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::next Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::stop Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::stPlaybackTimer Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::updateTrackBlock Oct 17 11:20:40 rivo volumio[3247]: info: CorePlayQueue::getTrackBlock Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:40 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:40 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 11:20:40 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:40 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:40 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::serviceStop Oct 17 11:20:40 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:40 rivo volumio[3247]: info: CoreCommandRouter::serviceStop Oct 17 11:20:40 rivo volumio[3247]: info: ControllerMpd::stop Oct 17 11:20:40 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand stop Oct 17 11:20:40 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:40.828Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:40 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:40.828Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:40 rivo volumio[3247]: info: MCU Signalled Playback Inactive Oct 17 11:20:40 rivo volumio[3247]: info: Oct 17 11:20:40 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:20:40 rivo volumio[3247]: info: sendMpdCommand stop took 141 milliseconds Oct 17 11:20:40 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:20:40 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::play index undefined Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:40 rivo volumio[3247]: info: CorePlayQueue::getTrack 1 Oct 17 11:20:40 rivo volumio[3247]: info: Oct 17 11:20:40 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:20:40 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:20:40 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:20:40 rivo volumio[3247]: info: Oct 17 11:20:40 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:20:40 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:20:40 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:20:40 rivo volumio[3247]: info: sendMpdCommand status took 10 milliseconds Oct 17 11:20:40 rivo volumio[3247]: info: sendMpdCommand status took 5 milliseconds Oct 17 11:20:40 rivo volumio[3247]: info: sendMpdCommand status took 3 milliseconds Oct 17 11:20:40 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:20:40 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:20:40 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:20:40 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:20:40 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:20:40 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:20:40 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 17 11:20:40 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 17 11:20:40 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 17 11:20:40 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:20:40 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:20:40 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:20:40 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:20:40 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:40 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:40 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:40 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:40 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:40 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:40 rivo volumio[3247]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Like Drawing Blood","artist":"Gotye","album":"Like Drawing Blood","uri":"USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.flac","trackType":"flac"} Oct 17 11:20:40 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::syncState stateService stop Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus stop Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:40 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:40 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:40 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:40 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:40 rivo volumio[3247]: info: No code Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:40 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:40 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:40 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:40 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:40 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:20:40 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:40 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:40 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:40 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:40 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:40 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:40 rivo volumio[3247]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Like Drawing Blood","artist":"Gotye","album":"Like Drawing Blood","uri":"USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.flac","trackType":"flac"} Oct 17 11:20:40 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::syncState stateService stop Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus stop Oct 17 11:20:40 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:41 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:41 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:41 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:41 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:41 rivo volumio[3247]: info: No code Oct 17 11:20:41 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:41 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:41 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:41 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:41 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:41 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:20:41 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:20:41 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:41 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:41 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:41 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:41 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:41 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:41 rivo volumio[3247]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Like Drawing Blood","artist":"Gotye","album":"Like Drawing Blood","uri":"USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.flac","trackType":"flac"} Oct 17 11:20:41 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:20:41 rivo volumio[3247]: info: CoreStateMachine::syncState stateService stop Oct 17 11:20:41 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus stop Oct 17 11:20:41 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:41 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:41 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:41 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:41 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:41 rivo volumio[3247]: info: No code Oct 17 11:20:41 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:20:41 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:41 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:20:41 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:20:41 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.028Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.029Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.029Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.030Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.031Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.032Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.032Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.033Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.034Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.035Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.034Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.036Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.036Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.037Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.037Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.038Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.038Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:41 rivo volumio5-onboarding[3996]: time=2026-10-17T11:20:41.039Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0" title="Like Drawing Blood" Oct 17 11:20:41 rivo volumio[3247]: info: ------------------------------ 78ms Oct 17 11:20:41 rivo volumio[3247]: info: ------------------------------ 73ms Oct 17 11:20:41 rivo volumio[3247]: info: ------------------------------ 70ms Oct 17 11:20:46 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:46 rivo volumio[3247]: info: Oct 17 11:20:46 rivo volumio[3247]: [1792236046860] ---------------------------- Client requests add and Play Volumio CUE entry Oct 17 11:20:46 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: mpd , addPlayCue Oct 17 11:20:46 rivo volumio[3247]: info: Adding CUE individual entry: 0 USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue Oct 17 11:20:46 rivo volumio[3247]: info: CoreCommandRouter::volumioAddQueueItems Oct 17 11:20:46 rivo volumio[3247]: info: CoreStateMachine::addQueueItems Oct 17 11:20:46 rivo volumio[3247]: info: CorePlayQueue::addQueueItems Oct 17 11:20:46 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:46 rivo volumio[3247]: info: Adding Item to queue: cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0 Oct 17 11:20:46 rivo volumio[3247]: info: Exploding uri cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@0 in service mpd Oct 17 11:20:46 rivo volumio[3247]: info: CoreCommandRouter::volumioPlay Oct 17 11:20:46 rivo volumio[3247]: info: CoreStateMachine::play index 1 Oct 17 11:20:46 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:46 rivo volumio[3247]: info: CoreStateMachine::stop Oct 17 11:20:46 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:46 rivo volumio[3247]: info: CoreStateMachine::play index undefined Oct 17 11:20:46 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:46 rivo volumio[3247]: info: CorePlayQueue::getTrack 1 Oct 17 11:20:46 rivo volumio[3247]: info: CoreCommandRouter::volumioPushQueue Oct 17 11:20:46 rivo volumio[3247]: info: CorePlayQueue::saveQueue Oct 17 11:20:46 rivo volumio[3247]: info: CoreStateMachine::updateTrackBlock Oct 17 11:20:46 rivo volumio[3247]: info: CorePlayQueue::getTrackBlock Oct 17 11:20:53 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:53 rivo volumio[3247]: info: Oct 17 11:20:53 rivo volumio[3247]: [1792236053395] ---------------------------- Client requests add and Play Volumio CUE entry Oct 17 11:20:53 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: mpd , addPlayCue Oct 17 11:20:53 rivo volumio[3247]: info: Adding CUE individual entry: 1 USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue Oct 17 11:20:53 rivo volumio[3247]: info: CoreCommandRouter::volumioAddQueueItems Oct 17 11:20:53 rivo volumio[3247]: info: CoreStateMachine::addQueueItems Oct 17 11:20:53 rivo volumio[3247]: info: CorePlayQueue::addQueueItems Oct 17 11:20:53 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:53 rivo volumio[3247]: info: Adding Item to queue: cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@1 Oct 17 11:20:53 rivo volumio[3247]: info: Exploding uri cue://USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue@1 in service mpd Oct 17 11:20:53 rivo volumio[3247]: info: CoreCommandRouter::volumioPlay Oct 17 11:20:53 rivo volumio[3247]: info: CoreStateMachine::play index 1 Oct 17 11:20:53 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:53 rivo volumio[3247]: info: CoreStateMachine::stop Oct 17 11:20:53 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:53 rivo volumio[3247]: info: CoreStateMachine::play index undefined Oct 17 11:20:53 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:53 rivo volumio[3247]: info: CorePlayQueue::getTrack 1 Oct 17 11:20:53 rivo volumio[3247]: info: CoreCommandRouter::volumioPushQueue Oct 17 11:20:53 rivo volumio[3247]: info: CorePlayQueue::saveQueue Oct 17 11:20:53 rivo volumio[3247]: info: CoreStateMachine::updateTrackBlock Oct 17 11:20:53 rivo volumio[3247]: info: CorePlayQueue::getTrackBlock Oct 17 11:20:58 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 17 11:20:58 rivo volumio[3247]: info: CURURI: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011 Oct 17 11:20:58 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:58 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac Oct 17 11:20:58 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/02 - Easy Way Out.flac Oct 17 11:20:58 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/03 - Somebody That I Used To Know.flac Oct 17 11:20:58 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/04 - Eyes Wide Open.flac Oct 17 11:20:58 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/05 - Smoke And Mirrors.flac Oct 17 11:20:58 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/06 - I Feel Better.flac Oct 17 11:20:58 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/07 - In Your Light.flac Oct 17 11:20:58 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/08 - State Of The Art.flac Oct 17 11:20:58 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/09 - Don't Worry, We'll Be Watching You.flac Oct 17 11:20:58 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/10 - Giving Me A Chance.flac Oct 17 11:20:58 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/11 - Save Me.flac Oct 17 11:20:58 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/12 - Bronte.flac Oct 17 11:20:58 rivo volumio[3247]: info: Preloading song: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/Gotye - Making Mirrors.m3u Oct 17 11:20:58 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac in service mpd Oct 17 11:20:58 rivo volumio[3247]: info: ALBUMART /albumart?cacheid=269&web=Gotye/Making%20Mirrors/extralarge&path=%2Fmnt%2FUSB%2FElements%2FMijn%20muziek%2FGotye%2FGotye%20-%20Making%20Mirrors%20%5BFLAC%5D%202011%2F01%20-%20Making%20Mirrors.flac&metadata=false Oct 17 11:20:58 rivo volumio[3247]: info: URI /mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac Oct 17 11:20:58 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/02 - Easy Way Out.flac in service mpd Oct 17 11:20:58 rivo volumio[3247]: info: ALBUMART /albumart?cacheid=269&web=Gotye/Making%20Mirrors/extralarge&path=%2Fmnt%2FUSB%2FElements%2FMijn%20muziek%2FGotye%2FGotye%20-%20Making%20Mirrors%20%5BFLAC%5D%202011%2F02%20-%20Easy%20Way%20Out.flac&metadata=false Oct 17 11:20:58 rivo volumio[3247]: info: URI /mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/02 - Easy Way Out.flac Oct 17 11:20:58 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/03 - Somebody That I Used To Know.flac in service mpd Oct 17 11:20:58 rivo volumio[3247]: info: ALBUMART /albumart?cacheid=269&web=Gotye/Making%20Mirrors/extralarge&path=%2Fmnt%2FUSB%2FElements%2FMijn%20muziek%2FGotye%2FGotye%20-%20Making%20Mirrors%20%5BFLAC%5D%202011%2F03%20-%20Somebody%20That%20I%20Used%20To%20Know.flac&metadata=false Oct 17 11:20:58 rivo volumio[3247]: info: URI /mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/03 - Somebody That I Used To Know.flac Oct 17 11:20:58 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/04 - Eyes Wide Open.flac in service mpd Oct 17 11:20:58 rivo volumio[3247]: info: ALBUMART /albumart?cacheid=269&web=Gotye/Making%20Mirrors/extralarge&path=%2Fmnt%2FUSB%2FElements%2FMijn%20muziek%2FGotye%2FGotye%20-%20Making%20Mirrors%20%5BFLAC%5D%202011%2F04%20-%20Eyes%20Wide%20Open.flac&metadata=false Oct 17 11:20:58 rivo volumio[3247]: info: URI /mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/04 - Eyes Wide Open.flac Oct 17 11:20:58 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/05 - Smoke And Mirrors.flac in service mpd Oct 17 11:20:58 rivo volumio[3247]: info: ALBUMART /albumart?cacheid=269&web=Gotye/Making%20Mirrors/extralarge&path=%2Fmnt%2FUSB%2FElements%2FMijn%20muziek%2FGotye%2FGotye%20-%20Making%20Mirrors%20%5BFLAC%5D%202011%2F05%20-%20Smoke%20And%20Mirrors.flac&metadata=false Oct 17 11:20:58 rivo volumio[3247]: info: URI /mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/05 - Smoke And Mirrors.flac Oct 17 11:20:59 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/06 - I Feel Better.flac in service mpd Oct 17 11:20:59 rivo volumio[3247]: info: ALBUMART /albumart?cacheid=269&web=Gotye/Making%20Mirrors/extralarge&path=%2Fmnt%2FUSB%2FElements%2FMijn%20muziek%2FGotye%2FGotye%20-%20Making%20Mirrors%20%5BFLAC%5D%202011%2F06%20-%20I%20Feel%20Better.flac&metadata=false Oct 17 11:20:59 rivo volumio[3247]: info: URI /mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/06 - I Feel Better.flac Oct 17 11:20:59 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/07 - In Your Light.flac in service mpd Oct 17 11:20:59 rivo volumio[3247]: info: ALBUMART /albumart?cacheid=269&web=Gotye/Making%20Mirrors/extralarge&path=%2Fmnt%2FUSB%2FElements%2FMijn%20muziek%2FGotye%2FGotye%20-%20Making%20Mirrors%20%5BFLAC%5D%202011%2F07%20-%20In%20Your%20Light.flac&metadata=false Oct 17 11:20:59 rivo volumio[3247]: info: URI /mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/07 - In Your Light.flac Oct 17 11:20:59 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/08 - State Of The Art.flac in service mpd Oct 17 11:20:59 rivo volumio[3247]: info: ALBUMART /albumart?cacheid=269&web=Gotye/Making%20Mirrors/extralarge&path=%2Fmnt%2FUSB%2FElements%2FMijn%20muziek%2FGotye%2FGotye%20-%20Making%20Mirrors%20%5BFLAC%5D%202011%2F08%20-%20State%20Of%20The%20Art.flac&metadata=false Oct 17 11:20:59 rivo volumio[3247]: info: URI /mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/08 - State Of The Art.flac Oct 17 11:20:59 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/09 - Don't Worry, We'll Be Watching You.flac in service mpd Oct 17 11:20:59 rivo volumio[3247]: info: ALBUMART /albumart?cacheid=269&web=Gotye/Making%20Mirrors/extralarge&path=%2Fmnt%2FUSB%2FElements%2FMijn%20muziek%2FGotye%2FGotye%20-%20Making%20Mirrors%20%5BFLAC%5D%202011%2F09%20-%20Don't%20Worry%2C%20We'll%20Be%20Watching%20You.flac&metadata=false Oct 17 11:20:59 rivo volumio[3247]: info: URI /mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/09 - Don't Worry, We'll Be Watching You.flac Oct 17 11:20:59 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/10 - Giving Me A Chance.flac in service mpd Oct 17 11:20:59 rivo volumio[3247]: info: ALBUMART /albumart?cacheid=269&web=Gotye/Making%20Mirrors/extralarge&path=%2Fmnt%2FUSB%2FElements%2FMijn%20muziek%2FGotye%2FGotye%20-%20Making%20Mirrors%20%5BFLAC%5D%202011%2F10%20-%20Giving%20Me%20A%20Chance.flac&metadata=false Oct 17 11:20:59 rivo volumio[3247]: info: URI /mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/10 - Giving Me A Chance.flac Oct 17 11:20:59 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/11 - Save Me.flac in service mpd Oct 17 11:20:59 rivo volumio[3247]: info: ALBUMART /albumart?cacheid=269&web=Gotye/Making%20Mirrors/extralarge&path=%2Fmnt%2FUSB%2FElements%2FMijn%20muziek%2FGotye%2FGotye%20-%20Making%20Mirrors%20%5BFLAC%5D%202011%2F11%20-%20Save%20Me.flac&metadata=false Oct 17 11:20:59 rivo volumio[3247]: info: URI /mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/11 - Save Me.flac Oct 17 11:20:59 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/12 - Bronte.flac in service mpd Oct 17 11:20:59 rivo volumio[3247]: info: ALBUMART /albumart?cacheid=269&web=Gotye/Making%20Mirrors/extralarge&path=%2Fmnt%2FUSB%2FElements%2FMijn%20muziek%2FGotye%2FGotye%20-%20Making%20Mirrors%20%5BFLAC%5D%202011%2F12%20-%20Bronte.flac&metadata=false Oct 17 11:20:59 rivo volumio[3247]: info: URI /mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/12 - Bronte.flac Oct 17 11:20:59 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/Gotye - Making Mirrors.m3u in service mpd Oct 17 11:20:59 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:59 rivo volumio[3247]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 17 11:20:59 rivo volumio[3247]: info: CoreStateMachine::ClearQueue Oct 17 11:20:59 rivo volumio[3247]: info: CoreStateMachine::stop Oct 17 11:20:59 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:59 rivo volumio[3247]: info: CorePlayQueue::clearPlayQueue Oct 17 11:20:59 rivo volumio[3247]: info: CorePlayQueue::saveQueue Oct 17 11:20:59 rivo volumio[3247]: info: CoreCommandRouter::volumioPushQueue Oct 17 11:20:59 rivo volumio[3247]: info: CoreStateMachine::addQueueItems Oct 17 11:20:59 rivo volumio[3247]: info: CorePlayQueue::addQueueItems Oct 17 11:20:59 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:59 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac Oct 17 11:20:59 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac Oct 17 11:20:59 rivo volumio[3247]: info: CoreCommandRouter::volumioPushQueue Oct 17 11:20:59 rivo volumio[3247]: info: CorePlayQueue::saveQueue Oct 17 11:20:59 rivo volumio[3247]: info: CoreStateMachine::updateTrackBlock Oct 17 11:20:59 rivo volumio[3247]: info: CorePlayQueue::getTrackBlock Oct 17 11:20:59 rivo volumio[3247]: info: CoreCommandRouter::volumioPlay Oct 17 11:20:59 rivo volumio[3247]: info: CoreStateMachine::play index 0 Oct 17 11:20:59 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:59 rivo volumio[3247]: info: CoreStateMachine::addQueueItems Oct 17 11:20:59 rivo volumio[3247]: info: CorePlayQueue::addQueueItems Oct 17 11:20:59 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:20:59 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/02 - Easy Way Out.flac Oct 17 11:20:59 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/02 - Easy Way Out.flac Oct 17 11:20:59 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/03 - Somebody That I Used To Know.flac Oct 17 11:20:59 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/03 - Somebody That I Used To Know.flac Oct 17 11:20:59 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/04 - Eyes Wide Open.flac Oct 17 11:20:59 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/04 - Eyes Wide Open.flac Oct 17 11:20:59 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/05 - Smoke And Mirrors.flac Oct 17 11:20:59 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/05 - Smoke And Mirrors.flac Oct 17 11:20:59 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/06 - I Feel Better.flac Oct 17 11:20:59 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/06 - I Feel Better.flac Oct 17 11:20:59 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/07 - In Your Light.flac Oct 17 11:20:59 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/07 - In Your Light.flac Oct 17 11:20:59 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/08 - State Of The Art.flac Oct 17 11:20:59 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/08 - State Of The Art.flac Oct 17 11:20:59 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/09 - Don't Worry, We'll Be Watching You.flac Oct 17 11:20:59 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/09 - Don't Worry, We'll Be Watching You.flac Oct 17 11:20:59 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/10 - Giving Me A Chance.flac Oct 17 11:20:59 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/10 - Giving Me A Chance.flac Oct 17 11:20:59 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/11 - Save Me.flac Oct 17 11:20:59 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/11 - Save Me.flac Oct 17 11:20:59 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/12 - Bronte.flac Oct 17 11:20:59 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/12 - Bronte.flac Oct 17 11:20:59 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/Gotye - Making Mirrors.m3u Oct 17 11:20:59 rivo volumio[3247]: info: Using cached record of: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/Gotye - Making Mirrors.m3u Oct 17 11:20:59 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/Making Mirrors.cue Oct 17 11:20:59 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/Making Mirrors.cue in service mpd Oct 17 11:20:59 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/Making Mirrors.cue Oct 17 11:20:59 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/Making Mirrors.cue in service mpd Oct 17 11:20:59 rivo volumio[3247]: info: CoreStateMachine::stop Oct 17 11:20:59 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:59 rivo volumio[3247]: info: CoreStateMachine::play index undefined Oct 17 11:20:59 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:20:59 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:59 rivo volumio[3247]: info: CoreStateMachine::startPlaybackTimer Oct 17 11:20:59 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:20:59 rivo volumio[3247]: verbose: ControllerMpd::clearAddPlayTracks USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac Oct 17 11:20:59 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand stop Oct 17 11:20:59 rivo volumio[3247]: info: CoreCommandRouter::volumioPushQueue Oct 17 11:20:59 rivo volumio[3247]: info: CorePlayQueue::saveQueue Oct 17 11:20:59 rivo volumio[3247]: info: CoreStateMachine::updateTrackBlock Oct 17 11:20:59 rivo volumio[3247]: info: CorePlayQueue::getTrackBlock Oct 17 11:20:59 rivo volumio[3247]: info: sendMpdCommand stop took 11 milliseconds Oct 17 11:20:59 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand clear Oct 17 11:20:59 rivo volumio[3247]: info: Oct 17 11:20:59 rivo volumio[3247]: ---------------------------- MPD announces system playlist update Oct 17 11:20:59 rivo volumio[3247]: info: Ignoring MPD Status Update Oct 17 11:20:59 rivo volumio[3247]: info: sendMpdCommand clear took 2 milliseconds Oct 17 11:20:59 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand add "USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac" Oct 17 11:20:59 rivo volumio[3247]: error: updateQueue error: null Oct 17 11:20:59 rivo volumio[3247]: info: Oct 17 11:20:59 rivo volumio[3247]: ---------------------------- MPD announces system playlist update Oct 17 11:20:59 rivo volumio[3247]: info: Ignoring MPD Status Update Oct 17 11:20:59 rivo volumio[3247]: info: ------------------------------ 3ms Oct 17 11:20:59 rivo volumio[3247]: info: sendMpdCommand add "USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac" took 2 milliseconds Oct 17 11:20:59 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand play Oct 17 11:20:59 rivo volumio[3247]: info: Oct 17 11:20:59 rivo volumio[3247]: ---------------------------- MPD announces system playlist update Oct 17 11:20:59 rivo volumio[3247]: info: Ignoring MPD Status Update Oct 17 11:20:59 rivo volumio[3247]: info: Oct 17 11:20:59 rivo volumio[3247]: ---------------------------- MPD announces system playlist update Oct 17 11:20:59 rivo volumio[3247]: info: Ignoring MPD Status Update Oct 17 11:20:59 rivo volumio[3247]: info: ------------------------------ 7ms Oct 17 11:20:59 rivo volumio[3247]: info: sendMpdCommand play took 6 milliseconds Oct 17 11:20:59 rivo volumio[3247]: info: ------------------------------ 5ms Oct 17 11:20:59 rivo volumio[3247]: info: ------------------------------ 5ms Oct 17 11:20:59 rivo volumio[3247]: info: Oct 17 11:20:59 rivo volumio[3247]: ---------------------------- MPD announces system playlist update Oct 17 11:20:59 rivo volumio[3247]: info: Ignoring MPD Status Update Oct 17 11:20:59 rivo volumio[3247]: info: Oct 17 11:20:59 rivo volumio[3247]: ---------------------------- MPD announces system playlist update Oct 17 11:20:59 rivo volumio[3247]: info: Ignoring MPD Status Update Oct 17 11:20:59 rivo volumio[3247]: info: ------------------------------ 2ms Oct 17 11:20:59 rivo volumio[3247]: info: ------------------------------ 1ms Oct 17 11:20:59 rivo volumio[3247]: info: Oct 17 11:20:59 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:20:59 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:20:59 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:20:59 rivo volumio[3247]: info: Oct 17 11:20:59 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:20:59 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:20:59 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:20:59 rivo volumio[3247]: info: Oct 17 11:20:59 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:20:59 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:20:59 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:21:00 rivo volumio[3247]: info: Oct 17 11:21:00 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:21:00 rivo volumio[3247]: info: sendMpdCommand status took 415 milliseconds Oct 17 11:21:00 rivo volumio[3247]: info: sendMpdCommand status took 414 milliseconds Oct 17 11:21:00 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:21:00 rivo volumio[3247]: info: sendMpdCommand status took 413 milliseconds Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:21:00 rivo volumio[3247]: info: Oct 17 11:21:00 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:21:00 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:21:00 rivo volumio[3247]: info: Oct 17 11:21:00 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:21:00 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:21:00 rivo volumio[3247]: info: sendMpdCommand status took 7 milliseconds Oct 17 11:21:00 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 17 11:21:00 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 17 11:21:00 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 17 11:21:00 rivo volumio[3247]: info: sendMpdCommand status took 4 milliseconds Oct 17 11:21:00 rivo volumio[3247]: info: sendMpdCommand status took 3 milliseconds Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::parseState Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 17 11:21:00 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:21:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:00 rivo volumio[3247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":61,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Making Mirrors","artist":"Gotye","album":"Making Mirrors","uri":"USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac","trackType":"flac"} Oct 17 11:21:00 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::syncState stateService play Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus stop Oct 17 11:21:00 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:21:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:00 rivo volumio[3247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":458,"duration":61,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"373 Kbps","isStreaming":false,"title":"Making Mirrors","artist":"Gotye","album":"Making Mirrors","uri":"USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac","trackType":"flac"} Oct 17 11:21:00 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::syncState stateService play Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus play Oct 17 11:21:00 rivo volumio[3247]: info: Received an update from plugin. extracting info from payload Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:21:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:21:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:21:00 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:21:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:00 rivo volumio[3247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":596,"duration":61,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"432 Kbps","isStreaming":false,"title":"Making Mirrors","artist":"Gotye","album":"Making Mirrors","uri":"USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac","trackType":"flac"} Oct 17 11:21:00 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::syncState stateService play Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus play Oct 17 11:21:00 rivo volumio[3247]: info: Received an update from plugin. extracting info from payload Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:21:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:21:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:21:00 rivo volumio[3247]: info: ------------------------------ 445ms Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.246Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=458 volume=100 Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.247Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac" title="Making Mirrors" Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.249Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=458 volume=100 Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.249Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac" title="Making Mirrors" Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.251Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=596 volume=100 Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.252Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac" title="Making Mirrors" Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.252Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=596 volume=100 Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.253Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac" title="Making Mirrors" Oct 17 11:21:00 rivo volumio[3247]: info: ------------------------------ 462ms Oct 17 11:21:00 rivo volumio[3247]: info: ------------------------------ 462ms Oct 17 11:21:00 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 40 milliseconds Oct 17 11:21:00 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 39 milliseconds Oct 17 11:21:00 rivo volumio[3247]: info: sendMpdCommand playlistinfo took 40 milliseconds Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:21:00 rivo volumio[3247]: verbose: ControllerMpd::parseTrackInfo Oct 17 11:21:00 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:21:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:00 rivo volumio[3247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":61,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"433 Kbps","isStreaming":false,"title":"Making Mirrors","artist":"Gotye","album":"Making Mirrors","uri":"USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac","trackType":"flac"} Oct 17 11:21:00 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::syncState stateService play Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus play Oct 17 11:21:00 rivo volumio[3247]: info: Received an update from plugin. extracting info from payload Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:21:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:21:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:21:00 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:21:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:00 rivo volumio[3247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":61,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"436 Kbps","isStreaming":false,"title":"Making Mirrors","artist":"Gotye","album":"Making Mirrors","uri":"USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac","trackType":"flac"} Oct 17 11:21:00 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::syncState stateService play Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus play Oct 17 11:21:00 rivo volumio[3247]: info: Received an update from plugin. extracting info from payload Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:21:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:21:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:21:00 rivo volumio[3247]: info: ControllerMpd::pushState Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::servicePushState Oct 17 11:21:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:00 rivo volumio[3247]: verbose: STATE SERVICE {"status":"play","position":0,"seek":848,"duration":61,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"436 Kbps","isStreaming":false,"title":"Making Mirrors","artist":"Gotye","album":"Making Mirrors","uri":"USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac","trackType":"flac"} Oct 17 11:21:00 rivo volumio[3247]: verbose: CURRENT POSITION 0 Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::syncState stateService play Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::syncState currentStatus play Oct 17 11:21:00 rivo volumio[3247]: info: Received an update from plugin. extracting info from payload Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:21:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:21:00 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:21:00 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:00 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:21:00 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.289Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=848 volume=100 Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.289Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac" title="Making Mirrors" Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.291Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=848 volume=100 Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.292Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac" title="Making Mirrors" Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.292Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=848 volume=100 Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.292Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac" title="Making Mirrors" Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.293Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=848 volume=100 Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.293Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=848 volume=100 Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.294Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac" title="Making Mirrors" Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.293Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac" title="Making Mirrors" Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.294Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_PLAYING positionMs=848 volume=100 Oct 17 11:21:00 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:00.295Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac" title="Making Mirrors" Oct 17 11:21:00 rivo volumio[3247]: info: ------------------------------ 94ms Oct 17 11:21:00 rivo volumio[3247]: info: ------------------------------ 90ms Oct 17 11:21:00 rivo volumio[3247]: info: ------------------------------ 88ms Oct 17 11:21:00 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:21:00 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:21:00 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:21:00 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:21:00 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:21:00 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:21:00 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:21:00 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:21:00 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:21:00 rivo volumio[3247]: info: Signalling Playback active due to playback status change Oct 17 11:21:00 rivo volumio[3247]: info: MCU Signalled Playback Active Oct 17 11:21:04 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:21:04 rivo volumio[3247]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 17 11:21:04 rivo volumio[3247]: info: CoreStateMachine::ClearQueue Oct 17 11:21:04 rivo volumio[3247]: info: CoreStateMachine::stop Oct 17 11:21:04 rivo volumio[3247]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 11:21:04 rivo volumio[3247]: info: CoreStateMachine::stPlaybackTimer Oct 17 11:21:04 rivo volumio[3247]: info: CoreStateMachine::updateTrackBlock Oct 17 11:21:04 rivo volumio[3247]: info: CorePlayQueue::getTrackBlock Oct 17 11:21:04 rivo volumio[3247]: info: CoreStateMachine::pushState Oct 17 11:21:04 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:04 rivo volumio[3247]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 11:21:04 rivo volumio[3247]: info: CoreCommandRouter::volumioPushState Oct 17 11:21:04 rivo volumio[3247]: info: MRS: Pushing multiroomSync output update for this device Oct 17 11:21:04 rivo volumio[3247]: info: MRS: Pushing multiroomSync output Oct 17 11:21:04 rivo volumio[3247]: info: CoreStateMachine::serviceStop Oct 17 11:21:04 rivo volumio[3247]: info: CorePlayQueue::getTrack 0 Oct 17 11:21:04 rivo volumio[3247]: info: CoreCommandRouter::serviceStop Oct 17 11:21:04 rivo volumio[3247]: info: ControllerMpd::stop Oct 17 11:21:04 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand stop Oct 17 11:21:04 rivo volumio[3247]: info: CorePlayQueue::clearPlayQueue Oct 17 11:21:04 rivo volumio[3247]: info: CorePlayQueue::saveQueue Oct 17 11:21:04 rivo volumio[3247]: info: CoreCommandRouter::volumioPushQueue Oct 17 11:21:04 rivo volumio[3247]: info: CoreStateMachine::addQueueItems Oct 17 11:21:04 rivo volumio[3247]: info: CorePlayQueue::addQueueItems Oct 17 11:21:04 rivo volumio[3247]: info: Preload queue cleared Oct 17 11:21:04 rivo volumio[3247]: info: Adding Item to queue: music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood Oct 17 11:21:04 rivo volumio[3247]: info: Exploding uri music-library/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood in service mpd Oct 17 11:21:04 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:04.504Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" state=STATUS_STOPPED positionMs=0 volume=100 Oct 17 11:21:04 rivo volumio5-onboarding[3996]: time=2026-10-17T11:21:04.504Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%10,192.168.2.132:49732 @ 0x2616330" id="mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Making Mirrors [FLAC] 2011/01 - Making Mirrors.flac" title="Making Mirrors" Oct 17 11:21:04 rivo volumio[3247]: info: MCU Signalled Playback Inactive Oct 17 11:21:04 rivo volumio[3247]: info: sendMpdCommand stop took 152 milliseconds Oct 17 11:21:04 rivo volumio[3247]: info: Oct 17 11:21:04 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:21:04 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:21:04 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:21:04 rivo volumio[3247]: info: Oct 17 11:21:04 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:21:04 rivo volumio[3247]: info: ControllerMpd::getState Oct 17 11:21:04 rivo volumio[3247]: verbose: ControllerMpd::sendMpdCommand status Oct 17 11:21:04 rivo volumio[3247]: info: Oct 17 11:21:04 rivo volumio[3247]: ---------------------------- MPD announces state update: player Oct 17 11:21:04 rivo volumio[3247]: info: ALBUMART /albumart?cacheid=269&web=Gotye/Like%20Drawing%20Blood/extralarge&path=%2Fmnt%2FUSB%2FElements%2FMijn%20muziek%2FGotye%2FGotye%20-%20Like%20Drawing%20Blood%2FGotye%20-%20Like%20Drawing%20Blood.cue&metadata=false Oct 17 11:21:04 rivo volumio[3247]: info: URI /mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue Oct 17 11:21:04 rivo volumio[3247]: info: ALBUMART /albumart?cacheid=269&web=Gotye/Like%20Drawing%20Blood/extralarge&path=%2Fmnt%2FUSB%2FElements%2FMijn%20muziek%2FGotye%2FGotye%20-%20Like%20Drawing%20Blood%2FGotye%20-%20Like%20Drawing%20Blood.cue&metadata=false Oct 17 11:21:04 rivo volumio[3247]: info: URI /mnt/USB/Elements/Mijn muziek/Gotye/Gotye - Like Drawing Blood/Gotye - Like Drawing Blood.cue Oct 17 11:21:04 rivo volumio[3247]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 11:21:04 rivo volumio[3247]: Error: Unable to resolve or reject the same promise twice Oct 17 11:21:04 rivo volumio[3247]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Oct 17 11:21:04 rivo volumio[3247]: at /volumio/app/plugins/music_service/mpd/index.js:2582:21 Oct 17 11:21:04 rivo volumio[3247]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Oct 17 11:21:04 rivo volumio[3247]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Oct 17 11:21:04 rivo volumio[3247]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Oct 17 11:21:04 rivo volumio[3247]: at Socket.emit (node:events:514:28) Oct 17 11:21:04 rivo volumio[3247]: at addChunk (node:internal/streams/readable:343:12) Oct 17 11:21:04 rivo volumio[3247]: at readableAddChunk (node:internal/streams/readable:312:11) Oct 17 11:21:04 rivo volumio[3247]: at Readable.push (node:internal/streams/readable:253:10) Oct 17 11:21:04 rivo volumio[3247]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Oct 17 11:21:04 rivo volumio[3247]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 11:21:05 rivo sudo[27101]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-17 11:20' Oct 17 11:21:05 rivo sudo[27101]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="8ed05bf20f96eb8557ed5652c420f84f39d66325" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0a52c1fb90959ba1872a2fb0225e56fe615b19ac" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed Sep 16 16:27:36 UTC 2026" VOLUMIO_VERSION="4.208" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="be0c94671215c2b1bf2440825a1e4211"