-- Logs begin at Mon 2026-02-23 17:51:15 MSK, end at Tue 2026-02-24 14:53:41 MSK. -- Feb 24 14:52:11 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: mpd , search Feb 24 14:52:11 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Feb 24 14:52:12 rivo volumio[5829]: info: searchQOBUZUri took 1190 milliseconds Feb 24 14:52:12 rivo volumio[5829]: info: All search sources collected, pushing search results Feb 24 14:52:12 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 24 14:52:12 rivo volumio[5829]: info: CURURI: artists://Fred%20Buccini Feb 24 14:52:12 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:52:12 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:52:12 rivo volumio[5829]: info: Preloading song: music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac Feb 24 14:52:12 rivo volumio[5829]: info: Preloading song: music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD2/07. Fred Buccini - I Love You For Sentimental Reasons.flac Feb 24 14:52:12 rivo volumio[5829]: info: Exploding uri music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac in service mpd Feb 24 14:52:12 rivo volumio[5829]: error: scanFolder - failure to stat '/mnt/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac' Feb 24 14:52:12 rivo volumio[5829]: info: Exploding uri music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD2/07. Fred Buccini - I Love You For Sentimental Reasons.flac in service mpd Feb 24 14:52:12 rivo volumio[5829]: error: scanFolder - failure to stat '/mnt/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD2/07. Fred Buccini - I Love You For Sentimental Reasons.flac' Feb 24 14:52:12 rivo volumio[5829]: info: Executing endpoint getSimilarArtists Feb 24 14:52:12 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 24 14:52:12 rivo volumio[5829]: info: Executing endpoint getSimilarArtists Feb 24 14:52:12 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 24 14:52:13 rivo volumio[5829]: info: Executing endpoint getSimilarArtists Feb 24 14:52:13 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 24 14:52:13 rivo volumio[5829]: info: Executing endpoint metavolumio Feb 24 14:52:13 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:52:13 rivo volumio[5829]: info: Executing endpoint metavolumio Feb 24 14:52:13 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:52:13 rivo volumio[5829]: info: Executing endpoint metavolumio Feb 24 14:52:13 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:52:20 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 24 14:52:20 rivo volumio[5829]: info: CURURI: artists://Fred%20Buccini/Covered%20in%20Gold%20CD1 Feb 24 14:52:20 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:52:20 rivo volumio[5829]: info: Executing endpoint getSimilarAlbums Feb 24 14:52:20 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Feb 24 14:52:23 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::ClearQueue Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::stop Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::stPlaybackTimer Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::updateTrackBlock Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrackBlock Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::serviceStop Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::serviceStop Feb 24 14:52:23 rivo volumio[5829]: info: [1771933943195] ControllerQobuz::stop Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 24 14:52:23 rivo volumio[5829]: info: ControllerMpd::stop Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::clearPlayQueue Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::saveQueue Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushQueue Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::addQueueItems Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::addQueueItems Feb 24 14:52:23 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:52:23 rivo volumio[5829]: info: Adding Item to queue: artists://Fred%20Buccini/Covered%20in%20Gold%20CD1 Feb 24 14:52:23 rivo volumio[5829]: info: Exploding uri artists://Fred%20Buccini/Covered%20in%20Gold%20CD1 in service mpd Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.214+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.215+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id=qobuz://song/42069606 title="Just the Two of Us" Feb 24 14:52:23 rivo volumio[5829]: info: Executing endpoint getSimilarAlbums Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Feb 24 14:52:23 rivo volumio[5829]: info: Feb 24 14:52:23 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:52:23 rivo volumio[5829]: info: sendMpdCommand stop took 70 milliseconds Feb 24 14:52:23 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushQueue Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::saveQueue Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::updateTrackBlock Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrackBlock Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPlay Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::play index 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::stop Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::play index undefined Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::startPlaybackTimer Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetVisibleSources Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 14:52:23 rivo volumio[5829]: info: Executing endpoint getSimilarAlbums Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Feb 24 14:52:23 rivo volumio[5829]: info: sendMpdCommand status took 41 milliseconds Feb 24 14:52:23 rivo volumio[5829]: info: sendMpdCommand stop took 14 milliseconds Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand clear Feb 24 14:52:23 rivo volumio[5829]: info: Feb 24 14:52:23 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:52:23 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:52:23 rivo volumio[5829]: info: Feb 24 14:52:23 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:52:23 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:52:23 rivo volumio[5829]: info: Feb 24 14:52:23 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:23 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:23 rivo volumio[5829]: info: sendMpdCommand playlistinfo took 11 milliseconds Feb 24 14:52:23 rivo volumio[5829]: info: sendMpdCommand clear took 10 milliseconds Feb 24 14:52:23 rivo volumio[5829]: info: sendMpdCommand status took 8 milliseconds Feb 24 14:52:23 rivo volumio[5829]: info: sendMpdCommand status took 6 milliseconds Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::parseTrackInfo Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:52:23 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: 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":"42069606","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/42069606","trackType":"qobuz"} Feb 24 14:52:23 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::syncState stateService stop Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus stop Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: No code Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 24 14:52:23 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::syncState stateService stop Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus stop Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: No code Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Feb 24 14:52:23 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::syncState stateService stop Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus stop Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: No code Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.521+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.522+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.531+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.532+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.533+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.535+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.536+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.539+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.540+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.541+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.547+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.549+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.550+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.551+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.556+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.556+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.559+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:52:23 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:23.561+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:23 rivo volumio[5829]: info: ------------------------------ 441ms Feb 24 14:52:23 rivo volumio[5829]: info: ------------------------------ 396ms Feb 24 14:52:23 rivo volumio[5829]: info: ------------------------------ 395ms Feb 24 14:52:23 rivo volumio[5829]: info: Feb 24 14:52:23 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:23 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:23 rivo volumio[5829]: info: Feb 24 14:52:23 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:23 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:23 rivo volumio[5829]: error: updateQueue error: null Feb 24 14:52:23 rivo volumio[5829]: info: Feb 24 14:52:23 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:23 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:23 rivo volumio[5829]: info: ------------------------------ 407ms Feb 24 14:52:23 rivo volumio[5829]: info: sendMpdCommand add "INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" took 402 milliseconds Feb 24 14:52:23 rivo volumio[5829]: info: ------------------------------ 14ms Feb 24 14:52:23 rivo volumio[5829]: info: ------------------------------ 12ms Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand play Feb 24 14:52:23 rivo volumio[5829]: info: Feb 24 14:52:23 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:23 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:23 rivo volumio[5829]: info: Feb 24 14:52:23 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:23 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:23 rivo volumio[5829]: info: Executing endpoint metavolumio Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:52:23 rivo volumio[5829]: info: Feb 24 14:52:23 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:52:23 rivo volumio[5829]: info: ------------------------------ 88ms Feb 24 14:52:23 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:52:23 rivo volumio[5829]: info: ------------------------------ 83ms Feb 24 14:52:23 rivo volumio[5829]: info: ------------------------------ 80ms Feb 24 14:52:23 rivo volumio[5829]: info: Feb 24 14:52:23 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:52:23 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:52:23 rivo volumio[5829]: info: Feb 24 14:52:23 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:52:23 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:52:23 rivo volumio[5829]: info: MCU Signalled Playback Inactive Feb 24 14:52:23 rivo volumio[5829]: error: MPD returned error for command status: Failed to decode /var/lib/mpd/music/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac; Failed to open '/var/lib/mpd/music/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac': Transport endpoint is not connected Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 24 14:52:23 rivo volumio[5829]: info: sendMpdCommand status took 24 milliseconds Feb 24 14:52:23 rivo volumio[5829]: error: MPD returned error for command status: Failed to decode /var/lib/mpd/music/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac; Failed to open '/var/lib/mpd/music/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac': Transport endpoint is not connected Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 24 14:52:23 rivo volumio[5829]: info: sendMpdCommand status took 24 milliseconds Feb 24 14:52:23 rivo volumio[5829]: error: MPD returned error for command status: Failed to decode /var/lib/mpd/music/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac; Failed to open '/var/lib/mpd/music/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac': Transport endpoint is not connected Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 24 14:52:23 rivo volumio[5829]: info: sendMpdCommand status took 24 milliseconds Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 14:52:23 rivo volumio[5829]: info: sendMpdCommand clearerror took 34 milliseconds Feb 24 14:52:23 rivo volumio[5829]: info: sendMpdCommand clearerror took 32 milliseconds Feb 24 14:52:23 rivo volumio[5829]: info: sendMpdCommand clearerror took 30 milliseconds Feb 24 14:52:23 rivo volumio[5829]: info: sendMpdCommand playlistinfo took 13 milliseconds Feb 24 14:52:23 rivo volumio[5829]: info: sendMpdCommand playlistinfo took 12 milliseconds Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::parseTrackInfo Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::parseTrackInfo Feb 24 14:52:23 rivo volumio[5829]: verbose: ControllerMpd::parseTrackInfo Feb 24 14:52:23 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: 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":"Unforgettable","artist":"Fred Buccini","album":"Covered in Gold CD1","uri":"INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac","trackType":"flac"} Feb 24 14:52:23 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::syncState stateService stop Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus stop Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: No code Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: 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":"Unforgettable","artist":"Fred Buccini","album":"Covered in Gold CD1","uri":"INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac","trackType":"flac"} Feb 24 14:52:23 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::syncState stateService stop Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus stop Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: No code Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: 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":"Unforgettable","artist":"Fred Buccini","album":"Covered in Gold CD1","uri":"INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac","trackType":"flac"} Feb 24 14:52:23 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::syncState stateService stop Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus stop Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:23 rivo volumio[5829]: info: No code Feb 24 14:52:23 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:23 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:23 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:23 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.070+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=433 volume=100 Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.071+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.075+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=433 volume=100 Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.076+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.079+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=433 volume=100 Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.080+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.083+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=433 volume=100 Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.084+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.087+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=433 volume=100 Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.089+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.090+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=433 volume=100 Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.092+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.094+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=433 volume=100 Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.096+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.099+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=433 volume=100 Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.100+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.102+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=433 volume=100 Feb 24 14:52:24 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:24.104+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:24 rivo volumio[5829]: info: ------------------------------ 386ms Feb 24 14:52:24 rivo volumio[5829]: info: ------------------------------ 385ms Feb 24 14:52:24 rivo volumio[5829]: info: ------------------------------ 385ms Feb 24 14:52:25 rivo volumio[5829]: info: Executing endpoint metavolumio Feb 24 14:52:25 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:52:25 rivo volumio[5829]: info: Executing endpoint metavolumio Feb 24 14:52:25 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:52:25 rivo volumio[5829]: info: Executing endpoint metavolumio Feb 24 14:52:25 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:52:27 rivo volumio[5829]: info: Executing endpoint metavolumio Feb 24 14:52:27 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:52:34 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::ClearQueue Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::stop Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::clearPlayQueue Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::saveQueue Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioPushQueue Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::addQueueItems Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::addQueueItems Feb 24 14:52:34 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:52:34 rivo volumio[5829]: info: Adding Item to queue: artists://Fred%20Buccini/Covered%20in%20Gold%20CD1 Feb 24 14:52:34 rivo volumio[5829]: info: Using cached record of: artists://Fred%20Buccini/Covered%20in%20Gold%20CD1 Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioPushQueue Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::saveQueue Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::updateTrackBlock Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrackBlock Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioPlay Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::play index 0 Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::stop Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::play index undefined Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::startPlaybackTimer Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioGetVisibleSources Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 14:52:34 rivo volumio[5829]: info: sendMpdCommand stop took 5 milliseconds Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand clear Feb 24 14:52:34 rivo volumio[5829]: info: Feb 24 14:52:34 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:34 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:34 rivo volumio[5829]: info: sendMpdCommand clear took 2 milliseconds Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" Feb 24 14:52:34 rivo volumio[5829]: info: Feb 24 14:52:34 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:34 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:34 rivo volumio[5829]: info: Feb 24 14:52:34 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:34 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:34 rivo volumio[5829]: error: updateQueue error: null Feb 24 14:52:34 rivo volumio[5829]: info: Feb 24 14:52:34 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:34 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:34 rivo volumio[5829]: info: ------------------------------ 8ms Feb 24 14:52:34 rivo volumio[5829]: info: sendMpdCommand add "INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" took 6 milliseconds Feb 24 14:52:34 rivo volumio[5829]: info: ------------------------------ 6ms Feb 24 14:52:34 rivo volumio[5829]: info: ------------------------------ 5ms Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand play Feb 24 14:52:34 rivo volumio[5829]: info: Feb 24 14:52:34 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:34 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:34 rivo volumio[5829]: info: Feb 24 14:52:34 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:34 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:34 rivo volumio[5829]: info: Feb 24 14:52:34 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:52:34 rivo volumio[5829]: info: ------------------------------ 9ms Feb 24 14:52:34 rivo volumio[5829]: info: sendMpdCommand play took 6 milliseconds Feb 24 14:52:34 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:52:34 rivo volumio[5829]: info: ------------------------------ 7ms Feb 24 14:52:34 rivo volumio[5829]: info: ------------------------------ 5ms Feb 24 14:52:34 rivo volumio[5829]: info: Feb 24 14:52:34 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:52:34 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:52:34 rivo volumio[5829]: info: Feb 24 14:52:34 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:52:34 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:52:34 rivo volumio[5829]: error: MPD returned error for command status: Failed to decode /var/lib/mpd/music/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac; Failed to open '/var/lib/mpd/music/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac': Transport endpoint is not connected Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 24 14:52:34 rivo volumio[5829]: info: sendMpdCommand status took 20 milliseconds Feb 24 14:52:34 rivo volumio[5829]: error: MPD returned error for command status: Failed to decode /var/lib/mpd/music/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac; Failed to open '/var/lib/mpd/music/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac': Transport endpoint is not connected Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 24 14:52:34 rivo volumio[5829]: info: sendMpdCommand status took 21 milliseconds Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 14:52:34 rivo volumio[5829]: error: MPD returned error for command status: Failed to decode /var/lib/mpd/music/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac; Failed to open '/var/lib/mpd/music/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac': Transport endpoint is not connected Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 24 14:52:34 rivo volumio[5829]: info: sendMpdCommand status took 43 milliseconds Feb 24 14:52:34 rivo volumio[5829]: info: sendMpdCommand clearerror took 28 milliseconds Feb 24 14:52:34 rivo volumio[5829]: info: sendMpdCommand clearerror took 25 milliseconds Feb 24 14:52:34 rivo volumio[5829]: info: sendMpdCommand playlistinfo took 16 milliseconds Feb 24 14:52:34 rivo volumio[5829]: info: sendMpdCommand playlistinfo took 15 milliseconds Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::parseTrackInfo Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::parseTrackInfo Feb 24 14:52:34 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: 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":"Unforgettable","artist":"Fred Buccini","album":"Covered in Gold CD1","uri":"INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac","trackType":"flac"} Feb 24 14:52:34 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::syncState stateService stop Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus stop Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:34 rivo volumio[5829]: info: No code Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:34 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: 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":"Unforgettable","artist":"Fred Buccini","album":"Covered in Gold CD1","uri":"INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac","trackType":"flac"} Feb 24 14:52:34 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::syncState stateService stop Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus stop Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:34 rivo volumio[5829]: info: No code Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.677+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.678+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.684+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.685+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.687+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.687+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.690+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.693+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.694+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.694+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.698+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.699+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:34 rivo volumio[5829]: info: ------------------------------ 322ms Feb 24 14:52:34 rivo volumio[5829]: info: ------------------------------ 321ms Feb 24 14:52:34 rivo volumio[5829]: info: sendMpdCommand clearerror took 321 milliseconds Feb 24 14:52:34 rivo volumio[5829]: info: sendMpdCommand playlistinfo took 317 milliseconds Feb 24 14:52:34 rivo volumio[5829]: verbose: ControllerMpd::parseTrackInfo Feb 24 14:52:34 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: 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":"Unforgettable","artist":"Fred Buccini","album":"Covered in Gold CD1","uri":"INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac","trackType":"flac"} Feb 24 14:52:34 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::syncState stateService stop Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus stop Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:34 rivo volumio[5829]: info: No code Feb 24 14:52:34 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:34 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:34 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:34 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.878+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=393 volume=100 Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.878+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.883+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=393 volume=100 Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.884+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.887+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=393 volume=100 Feb 24 14:52:34 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:34.888+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id="music-library/INTERNAL/Lounge/Vintage Cafe/2012. Vintage Cafe 7/CD1/14. Fred Buccini - Unforgettable.flac" title=Unforgettable Feb 24 14:52:34 rivo volumio[5829]: info: ------------------------------ 478ms Feb 24 14:52:36 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: mpd , search Feb 24 14:52:36 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Feb 24 14:52:37 rivo volumio[5829]: info: searchQOBUZUri took 880 milliseconds Feb 24 14:52:37 rivo volumio[5829]: info: All search sources collected, pushing search results Feb 24 14:52:37 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Feb 24 14:52:37 rivo volumio[5829]: info: handleBrowseUri took 720 milliseconds Feb 24 14:52:37 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:52:37 rivo volumio[5829]: info: Executing endpoint getSimilarArtists Feb 24 14:52:37 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 24 14:52:38 rivo volumio[5829]: info: Executing endpoint getSimilarArtists Feb 24 14:52:38 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 24 14:52:38 rivo volumio[5829]: info: Executing endpoint getSimilarArtists Feb 24 14:52:38 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 24 14:52:38 rivo volumio[5829]: info: Executing endpoint metavolumio Feb 24 14:52:38 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:52:40 rivo volumio[5829]: info: Executing endpoint metavolumio Feb 24 14:52:40 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:52:43 rivo volumio[5829]: info: Executing endpoint metavolumio Feb 24 14:52:43 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:52:45 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Feb 24 14:52:46 rivo volumio[5829]: info: handleBrowseUri took 239 milliseconds Feb 24 14:52:46 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:52:46 rivo volumio[5829]: info: Preloading song: qobuz://song/63373761 Feb 24 14:52:46 rivo volumio[5829]: info: Preloading song: qobuz://song/63373762 Feb 24 14:52:46 rivo volumio[5829]: info: Preloading song: qobuz://song/63373763 Feb 24 14:52:46 rivo volumio[5829]: info: Preloading song: qobuz://song/63373764 Feb 24 14:52:46 rivo volumio[5829]: info: Preloading song: qobuz://song/63373765 Feb 24 14:52:46 rivo volumio[5829]: info: Preloading song: qobuz://song/63373766 Feb 24 14:52:46 rivo volumio[5829]: info: Preloading song: qobuz://song/63373767 Feb 24 14:52:46 rivo volumio[5829]: info: Preloading song: qobuz://song/63373768 Feb 24 14:52:46 rivo volumio[5829]: info: Preloading song: qobuz://song/63373769 Feb 24 14:52:46 rivo volumio[5829]: info: Preloading song: qobuz://song/63373770 Feb 24 14:52:46 rivo volumio[5829]: info: Preloading song: qobuz://song/63373771 Feb 24 14:52:46 rivo volumio[5829]: info: Preloading song: qobuz://song/63373772 Feb 24 14:52:46 rivo volumio[5829]: info: Preloading song: qobuz://song/63373773 Feb 24 14:52:46 rivo volumio[5829]: info: Exploding uri qobuz://song/63373761 in service qobuz Feb 24 14:52:46 rivo volumio[5829]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 24 14:52:46 rivo volumio[5829]: info: Exploding uri qobuz://song/63373762 in service qobuz Feb 24 14:52:46 rivo volumio[5829]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 24 14:52:46 rivo volumio[5829]: info: Exploding uri qobuz://song/63373763 in service qobuz Feb 24 14:52:46 rivo volumio[5829]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 24 14:52:46 rivo volumio[5829]: info: Exploding uri qobuz://song/63373764 in service qobuz Feb 24 14:52:46 rivo volumio[5829]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 24 14:52:46 rivo volumio[5829]: info: Exploding uri qobuz://song/63373765 in service qobuz Feb 24 14:52:46 rivo volumio[5829]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 24 14:52:46 rivo volumio[5829]: info: Exploding uri qobuz://song/63373766 in service qobuz Feb 24 14:52:46 rivo volumio[5829]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 24 14:52:46 rivo volumio[5829]: info: Exploding uri qobuz://song/63373767 in service qobuz Feb 24 14:52:46 rivo volumio[5829]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 24 14:52:46 rivo volumio[5829]: info: explodeUri took 344 milliseconds Feb 24 14:52:46 rivo volumio[5829]: info: Exploding uri qobuz://song/63373768 in service qobuz Feb 24 14:52:46 rivo volumio[5829]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 24 14:52:46 rivo volumio[5829]: info: explodeUri took 336 milliseconds Feb 24 14:52:46 rivo volumio[5829]: info: Exploding uri qobuz://song/63373769 in service qobuz Feb 24 14:52:46 rivo volumio[5829]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 24 14:52:46 rivo volumio[5829]: info: explodeUri took 326 milliseconds Feb 24 14:52:46 rivo volumio[5829]: info: Exploding uri qobuz://song/63373770 in service qobuz Feb 24 14:52:46 rivo volumio[5829]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 24 14:52:46 rivo volumio[5829]: info: Exploding uri qobuz://song/63373771 in service qobuz Feb 24 14:52:46 rivo volumio[5829]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 24 14:52:46 rivo volumio[5829]: info: explodeUri took 373 milliseconds Feb 24 14:52:46 rivo volumio[5829]: info: Exploding uri qobuz://song/63373772 in service qobuz Feb 24 14:52:46 rivo volumio[5829]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 24 14:52:46 rivo volumio[5829]: info: explodeUri took 367 milliseconds Feb 24 14:52:46 rivo volumio[5829]: info: Exploding uri qobuz://song/63373773 in service qobuz Feb 24 14:52:46 rivo volumio[5829]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 24 14:52:46 rivo volumio[5829]: info: explodeUri took 369 milliseconds Feb 24 14:52:46 rivo volumio[5829]: info: explodeUri took 326 milliseconds Feb 24 14:52:47 rivo volumio[5829]: info: explodeUri took 372 milliseconds Feb 24 14:52:47 rivo volumio[5829]: info: explodeUri took 383 milliseconds Feb 24 14:52:47 rivo volumio[5829]: info: explodeUri took 355 milliseconds Feb 24 14:52:47 rivo volumio[5829]: info: explodeUri took 340 milliseconds Feb 24 14:52:47 rivo volumio[5829]: info: explodeUri took 334 milliseconds Feb 24 14:52:47 rivo volumio[5829]: info: explodeUri took 358 milliseconds Feb 24 14:52:47 rivo volumio[5829]: info: Executing endpoint getSimilarAlbums Feb 24 14:52:47 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Feb 24 14:52:49 rivo volumio[5829]: info: Executing endpoint getSimilarAlbums Feb 24 14:52:49 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Feb 24 14:52:49 rivo volumio[5829]: info: Executing endpoint getSimilarAlbums Feb 24 14:52:49 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Feb 24 14:52:49 rivo volumio[5829]: info: Executing endpoint metavolumio Feb 24 14:52:49 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:52:50 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:52:50 rivo volumio[5829]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 24 14:52:50 rivo volumio[5829]: info: CoreStateMachine::ClearQueue Feb 24 14:52:50 rivo volumio[5829]: info: CoreStateMachine::stop Feb 24 14:52:50 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 14:52:50 rivo volumio[5829]: info: CorePlayQueue::clearPlayQueue Feb 24 14:52:50 rivo volumio[5829]: info: CorePlayQueue::saveQueue Feb 24 14:52:50 rivo volumio[5829]: info: CoreCommandRouter::volumioPushQueue Feb 24 14:52:50 rivo volumio[5829]: info: CoreStateMachine::addQueueItems Feb 24 14:52:50 rivo volumio[5829]: info: CorePlayQueue::addQueueItems Feb 24 14:52:50 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:52:50 rivo volumio[5829]: info: Adding Item to queue: qobuz://album/vgkg9w5fh5v8b Feb 24 14:52:50 rivo volumio[5829]: info: Exploding uri qobuz://album/vgkg9w5fh5v8b in service qobuz Feb 24 14:52:50 rivo volumio[5829]: https://prod.vlmapi.io/v2/qobuz/explodeUri Feb 24 14:52:50 rivo volumio[5829]: info: explodeUri took 249 milliseconds Feb 24 14:52:50 rivo volumio[5829]: info: CoreCommandRouter::volumioPushQueue Feb 24 14:52:50 rivo volumio[5829]: info: CorePlayQueue::saveQueue Feb 24 14:52:50 rivo volumio[5829]: info: CoreStateMachine::updateTrackBlock Feb 24 14:52:50 rivo volumio[5829]: info: CorePlayQueue::getTrackBlock Feb 24 14:52:50 rivo volumio[5829]: info: CoreCommandRouter::volumioPlay Feb 24 14:52:50 rivo volumio[5829]: info: CoreStateMachine::play index 0 Feb 24 14:52:50 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 14:52:50 rivo volumio[5829]: info: CoreStateMachine::stop Feb 24 14:52:50 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 14:52:50 rivo volumio[5829]: info: CoreStateMachine::play index undefined Feb 24 14:52:50 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 14:52:50 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:50 rivo volumio[5829]: info: CoreStateMachine::startPlaybackTimer Feb 24 14:52:50 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:50 rivo volumio[5829]: info: [1771933970746] ControllerQobuz::clearAddPlayTrack Feb 24 14:52:50 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 14:52:50 rivo volumio[5829]: info: sendMpdCommand stop took 6 milliseconds Feb 24 14:52:50 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand clear Feb 24 14:52:50 rivo volumio[5829]: info: Feb 24 14:52:50 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:50 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:50 rivo volumio[5829]: info: sendMpdCommand clear took 2 milliseconds Feb 24 14:52:50 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/63373761" Feb 24 14:52:50 rivo volumio[5829]: info: Feb 24 14:52:50 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:50 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:50 rivo volumio[5829]: info: Feb 24 14:52:50 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:50 rivo volumio[5829]: STREAMING PROXY: Handling url /?data=qobuz://song/63373761 Feb 24 14:52:50 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:50 rivo volumio[5829]: error: updateQueue error: null Feb 24 14:52:50 rivo volumio[5829]: info: ------------------------------ 6ms Feb 24 14:52:50 rivo volumio[5829]: info: Executing endpoint getStreamUrlqobuz Feb 24 14:52:50 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 24 14:52:51 rivo volumio[5829]: info: getStreamUrl took 277 milliseconds Feb 24 14:52:51 rivo volumio[5829]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3282062&eid=63373761&fmt=6&profile=raw&app_id=539451548&cid=3831380&etsp=1771937570&hmac=R4wfhHL-w7mLuRIGR_mHbfqbiOQ Feb 24 14:52:51 rivo volumio[5829]: STREAMING PROXY: Requesting upstream with range: none Feb 24 14:52:51 rivo volumio[5829]: STREAMING PROXY: Upstream status code: 200 Feb 24 14:52:51 rivo volumio[5829]: error: updateQueue error: null Feb 24 14:52:51 rivo volumio[5829]: error: updateQueue error: null Feb 24 14:52:51 rivo volumio[5829]: STREAMING PROXY: Client closed connection Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/63373761" Feb 24 14:52:51 rivo volumio[5829]: info: ------------------------------ 665ms Feb 24 14:52:51 rivo volumio[5829]: STREAMING PROXY: Upstream closed. Received 586 bytes Feb 24 14:52:51 rivo volumio[5829]: info: ------------------------------ 664ms Feb 24 14:52:51 rivo volumio[5829]: STREAMING PROXY: Incomplete transfer. Expected 34221705, got 586 Feb 24 14:52:51 rivo volumio[5829]: STREAMING PROXY: Retrying with range: bytes=586- (attempt 1) Feb 24 14:52:51 rivo volumio[5829]: info: Feb 24 14:52:51 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:51 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:51 rivo volumio[5829]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/63373761" took 3 milliseconds Feb 24 14:52:51 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand play Feb 24 14:52:51 rivo volumio[5829]: info: Feb 24 14:52:51 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:51 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:51 rivo volumio[5829]: info: Feb 24 14:52:51 rivo volumio[5829]: ---------------------------- MPD announces system playlist update Feb 24 14:52:51 rivo volumio[5829]: STREAMING PROXY: Handling url /?data=qobuz://song/63373761 Feb 24 14:52:51 rivo volumio[5829]: info: Ignoring MPD Status Update Feb 24 14:52:51 rivo volumio[5829]: info: ------------------------------ 7ms Feb 24 14:52:51 rivo volumio[5829]: info: sendMpdCommand play took 6 milliseconds Feb 24 14:52:51 rivo volumio[5829]: info: ------------------------------ 5ms Feb 24 14:52:51 rivo volumio[5829]: info: ------------------------------ 3ms Feb 24 14:52:51 rivo volumio[5829]: info: Executing endpoint getStreamUrlqobuz Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Feb 24 14:52:51 rivo volumio[5829]: info: getStreamUrl took 317 milliseconds Feb 24 14:52:51 rivo volumio[5829]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3282062&eid=63373761&fmt=6&profile=raw&app_id=539451548&cid=3831380&etsp=1771937571&hmac=jvD6k2tIENRtVbVSmXeM2OMUoVs Feb 24 14:52:51 rivo volumio[5829]: STREAMING PROXY: Requesting upstream with range: none Feb 24 14:52:51 rivo volumio[5829]: STREAMING PROXY: Upstream status code: 200 Feb 24 14:52:51 rivo volumio[5829]: info: Feb 24 14:52:51 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:52:51 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:52:51 rivo volumio[5829]: info: Feb 24 14:52:51 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:52:51 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:52:51 rivo volumio[5829]: info: Feb 24 14:52:51 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:52:51 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:52:51 rivo volumio[5829]: info: Feb 24 14:52:51 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:52:51 rivo volumio[5829]: info: sendMpdCommand status took 13 milliseconds Feb 24 14:52:51 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 14:52:51 rivo volumio[5829]: info: sendMpdCommand status took 15 milliseconds Feb 24 14:52:51 rivo volumio[5829]: info: sendMpdCommand status took 14 milliseconds Feb 24 14:52:51 rivo volumio[5829]: info: sendMpdCommand status took 3 milliseconds Feb 24 14:52:51 rivo volumio[5829]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::parseTrackInfo Feb 24 14:52:51 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:52:51 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:51 rivo volumio[5829]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":294,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"63373761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/63373761","trackType":"qobuz"} Feb 24 14:52:51 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:52:51 rivo volumio[5829]: info: CoreStateMachine::syncState stateService play Feb 24 14:52:51 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus stop Feb 24 14:52:51 rivo volumio[5829]: info: ------------------------------ 29ms Feb 24 14:52:51 rivo volumio[5829]: info: Feb 24 14:52:51 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:52:51 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:52:51 rivo volumio[5829]: info: Feb 24 14:52:51 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:52:51 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:52:51 rivo volumio[5829]: info: sendMpdCommand playlistinfo took 15 milliseconds Feb 24 14:52:51 rivo volumio[5829]: info: sendMpdCommand playlistinfo took 14 milliseconds Feb 24 14:52:51 rivo volumio[5829]: info: sendMpdCommand status took 7 milliseconds Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::parseTrackInfo Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:52:51 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 14:52:51 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:52:51 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:51 rivo volumio[5829]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":294,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"63373761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/63373761","trackType":"qobuz"} Feb 24 14:52:51 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:52:51 rivo volumio[5829]: info: CoreStateMachine::syncState stateService play Feb 24 14:52:51 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus play Feb 24 14:52:51 rivo volumio[5829]: info: Received an update from plugin. extracting info from payload Feb 24 14:52:51 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:51 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:51 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:51 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:51 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:51 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:51 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:52:51 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:51 rivo volumio[5829]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":294,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"63373761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/63373761","trackType":"qobuz"} Feb 24 14:52:51 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:52:51 rivo volumio[5829]: info: CoreStateMachine::syncState stateService play Feb 24 14:52:51 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus play Feb 24 14:52:51 rivo volumio[5829]: info: Received an update from plugin. extracting info from payload Feb 24 14:52:51 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:51 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:51 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:51 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:51 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:51 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:51 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:52:51 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:51 rivo volumio[5829]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":294,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"63373761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/63373761","trackType":"qobuz"} Feb 24 14:52:51 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:52:51 rivo volumio[5829]: info: CoreStateMachine::syncState stateService play Feb 24 14:52:51 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus play Feb 24 14:52:51 rivo volumio[5829]: info: Received an update from plugin. extracting info from payload Feb 24 14:52:51 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:51 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:51 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:51 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:51 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:51 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:51 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.028+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_PLAYING positionMs=0 volume=100 Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.030+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id=qobuz://song/63373761 title=Stella Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.034+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_PLAYING positionMs=0 volume=100 Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.035+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id=qobuz://song/63373761 title=Stella Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.038+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_PLAYING positionMs=0 volume=100 Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.038+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id=qobuz://song/63373761 title=Stella Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.044+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_PLAYING positionMs=0 volume=100 Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.045+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id=qobuz://song/63373761 title=Stella Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.051+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_PLAYING positionMs=0 volume=100 Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.055+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_PLAYING positionMs=0 volume=100 Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.056+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id=qobuz://song/63373761 title=Stella Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.061+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id=qobuz://song/63373761 title=Stella Feb 24 14:52:52 rivo volumio[5829]: info: ------------------------------ 316ms Feb 24 14:52:52 rivo volumio[5829]: info: ------------------------------ 316ms Feb 24 14:52:52 rivo volumio[5829]: info: ------------------------------ 307ms Feb 24 14:52:52 rivo volumio[5829]: info: sendMpdCommand status took 290 milliseconds Feb 24 14:52:52 rivo volumio[5829]: info: sendMpdCommand playlistinfo took 284 milliseconds Feb 24 14:52:52 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:52:52 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 14:52:52 rivo volumio[5829]: verbose: ControllerMpd::parseTrackInfo Feb 24 14:52:52 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:52:52 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:52:52 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:52 rivo volumio[5829]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":294,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"775 Kbps","isStreaming":false,"title":"63373761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/63373761","trackType":"qobuz"} Feb 24 14:52:52 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:52:52 rivo volumio[5829]: info: CoreStateMachine::syncState stateService play Feb 24 14:52:52 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus play Feb 24 14:52:52 rivo volumio[5829]: info: Received an update from plugin. extracting info from payload Feb 24 14:52:52 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:52 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 14:52:52 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:52 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:52 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:52 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:52 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:52 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:52 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:52 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:52 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.258+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_PLAYING positionMs=395 volume=100 Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.259+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id=qobuz://song/63373761 title=Stella Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.266+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_PLAYING positionMs=395 volume=100 Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.268+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id=qobuz://song/63373761 title=Stella Feb 24 14:52:52 rivo volumio[5829]: info: ------------------------------ 473ms Feb 24 14:52:52 rivo volumio[5829]: info: Signalling Playback active due to playback status change Feb 24 14:52:52 rivo volumio[5829]: info: sendMpdCommand playlistinfo took 279 milliseconds Feb 24 14:52:52 rivo volumio[5829]: STREAMING PROXY: Resuming with range: bytes=586- Feb 24 14:52:52 rivo volumio[5829]: verbose: ControllerMpd::parseTrackInfo Feb 24 14:52:52 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:52:52 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:52:52 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:52:52 rivo volumio[5829]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":294,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"756 Kbps","isStreaming":false,"title":"63373761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/63373761","trackType":"qobuz"} Feb 24 14:52:52 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:52:52 rivo volumio[5829]: info: CoreStateMachine::syncState stateService play Feb 24 14:52:52 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus play Feb 24 14:52:52 rivo volumio[5829]: info: Received an update from plugin. extracting info from payload Feb 24 14:52:52 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:52 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 14:52:52 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:52 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:52 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:52 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:52 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:52:52 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:52:52 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:52:52 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:52:52 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.545+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_PLAYING positionMs=676 volume=100 Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.546+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id=qobuz://song/63373761 title=Stella Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.555+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_PLAYING positionMs=676 volume=100 Feb 24 14:52:52 rivo volumio5-onboarding[3807]: time=2026-02-24T14:52:52.555+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id=qobuz://song/63373761 title=Stella Feb 24 14:52:52 rivo volumio[5829]: info: ------------------------------ 735ms Feb 24 14:52:52 rivo volumio[5829]: info: Executing endpoint metavolumio Feb 24 14:52:52 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:52:52 rivo volumio[5829]: STREAMING PROXY: Resume upstream status code: 206 Feb 24 14:52:52 rivo volumio[5829]: info: MCU Signalled Playback Active Feb 24 14:52:54 rivo volumio[5829]: info: Executing endpoint metavolumio Feb 24 14:52:54 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:52:54 rivo volumio[5829]: info: Executing endpoint metavolumio Feb 24 14:52:54 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:52:54 rivo volumio[5829]: info: Executing endpoint metavolumio Feb 24 14:52:54 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 24 14:52:55 rivo volumio[5829]: STREAMING PROXY: Upstream closed. Received 34221705 bytes Feb 24 14:52:55 rivo volumio[5829]: STREAMING PROXY: Client closed connection Feb 24 14:52:59 rivo volumio[5829]: STREAMING PROXY: Resume ended. Received 34221119 bytes Feb 24 14:53:10 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 24 14:53:10 rivo volumio[5829]: info: CURURI: music-library Feb 24 14:53:10 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:53:11 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 24 14:53:11 rivo volumio[5829]: info: CURURI: music-library/INTERNAL Feb 24 14:53:11 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:53:15 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 24 14:53:15 rivo volumio[5829]: info: CURURI: music-library/INTERNAL/Discographies Feb 24 14:53:15 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:53:21 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 24 14:53:21 rivo volumio[5829]: info: CURURI: music-library/INTERNAL/Discographies/Donna Summer - 2012 - 8 Albums Mini LP SHM-CD (Universal Music Japan) Feb 24 14:53:21 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:53:27 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::ClearQueue Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::stop Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::stPlaybackTimer Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::updateTrackBlock Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrackBlock Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::serviceStop Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::serviceStop Feb 24 14:53:27 rivo volumio[5829]: info: [1771934007172] ControllerQobuz::stop Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 24 14:53:27 rivo volumio[5829]: info: ControllerMpd::stop Feb 24 14:53:27 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand stop Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::clearPlayQueue Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::saveQueue Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioPushQueue Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::addQueueItems Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::addQueueItems Feb 24 14:53:27 rivo volumio[5829]: info: Preload queue cleared Feb 24 14:53:27 rivo volumio[5829]: info: Adding Item to queue: music-library/INTERNAL/Discographies/Donna Summer - 2012 - 8 Albums Mini LP SHM-CD (Universal Music Japan)/1979 Bad Girls (2 SHM-CD Set Universal Music Japan Mini LP 2012) Feb 24 14:53:27 rivo volumio[5829]: info: Exploding uri music-library/INTERNAL/Discographies/Donna Summer - 2012 - 8 Albums Mini LP SHM-CD (Universal Music Japan)/1979 Bad Girls (2 SHM-CD Set Universal Music Japan Mini LP 2012) in service mpd Feb 24 14:53:27 rivo volumio[5829]: error: scanFolder - failure to stat '/mnt/INTERNAL/Discographies/Donna Summer - 2012 - 8 Albums Mini LP SHM-CD (Universal Music Japan)/1979 Bad Girls (2 SHM-CD Set Universal Music Japan Mini LP 2012)' Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.195+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.196+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id=qobuz://song/63373761 title=Stella Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioPushQueue Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::saveQueue Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::updateTrackBlock Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrackBlock Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioPlay Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::play index 0 Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::stop Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::play index undefined Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: Feb 24 14:53:27 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:53:27 rivo volumio[5829]: info: sendMpdCommand stop took 90 milliseconds Feb 24 14:53:27 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:53:27 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:53:27 rivo volumio[5829]: info: sendMpdCommand status took 1 milliseconds Feb 24 14:53:27 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:53:27 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 14:53:27 rivo volumio[5829]: info: Feb 24 14:53:27 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:53:27 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:53:27 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:53:27 rivo volumio[5829]: info: Feb 24 14:53:27 rivo volumio[5829]: ---------------------------- MPD announces state update: player Feb 24 14:53:27 rivo volumio[5829]: info: ControllerMpd::getState Feb 24 14:53:27 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand status Feb 24 14:53:27 rivo volumio[5829]: info: sendMpdCommand playlistinfo took 8 milliseconds Feb 24 14:53:27 rivo volumio[5829]: info: sendMpdCommand status took 6 milliseconds Feb 24 14:53:27 rivo volumio[5829]: info: sendMpdCommand status took 4 milliseconds Feb 24 14:53:27 rivo volumio[5829]: verbose: ControllerMpd::parseTrackInfo Feb 24 14:53:27 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:53:27 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 14:53:27 rivo volumio[5829]: verbose: ControllerMpd::parseState Feb 24 14:53:27 rivo volumio[5829]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 24 14:53:27 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: 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":"63373761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/63373761","trackType":"qobuz"} Feb 24 14:53:27 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::syncState stateService stop Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus stop Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:53:27 rivo volumio[5829]: info: No code Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.359+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.359+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id= title= Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.367+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.367+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id= title= Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.376+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.376+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id= title= Feb 24 14:53:27 rivo volumio[5829]: info: ------------------------------ 158ms Feb 24 14:53:27 rivo volumio[5829]: info: sendMpdCommand playlistinfo took 151 milliseconds Feb 24 14:53:27 rivo volumio[5829]: info: sendMpdCommand playlistinfo took 151 milliseconds Feb 24 14:53:27 rivo volumio[5829]: verbose: ControllerMpd::parseTrackInfo Feb 24 14:53:27 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: 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":"63373761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/63373761","trackType":"qobuz"} Feb 24 14:53:27 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::syncState stateService stop Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus stop Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:53:27 rivo volumio[5829]: info: No code Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:53:27 rivo volumio[5829]: info: ControllerMpd::pushState Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::servicePushState Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: 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":"63373761","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/63373761","trackType":"qobuz"} Feb 24 14:53:27 rivo volumio[5829]: verbose: CURRENT POSITION 0 Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::syncState stateService stop Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::syncState currentStatus stop Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:53:27 rivo volumio[5829]: info: No code Feb 24 14:53:27 rivo volumio[5829]: info: CoreStateMachine::pushState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioPushState Feb 24 14:53:27 rivo volumio[5829]: info: CoreCommandRouter::volumioGetState Feb 24 14:53:27 rivo volumio[5829]: info: CorePlayQueue::getTrack 0 Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output update for this device Feb 24 14:53:27 rivo volumio[5829]: info: MRS: Pushing multiroomSync output Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.579+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.581+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id= title= Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.584+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.586+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id= title= Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.588+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.589+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id= title= Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.593+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.594+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id= title= Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.598+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.599+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id= title= Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.603+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" state=STATUS_STOPPED positionMs=0 volume=100 Feb 24 14:53:27 rivo volumio5-onboarding[3807]: time=2026-02-24T14:53:27.603+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.231:52162 @ 0x1d27a70" id= title= Feb 24 14:53:27 rivo volumio[5829]: info: ------------------------------ 397ms Feb 24 14:53:27 rivo volumio[5829]: info: ------------------------------ 397ms Feb 24 14:53:27 rivo volumio[5829]: info: MCU Signalled Playback Inactive Feb 24 14:53:40 rivo volumio[5829]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 14:53:40 rivo volumio[5829]: Error: connect ETIMEDOUT 23.73.2.88:443 Feb 24 14:53:40 rivo volumio[5829]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Feb 24 14:53:40 rivo volumio[5829]: errno: -110, Feb 24 14:53:40 rivo volumio[5829]: code: 'ETIMEDOUT', Feb 24 14:53:40 rivo volumio[5829]: syscall: 'connect', Feb 24 14:53:40 rivo volumio[5829]: address: '23.73.2.88', Feb 24 14:53:40 rivo volumio[5829]: port: 443 Feb 24 14:53:40 rivo volumio[5829]: } Feb 24 14:53:40 rivo volumio[5829]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 24 14:53:41 rivo sudo[7974]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-24 14:52 Feb 24 14:53:41 rivo sudo[7974]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 05 Feb 2026 02:25:23 PM CET" VOLUMIO_VERSION="3.908" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="ab3f2fa07b5f7b8b5e7143217bee70a8"