-- Logs begin at Fri 2025-05-23 18:25:24 +07, end at Tue 2025-05-27 15:15:57 +07. -- May 27 15:14:00 rivoplus volumio[10162]: info: Preload queue cleared May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioReplaceandPlayItems May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::ClearQueue May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::stop May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::stPlaybackTimer May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::updateTrackBlock May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::getTrackBlock May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::serviceStop May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::serviceStop May 27 15:14:00 rivoplus volumio[10162]: info: [1748333640433] ControllerUPNPBrowser::stop May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand stop May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::clearPlayQueue May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::saveQueue May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushQueue May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::addQueueItems May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::addQueueItems May 27 15:14:00 rivoplus volumio[10162]: info: Preload queue cleared May 27 15:14:00 rivoplus volumio[10162]: info: Adding Item to queue: upnp/folder/http://192.168.1.250:50001/ContentDirectory/control@22$462 May 27 15:14:00 rivoplus volumio[10162]: info: Using cached record of: upnp/folder/http://192.168.1.250:50001/ContentDirectory/control@22$462 May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushQueue May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::saveQueue May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::updateTrackBlock May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::getTrackBlock May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPlay May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::play index 0 May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::stop May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::play index undefined May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::startPlaybackTimer May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:00 rivoplus volumio[10162]: info: [1748333640472] ControllerUPNPBrowser::clearAddPlayTrack May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand stop May 27 15:14:00 rivoplus volumio[10162]: info: May 27 15:14:00 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand stop took 57 milliseconds May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand stop took 18 milliseconds May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand clear May 27 15:14:00 rivoplus volumio[10162]: info: May 27 15:14:00 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:00 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand status took 5 milliseconds May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand clear took 3 milliseconds May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.250:50002/m/NDLNA/4009.dsf" May 27 15:14:00 rivoplus volumio[10162]: info: May 27 15:14:00 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:00 rivoplus volumio[10162]: info: May 27 15:14:00 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:00 rivoplus volumio[10162]: error: updateQueue error: null May 27 15:14:00 rivoplus volumio[10162]: info: ------------------------------ 10ms May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 9 milliseconds May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:00 rivoplus volumio[10162]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 27 15:14:00 rivoplus volumio[10162]: info: ------------------------------ 18ms May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.250:50002/m/NDLNA/4009.dsf" May 27 15:14:00 rivoplus volumio[10162]: info: May 27 15:14:00 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:00 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand status took 18 milliseconds May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand status took 21 milliseconds May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand add "http://192.168.1.250:50002/m/NDLNA/4009.dsf" took 8 milliseconds May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand play May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:00 rivoplus volumio[10162]: 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} May 27 15:14:00 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService stop May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: No code May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:00 rivoplus volumio[10162]: 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} May 27 15:14:00 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService stop May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: No code May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: ------------------------------ 96ms May 27 15:14:00 rivoplus volumio[10162]: info: ------------------------------ 95ms May 27 15:14:00 rivoplus volumio[10162]: info: May 27 15:14:00 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:00 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:00 rivoplus volumio[10162]: info: May 27 15:14:00 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:00 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:00 rivoplus volumio[10162]: info: May 27 15:14:00 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:00 rivoplus volumio[10162]: info: ------------------------------ 88ms May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand play took 80 milliseconds May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:00 rivoplus volumio[10162]: info: ------------------------------ 9ms May 27 15:14:00 rivoplus volumio[10162]: info: ------------------------------ 8ms May 27 15:14:00 rivoplus volumio[10162]: info: May 27 15:14:00 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:00 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:00 rivoplus volumio[10162]: info: May 27 15:14:00 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:00 rivoplus volumio[10162]: info: May 27 15:14:00 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:00 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:00 rivoplus volumio[10162]: info: May 27 15:14:00 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:00 rivoplus volumio[10162]: info: Signalling Playback active due to playback status change May 27 15:14:00 rivoplus volumio[10162]: info: May 27 15:14:00 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand status took 112 milliseconds May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:00 rivoplus volumio[10162]: info: ------------------------------ 113ms May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand status took 108 milliseconds May 27 15:14:00 rivoplus volumio[10162]: info: ------------------------------ 108ms May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand status took 108 milliseconds May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:00 rivoplus volumio[10162]: info: May 27 15:14:00 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:00 rivoplus volumio[10162]: info: May 27 15:14:00 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:00 rivoplus volumio[10162]: info: MCU Signalled Playback Inactive May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand status took 21 milliseconds May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 13 milliseconds May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 13 milliseconds May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 12 milliseconds May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand status took 10 milliseconds May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand status took 8 milliseconds May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:00 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":260,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"4009.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/4009.dsf","trackType":"dsf"} May 27 15:14:00 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:00 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":260,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"4009.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/4009.dsf","trackType":"dsf"} May 27 15:14:00 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:00 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:00 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":260,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"4009.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/4009.dsf","trackType":"dsf"} May 27 15:14:00 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:00 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: ------------------------------ 181ms May 27 15:14:00 rivoplus volumio[10162]: info: ------------------------------ 207ms May 27 15:14:00 rivoplus volumio[10162]: info: ------------------------------ 205ms May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 81 milliseconds May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 81 milliseconds May 27 15:14:00 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 81 milliseconds May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:00 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:00 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":22,"duration":260,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"4009.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/4009.dsf","trackType":"dsf"} May 27 15:14:00 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:00 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:00 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":22,"duration":260,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"4009.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/4009.dsf","trackType":"dsf"} May 27 15:14:00 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:00 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:00 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:00 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":22,"duration":260,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"4009.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/4009.dsf","trackType":"dsf"} May 27 15:14:00 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:00 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:00 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:00 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:00 rivoplus volumio[10162]: info: ------------------------------ 185ms May 27 15:14:00 rivoplus volumio[10162]: info: ------------------------------ 169ms May 27 15:14:00 rivoplus volumio[10162]: info: ------------------------------ 169ms May 27 15:14:00 rivoplus volumio[10162]: info: MCU Signalled Playback Active May 27 15:14:01 rivoplus volumio[10162]: info: Preload queue cleared May 27 15:14:01 rivoplus volumio[10162]: info: CoreCommandRouter::volumioReplaceandPlayItems May 27 15:14:01 rivoplus volumio[10162]: info: CoreStateMachine::ClearQueue May 27 15:14:01 rivoplus volumio[10162]: info: CoreStateMachine::stop May 27 15:14:01 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:14:01 rivoplus volumio[10162]: info: CoreStateMachine::stPlaybackTimer May 27 15:14:01 rivoplus volumio[10162]: info: CoreStateMachine::updateTrackBlock May 27 15:14:01 rivoplus volumio[10162]: info: CorePlayQueue::getTrackBlock May 27 15:14:01 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:01 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:01 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:01 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:01 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:01 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:01 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:01 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:01 rivoplus volumio[10162]: info: CoreStateMachine::serviceStop May 27 15:14:01 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:01 rivoplus volumio[10162]: info: CoreCommandRouter::serviceStop May 27 15:14:01 rivoplus volumio[10162]: info: [1748333641940] ControllerUPNPBrowser::stop May 27 15:14:01 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand stop May 27 15:14:01 rivoplus volumio[10162]: info: CorePlayQueue::clearPlayQueue May 27 15:14:01 rivoplus volumio[10162]: info: CorePlayQueue::saveQueue May 27 15:14:01 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushQueue May 27 15:14:01 rivoplus volumio[10162]: info: CoreStateMachine::addQueueItems May 27 15:14:01 rivoplus volumio[10162]: info: CorePlayQueue::addQueueItems May 27 15:14:01 rivoplus volumio[10162]: info: Preload queue cleared May 27 15:14:01 rivoplus volumio[10162]: info: Adding Item to queue: upnp/folder/http://192.168.1.250:50001/ContentDirectory/control@22$462 May 27 15:14:01 rivoplus volumio[10162]: info: Using cached record of: upnp/folder/http://192.168.1.250:50001/ContentDirectory/control@22$462 May 27 15:14:01 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushQueue May 27 15:14:01 rivoplus volumio[10162]: info: CorePlayQueue::saveQueue May 27 15:14:01 rivoplus volumio[10162]: info: CoreStateMachine::updateTrackBlock May 27 15:14:01 rivoplus volumio[10162]: info: CorePlayQueue::getTrackBlock May 27 15:14:01 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPlay May 27 15:14:01 rivoplus volumio[10162]: info: CoreStateMachine::play index 0 May 27 15:14:01 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:14:01 rivoplus volumio[10162]: info: CoreStateMachine::stop May 27 15:14:01 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:14:01 rivoplus volumio[10162]: info: CoreStateMachine::play index undefined May 27 15:14:01 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:14:01 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:01 rivoplus volumio[10162]: info: CoreStateMachine::startPlaybackTimer May 27 15:14:01 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:01 rivoplus volumio[10162]: info: [1748333641983] ControllerUPNPBrowser::clearAddPlayTrack May 27 15:14:01 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand stop May 27 15:14:02 rivoplus volumio[10162]: info: May 27 15:14:02 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand stop took 62 milliseconds May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand stop took 19 milliseconds May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand clear May 27 15:14:02 rivoplus volumio[10162]: info: May 27 15:14:02 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:02 rivoplus volumio[10162]: info: May 27 15:14:02 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:02 rivoplus volumio[10162]: info: May 27 15:14:02 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:02 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand status took 10 milliseconds May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand clear took 10 milliseconds May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand status took 7 milliseconds May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand status took 5 milliseconds May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.250:50002/m/NDLNA/4009.dsf" May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: 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} May 27 15:14:02 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService stop May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:02 rivoplus volumio[10162]: info: No code May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: 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} May 27 15:14:02 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService stop May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:02 rivoplus volumio[10162]: info: No code May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:02 rivoplus volumio[10162]: info: ------------------------------ 114ms May 27 15:14:02 rivoplus volumio[10162]: info: ------------------------------ 113ms May 27 15:14:02 rivoplus volumio[10162]: info: May 27 15:14:02 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:02 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:02 rivoplus volumio[10162]: info: May 27 15:14:02 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:02 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:02 rivoplus volumio[10162]: error: updateQueue error: null May 27 15:14:02 rivoplus volumio[10162]: error: updateQueue error: null May 27 15:14:02 rivoplus volumio[10162]: error: updateQueue error: null May 27 15:14:02 rivoplus volumio[10162]: info: ------------------------------ 120ms May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 117 milliseconds May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.250:50002/m/NDLNA/4009.dsf" May 27 15:14:02 rivoplus volumio[10162]: info: ------------------------------ 12ms May 27 15:14:02 rivoplus volumio[10162]: info: ------------------------------ 10ms May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:02 rivoplus volumio[10162]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 27 15:14:02 rivoplus volumio[10162]: info: ------------------------------ 138ms May 27 15:14:02 rivoplus volumio[10162]: info: May 27 15:14:02 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:02 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand add "http://192.168.1.250:50002/m/NDLNA/4009.dsf" took 45 milliseconds May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand play May 27 15:14:02 rivoplus volumio[10162]: info: MCU Signalled Playback Inactive May 27 15:14:02 rivoplus volumio[10162]: info: May 27 15:14:02 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:02 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:02 rivoplus volumio[10162]: info: May 27 15:14:02 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:02 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:02 rivoplus volumio[10162]: info: ------------------------------ 12ms May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand play took 10 milliseconds May 27 15:14:02 rivoplus volumio[10162]: info: ------------------------------ 6ms May 27 15:14:02 rivoplus volumio[10162]: info: ------------------------------ 4ms May 27 15:14:02 rivoplus volumio[10162]: info: May 27 15:14:02 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:02 rivoplus volumio[10162]: info: May 27 15:14:02 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:02 rivoplus volumio[10162]: info: May 27 15:14:02 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:02 rivoplus volumio[10162]: info: May 27 15:14:02 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand status took 43 milliseconds May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand status took 42 milliseconds May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand status took 40 milliseconds May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:02 rivoplus volumio[10162]: info: May 27 15:14:02 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:02 rivoplus volumio[10162]: info: May 27 15:14:02 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand status took 9 milliseconds May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 8 milliseconds May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 7 milliseconds May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 6 milliseconds May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand status took 4 milliseconds May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":260,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"4009.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/4009.dsf","trackType":"dsf"} May 27 15:14:02 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":260,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"4009.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/4009.dsf","trackType":"dsf"} May 27 15:14:02 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:02 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":260,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"4009.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/4009.dsf","trackType":"dsf"} May 27 15:14:02 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:02 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:02 rivoplus volumio[10162]: info: ------------------------------ 93ms May 27 15:14:02 rivoplus volumio[10162]: info: ------------------------------ 123ms May 27 15:14:02 rivoplus volumio[10162]: info: ------------------------------ 122ms May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand status took 78 milliseconds May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 76 milliseconds May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 75 milliseconds May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":260,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"4009.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/4009.dsf","trackType":"dsf"} May 27 15:14:02 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:02 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2,"duration":260,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"4009.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/4009.dsf","trackType":"dsf"} May 27 15:14:02 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:02 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:02 rivoplus volumio[10162]: info: ------------------------------ 197ms May 27 15:14:02 rivoplus volumio[10162]: info: ------------------------------ 195ms May 27 15:14:02 rivoplus volumio[10162]: info: Signalling Playback active due to playback status change May 27 15:14:02 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 195 milliseconds May 27 15:14:02 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:02 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:02 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:02 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2,"duration":260,"samplerate":"5.64 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"11289 Kbps","isStreaming":false,"title":"4009.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/4009.dsf","trackType":"dsf"} May 27 15:14:02 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:02 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:02 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:02 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:02 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:02 rivoplus volumio[10162]: info: ------------------------------ 338ms May 27 15:14:02 rivoplus volumio[10162]: info: MCU Signalled Playback Active May 27 15:14:04 rivoplus volumio[10162]: info: Executing endpoint metavolumio May 27 15:14:04 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 15:14:15 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 27 15:14:15 rivoplus volumio[10162]: info: Preload queue cleared May 27 15:14:15 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3808 May 27 15:14:15 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3798 May 27 15:14:15 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3809 May 27 15:14:15 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3812 May 27 15:14:15 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3799 May 27 15:14:15 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3797 May 27 15:14:15 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3806 May 27 15:14:15 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3801 May 27 15:14:15 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3810 May 27 15:14:15 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3804 May 27 15:14:15 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3802 May 27 15:14:15 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3803 May 27 15:14:15 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3807 May 27 15:14:15 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3800 May 27 15:14:15 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3805 May 27 15:14:15 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3811 May 27 15:14:15 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3808 in service upnp_browser May 27 15:14:16 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3798 in service upnp_browser May 27 15:14:16 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3809 in service upnp_browser May 27 15:14:16 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3812 in service upnp_browser May 27 15:14:16 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3799 in service upnp_browser May 27 15:14:16 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3797 in service upnp_browser May 27 15:14:16 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3806 in service upnp_browser May 27 15:14:16 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3801 in service upnp_browser May 27 15:14:16 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3810 in service upnp_browser May 27 15:14:16 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3804 in service upnp_browser May 27 15:14:16 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3802 in service upnp_browser May 27 15:14:16 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3803 in service upnp_browser May 27 15:14:16 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3807 in service upnp_browser May 27 15:14:16 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3800 in service upnp_browser May 27 15:14:16 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3805 in service upnp_browser May 27 15:14:16 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3811 in service upnp_browser May 27 15:14:19 rivoplus volumio[10162]: info: Preload queue cleared May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioReplaceandPlayItems May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::ClearQueue May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::stop May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::stPlaybackTimer May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::updateTrackBlock May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrackBlock May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:19 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::serviceStop May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::serviceStop May 27 15:14:19 rivoplus volumio[10162]: info: [1748333659624] ControllerUPNPBrowser::stop May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand stop May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::clearPlayQueue May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::saveQueue May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushQueue May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::addQueueItems May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::addQueueItems May 27 15:14:19 rivoplus volumio[10162]: info: Preload queue cleared May 27 15:14:19 rivoplus volumio[10162]: info: Adding Item to queue: upnp/folder/http://192.168.1.250:50001/ContentDirectory/control@22$440 May 27 15:14:19 rivoplus volumio[10162]: info: Exploding uri upnp/folder/http://192.168.1.250:50001/ContentDirectory/control@22$440 in service upnp_browser May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushQueue May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::saveQueue May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::updateTrackBlock May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrackBlock May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPlay May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::play index 0 May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::stop May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::play index undefined May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::startPlaybackTimer May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: [1748333659707] ControllerUPNPBrowser::clearAddPlayTrack May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand stop May 27 15:14:19 rivoplus volumio[10162]: info: May 27 15:14:19 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:19 rivoplus volumio[10162]: info: sendMpdCommand stop took 87 milliseconds May 27 15:14:19 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:19 rivoplus volumio[10162]: info: sendMpdCommand stop took 8 milliseconds May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand clear May 27 15:14:19 rivoplus volumio[10162]: info: May 27 15:14:19 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:19 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:19 rivoplus volumio[10162]: info: May 27 15:14:19 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:19 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:19 rivoplus volumio[10162]: info: May 27 15:14:19 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:19 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:19 rivoplus volumio[10162]: info: sendMpdCommand status took 14 milliseconds May 27 15:14:19 rivoplus volumio[10162]: info: sendMpdCommand clear took 14 milliseconds May 27 15:14:19 rivoplus volumio[10162]: info: sendMpdCommand status took 11 milliseconds May 27 15:14:19 rivoplus volumio[10162]: info: sendMpdCommand status took 10 milliseconds May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.250:50002/m/NDLNA/3808.dff" May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:19 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:19 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: 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} May 27 15:14:19 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService stop May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:19 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:19 rivoplus volumio[10162]: info: No code May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:19 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:19 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:19 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: 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} May 27 15:14:19 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService stop May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:19 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:19 rivoplus volumio[10162]: info: No code May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:19 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:19 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:19 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:19 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:19 rivoplus volumio[10162]: info: ------------------------------ 86ms May 27 15:14:19 rivoplus volumio[10162]: info: ------------------------------ 84ms May 27 15:14:19 rivoplus volumio[10162]: info: May 27 15:14:19 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:19 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:19 rivoplus volumio[10162]: info: May 27 15:14:19 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:19 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:19 rivoplus volumio[10162]: error: updateQueue error: null May 27 15:14:19 rivoplus volumio[10162]: error: updateQueue error: null May 27 15:14:19 rivoplus volumio[10162]: info: ------------------------------ 93ms May 27 15:14:19 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 90 milliseconds May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.250:50002/m/NDLNA/3808.dff" May 27 15:14:19 rivoplus volumio[10162]: info: ------------------------------ 17ms May 27 15:14:19 rivoplus volumio[10162]: info: ------------------------------ 11ms May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:19 rivoplus volumio[10162]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 27 15:14:19 rivoplus volumio[10162]: info: ------------------------------ 118ms May 27 15:14:19 rivoplus volumio[10162]: info: MCU Signalled Playback Inactive May 27 15:14:19 rivoplus volumio[10162]: info: May 27 15:14:19 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:19 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:19 rivoplus volumio[10162]: info: sendMpdCommand add "http://192.168.1.250:50002/m/NDLNA/3808.dff" took 51 milliseconds May 27 15:14:19 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand play May 27 15:14:19 rivoplus volumio[10162]: info: May 27 15:14:19 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:19 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:19 rivoplus volumio[10162]: info: May 27 15:14:19 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:19 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:19 rivoplus volumio[10162]: info: ------------------------------ 13ms May 27 15:14:19 rivoplus volumio[10162]: info: sendMpdCommand play took 12 milliseconds May 27 15:14:19 rivoplus volumio[10162]: info: ------------------------------ 9ms May 27 15:14:19 rivoplus volumio[10162]: info: ------------------------------ 7ms May 27 15:14:19 rivoplus volumio[10162]: info: May 27 15:14:19 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:19 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:19 rivoplus volumio[10162]: info: May 27 15:14:19 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:19 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:19 rivoplus volumio[10162]: info: May 27 15:14:19 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:19 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:19 rivoplus volumio[10162]: info: sendMpdCommand status took 72 milliseconds May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:19 rivoplus volumio[10162]: info: May 27 15:14:19 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:19 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:19 rivoplus volumio[10162]: info: May 27 15:14:19 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:19 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:19 rivoplus volumio[10162]: info: May 27 15:14:19 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:19 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:19 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:19 rivoplus volumio[10162]: info: sendMpdCommand status took 62 milliseconds May 27 15:14:19 rivoplus volumio[10162]: info: sendMpdCommand status took 61 milliseconds May 27 15:14:19 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 25 milliseconds May 27 15:14:19 rivoplus volumio[10162]: info: sendMpdCommand status took 11 milliseconds May 27 15:14:19 rivoplus volumio[10162]: info: sendMpdCommand status took 6 milliseconds May 27 15:14:20 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:20 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:20 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:20 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:20 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:20 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:20 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:20 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:20 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:20 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:20 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:20 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":275,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3808.dff","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3808.dff","trackType":"dff"} May 27 15:14:20 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:14:20 rivoplus volumio[10162]: info: ------------------------------ 115ms May 27 15:14:20 rivoplus volumio[10162]: info: sendMpdCommand status took 17 milliseconds May 27 15:14:20 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 14 milliseconds May 27 15:14:20 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 13 milliseconds May 27 15:14:20 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 12 milliseconds May 27 15:14:20 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:20 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:20 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:20 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:20 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:20 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:20 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:20 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:20 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":217,"duration":275,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3808.dff","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3808.dff","trackType":"dff"} May 27 15:14:20 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:20 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:20 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:20 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:20 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":274,"duration":275,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3808.dff","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3808.dff","trackType":"dff"} May 27 15:14:20 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:20 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:20 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:20 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:20 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":354,"duration":275,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3808.dff","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3808.dff","trackType":"dff"} May 27 15:14:20 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:20 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:20 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:20 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:20 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":446,"duration":275,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3808.dff","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3808.dff","trackType":"dff"} May 27 15:14:20 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:20 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:20 rivoplus volumio[10162]: info: ------------------------------ 227ms May 27 15:14:20 rivoplus volumio[10162]: info: ------------------------------ 226ms May 27 15:14:20 rivoplus volumio[10162]: info: ------------------------------ 176ms May 27 15:14:20 rivoplus volumio[10162]: info: ------------------------------ 175ms May 27 15:14:20 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 152 milliseconds May 27 15:14:20 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:20 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:20 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:20 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":446,"duration":275,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3808.dff","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3808.dff","trackType":"dff"} May 27 15:14:20 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:20 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:20 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:20 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:20 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:20 rivoplus volumio[10162]: info: ------------------------------ 226ms May 27 15:14:20 rivoplus volumio[10162]: info: Signalling Playback active due to playback status change May 27 15:14:20 rivoplus volumio[10162]: info: MCU Signalled Playback Active May 27 15:14:22 rivoplus volumio[10162]: info: Executing endpoint metavolumio May 27 15:14:22 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 15:14:30 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 27 15:14:30 rivoplus volumio[10162]: info: Preload queue cleared May 27 15:14:30 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3953 May 27 15:14:30 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3957 May 27 15:14:30 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3958 May 27 15:14:30 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3960 May 27 15:14:30 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3955 May 27 15:14:30 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3956 May 27 15:14:30 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3961 May 27 15:14:30 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3959 May 27 15:14:30 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3954 May 27 15:14:30 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3953 in service upnp_browser May 27 15:14:31 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3957 in service upnp_browser May 27 15:14:31 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3958 in service upnp_browser May 27 15:14:31 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3960 in service upnp_browser May 27 15:14:31 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3955 in service upnp_browser May 27 15:14:31 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3956 in service upnp_browser May 27 15:14:31 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3961 in service upnp_browser May 27 15:14:31 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3959 in service upnp_browser May 27 15:14:31 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3954 in service upnp_browser May 27 15:14:48 rivoplus volumio[10162]: info: Preload queue cleared May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioReplaceandPlayItems May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::ClearQueue May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::stop May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::stPlaybackTimer May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::updateTrackBlock May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrackBlock May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::serviceStop May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::serviceStop May 27 15:14:48 rivoplus volumio[10162]: info: [1748333688605] ControllerUPNPBrowser::stop May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand stop May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::clearPlayQueue May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::saveQueue May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushQueue May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::addQueueItems May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::addQueueItems May 27 15:14:48 rivoplus volumio[10162]: info: Preload queue cleared May 27 15:14:48 rivoplus volumio[10162]: info: Adding Item to queue: upnp/folder/http://192.168.1.250:50001/ContentDirectory/control@22$458 May 27 15:14:48 rivoplus volumio[10162]: info: Exploding uri upnp/folder/http://192.168.1.250:50001/ContentDirectory/control@22$458 in service upnp_browser May 27 15:14:48 rivoplus volumio[10162]: info: May 27 15:14:48 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand stop took 38 milliseconds May 27 15:14:48 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:48 rivoplus volumio[10162]: info: May 27 15:14:48 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:48 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:48 rivoplus volumio[10162]: info: May 27 15:14:48 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:48 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand status took 6 milliseconds May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand status took 5 milliseconds May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand status took 3 milliseconds May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 3 milliseconds May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 4 milliseconds May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 3 milliseconds May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:48 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: 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":"3808.dff","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3808.dff","trackType":"dff"} May 27 15:14:48 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService stop May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:48 rivoplus volumio[10162]: info: No code May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:48 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: 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":"3808.dff","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3808.dff","trackType":"dff"} May 27 15:14:48 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService stop May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:48 rivoplus volumio[10162]: info: No code May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:48 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: 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":"3808.dff","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3808.dff","trackType":"dff"} May 27 15:14:48 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService stop May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:48 rivoplus volumio[10162]: info: No code May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:48 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:48 rivoplus volumio[10162]: info: ------------------------------ 112ms May 27 15:14:48 rivoplus volumio[10162]: info: ------------------------------ 111ms May 27 15:14:48 rivoplus volumio[10162]: info: ------------------------------ 111ms May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushQueue May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::saveQueue May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::updateTrackBlock May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrackBlock May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPlay May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::play index 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::stop May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::play index undefined May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::startPlaybackTimer May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: info: [1748333688794] ControllerUPNPBrowser::clearAddPlayTrack May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand stop May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand stop took 2 milliseconds May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand clear May 27 15:14:48 rivoplus volumio[10162]: info: May 27 15:14:48 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:48 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand clear took 62 milliseconds May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.250:50002/m/NDLNA/3953.dsf" May 27 15:14:48 rivoplus volumio[10162]: info: MCU Signalled Playback Inactive May 27 15:14:48 rivoplus volumio[10162]: info: May 27 15:14:48 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:48 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:48 rivoplus volumio[10162]: info: May 27 15:14:48 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:48 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:48 rivoplus volumio[10162]: error: updateQueue error: null May 27 15:14:48 rivoplus volumio[10162]: info: ------------------------------ 10ms May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.250:50002/m/NDLNA/3953.dsf" May 27 15:14:48 rivoplus volumio[10162]: error: updateQueue error: null May 27 15:14:48 rivoplus volumio[10162]: error: updateQueue error: null May 27 15:14:48 rivoplus volumio[10162]: info: May 27 15:14:48 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:48 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:48 rivoplus volumio[10162]: info: ------------------------------ 26ms May 27 15:14:48 rivoplus volumio[10162]: info: ------------------------------ 25ms May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand add "http://192.168.1.250:50002/m/NDLNA/3953.dsf" took 3 milliseconds May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand play May 27 15:14:48 rivoplus volumio[10162]: info: May 27 15:14:48 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:48 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:48 rivoplus volumio[10162]: info: May 27 15:14:48 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:14:48 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:14:48 rivoplus volumio[10162]: info: ------------------------------ 7ms May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand play took 5 milliseconds May 27 15:14:48 rivoplus volumio[10162]: info: ------------------------------ 4ms May 27 15:14:48 rivoplus volumio[10162]: info: ------------------------------ 3ms May 27 15:14:48 rivoplus volumio[10162]: info: May 27 15:14:48 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:48 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:48 rivoplus volumio[10162]: info: May 27 15:14:48 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:48 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:48 rivoplus volumio[10162]: info: May 27 15:14:48 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:48 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand status took 19 milliseconds May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:48 rivoplus volumio[10162]: info: May 27 15:14:48 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:48 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand status took 39 milliseconds May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand status took 35 milliseconds May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 6 milliseconds May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:48 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":342,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3953.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3953.dsf","trackType":"dsf"} May 27 15:14:48 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:14:48 rivoplus volumio[10162]: info: ------------------------------ 66ms May 27 15:14:48 rivoplus volumio[10162]: info: May 27 15:14:48 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:48 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:48 rivoplus volumio[10162]: info: May 27 15:14:48 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:14:48 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand status took 32 milliseconds May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 28 milliseconds May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 27 milliseconds May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand status took 7 milliseconds May 27 15:14:48 rivoplus volumio[10162]: info: sendMpdCommand status took 5 milliseconds May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:14:48 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:14:48 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:48 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:48 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":342,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3953.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3953.dsf","trackType":"dsf"} May 27 15:14:48 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:48 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:48 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:48 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:49 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:49 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:49 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":148,"duration":342,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3953.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3953.dsf","trackType":"dsf"} May 27 15:14:49 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:49 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:49 rivoplus volumio[10162]: info: ------------------------------ 133ms May 27 15:14:49 rivoplus volumio[10162]: info: ------------------------------ 125ms May 27 15:14:49 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 57 milliseconds May 27 15:14:49 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 56 milliseconds May 27 15:14:49 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 55 milliseconds May 27 15:14:49 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:49 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:49 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:14:49 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:49 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:49 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":417,"duration":342,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3953.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3953.dsf","trackType":"dsf"} May 27 15:14:49 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:49 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:49 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:49 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:49 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":503,"duration":342,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3953.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3953.dsf","trackType":"dsf"} May 27 15:14:49 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:49 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:49 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:14:49 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:14:49 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":503,"duration":342,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3953.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3953.dsf","trackType":"dsf"} May 27 15:14:49 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:14:49 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:49 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:14:49 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:14:49 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:14:49 rivoplus volumio[10162]: info: ------------------------------ 153ms May 27 15:14:49 rivoplus volumio[10162]: info: ------------------------------ 135ms May 27 15:14:49 rivoplus volumio[10162]: info: ------------------------------ 125ms May 27 15:14:49 rivoplus volumio[10162]: info: Signalling Playback active due to playback status change May 27 15:14:49 rivoplus volumio[10162]: info: MCU Signalled Playback Active May 27 15:14:52 rivoplus volumio[10162]: info: Executing endpoint metavolumio May 27 15:14:52 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 15:14:59 rivoplus volumio[10162]: error: Failed request for metavolumio API May 27 15:15:00 rivoplus ntpd[3409]: Soliciting pool server 2401:5f80:5001:1f::31f May 27 15:15:00 rivoplus ntpd[3409]: Soliciting pool server 115.165.161.155 May 27 15:15:03 rivoplus ntpd[3409]: Soliciting pool server 103.199.19.135 May 27 15:15:03 rivoplus ntpd[3409]: Soliciting pool server 27.71.27.209 May 27 15:15:06 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 27 15:15:06 rivoplus volumio[10162]: info: Preload queue cleared May 27 15:15:06 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3852 May 27 15:15:06 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3851 May 27 15:15:06 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3850 May 27 15:15:06 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3857 May 27 15:15:06 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3855 May 27 15:15:06 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3854 May 27 15:15:06 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3856 May 27 15:15:06 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3853 May 27 15:15:06 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3859 May 27 15:15:06 rivoplus volumio[10162]: info: Preloading song: upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3858 May 27 15:15:06 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3852 in service upnp_browser May 27 15:15:06 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3851 in service upnp_browser May 27 15:15:06 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3850 in service upnp_browser May 27 15:15:06 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3857 in service upnp_browser May 27 15:15:06 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3855 in service upnp_browser May 27 15:15:06 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3854 in service upnp_browser May 27 15:15:06 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3856 in service upnp_browser May 27 15:15:06 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3853 in service upnp_browser May 27 15:15:06 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3859 in service upnp_browser May 27 15:15:06 rivoplus volumio[10162]: info: Exploding uri upnp/http://192.168.1.250:50001/ContentDirectory/control@22$@3858 in service upnp_browser May 27 15:15:11 rivoplus volumio[10162]: info: Preload queue cleared May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioReplaceandPlayItems May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::ClearQueue May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::stop May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::stPlaybackTimer May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::updateTrackBlock May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrackBlock May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::serviceStop May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::serviceStop May 27 15:15:11 rivoplus volumio[10162]: info: [1748333711223] ControllerUPNPBrowser::stop May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand stop May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::clearPlayQueue May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::saveQueue May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushQueue May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::addQueueItems May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::addQueueItems May 27 15:15:11 rivoplus volumio[10162]: info: Preload queue cleared May 27 15:15:11 rivoplus volumio[10162]: info: Adding Item to queue: upnp/folder/http://192.168.1.250:50001/ContentDirectory/control@22$445 May 27 15:15:11 rivoplus volumio[10162]: info: Exploding uri upnp/folder/http://192.168.1.250:50001/ContentDirectory/control@22$445 in service upnp_browser May 27 15:15:11 rivoplus volumio[10162]: info: May 27 15:15:11 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand stop took 39 milliseconds May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand status took 1 milliseconds May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:15:11 rivoplus volumio[10162]: info: May 27 15:15:11 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:15:11 rivoplus volumio[10162]: info: May 27 15:15:11 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 6 milliseconds May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand status took 4 milliseconds May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand status took 3 milliseconds May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: 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":"3953.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3953.dsf","trackType":"dsf"} May 27 15:15:11 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService stop May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: No code May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: ------------------------------ 53ms May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushQueue May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::saveQueue May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::updateTrackBlock May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrackBlock May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPlay May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::play index 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::stop May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::play index undefined May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService undefined May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::startPlaybackTimer May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: [1748333711356] ControllerUPNPBrowser::clearAddPlayTrack May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand stop May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 86 milliseconds May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 85 milliseconds May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand stop took 4 milliseconds May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand clear May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: 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":"3953.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3953.dsf","trackType":"dsf"} May 27 15:15:11 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService stop May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: No code May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: 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":"3953.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3953.dsf","trackType":"dsf"} May 27 15:15:11 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService stop May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: No code May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: ------------------------------ 164ms May 27 15:15:11 rivoplus volumio[10162]: info: ------------------------------ 164ms May 27 15:15:11 rivoplus volumio[10162]: info: May 27 15:15:11 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:15:11 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand clear took 149 milliseconds May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.250:50002/m/NDLNA/3852.dsf" May 27 15:15:11 rivoplus volumio[10162]: info: MCU Signalled Playback Inactive May 27 15:15:11 rivoplus volumio[10162]: info: May 27 15:15:11 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:15:11 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:15:11 rivoplus volumio[10162]: info: May 27 15:15:11 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:15:11 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:15:11 rivoplus volumio[10162]: error: updateQueue error: null May 27 15:15:11 rivoplus volumio[10162]: info: ------------------------------ 22ms May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.250:50002/m/NDLNA/3852.dsf" May 27 15:15:11 rivoplus volumio[10162]: error: updateQueue error: null May 27 15:15:11 rivoplus volumio[10162]: error: updateQueue error: null May 27 15:15:11 rivoplus volumio[10162]: info: May 27 15:15:11 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:15:11 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:15:11 rivoplus volumio[10162]: info: ------------------------------ 30ms May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand add "http://192.168.1.250:50002/m/NDLNA/3852.dsf" took 3 milliseconds May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::setConsumeUpdateService mpd May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand play May 27 15:15:11 rivoplus volumio[10162]: info: May 27 15:15:11 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:15:11 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:15:11 rivoplus volumio[10162]: info: May 27 15:15:11 rivoplus volumio[10162]: ---------------------------- MPD announces system playlist update May 27 15:15:11 rivoplus volumio[10162]: info: Ignoring MPD Status Update May 27 15:15:11 rivoplus volumio[10162]: info: ------------------------------ 7ms May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand play took 5 milliseconds May 27 15:15:11 rivoplus volumio[10162]: info: ------------------------------ 4ms May 27 15:15:11 rivoplus volumio[10162]: info: May 27 15:15:11 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:15:11 rivoplus volumio[10162]: info: May 27 15:15:11 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:15:11 rivoplus volumio[10162]: info: May 27 15:15:11 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:15:11 rivoplus volumio[10162]: info: May 27 15:15:11 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand status took 43 milliseconds May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:15:11 rivoplus volumio[10162]: info: May 27 15:15:11 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:15:11 rivoplus volumio[10162]: info: May 27 15:15:11 rivoplus volumio[10162]: ---------------------------- MPD announces state update: player May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::getState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand status May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand status took 54 milliseconds May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand status took 52 milliseconds May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand status took 13 milliseconds May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 13 milliseconds May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":338,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"3852.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3852.dsf","trackType":"dsf"} May 27 15:15:11 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus stop May 27 15:15:11 rivoplus volumio[10162]: info: ------------------------------ 63ms May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand status took 22 milliseconds May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand status took 20 milliseconds May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 17 milliseconds May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseState May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":131,"duration":338,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3852.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3852.dsf","trackType":"dsf"} May 27 15:15:11 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:15:11 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":137,"duration":338,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3852.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3852.dsf","trackType":"dsf"} May 27 15:15:11 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:15:11 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":148,"duration":338,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3852.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3852.dsf","trackType":"dsf"} May 27 15:15:11 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:15:11 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: ------------------------------ 175ms May 27 15:15:11 rivoplus volumio[10162]: info: ------------------------------ 173ms May 27 15:15:11 rivoplus volumio[10162]: info: ------------------------------ 135ms May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 106 milliseconds May 27 15:15:11 rivoplus volumio[10162]: info: sendMpdCommand playlistinfo took 105 milliseconds May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:15:11 rivoplus volumio[10162]: verbose: ControllerMpd::parseTrackInfo May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":457,"duration":338,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3852.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3852.dsf","trackType":"dsf"} May 27 15:15:11 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:15:11 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: ControllerMpd::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::servicePushState May 27 15:15:11 rivoplus volumio[10162]: info: CorePlayQueue::getTrack 0 May 27 15:15:11 rivoplus volumio[10162]: verbose: STATE SERVICE {"status":"play","position":0,"seek":457,"duration":338,"samplerate":"2.82 MHz","bitdepth":"1 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"5644 Kbps","isStreaming":false,"title":"3852.dsf","artist":null,"album":null,"uri":"http://192.168.1.250:50002/m/NDLNA/3852.dsf","trackType":"dsf"} May 27 15:15:11 rivoplus volumio[10162]: verbose: CURRENT POSITION 0 May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState stateService play May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::syncState currentStatus play May 27 15:15:11 rivoplus volumio[10162]: info: Received an update from plugin. extracting info from payload May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: CoreStateMachine::pushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioPushState May 27 15:15:11 rivoplus volumio[10162]: info: CoreCommandRouter::volumioGetState May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output update for this device May 27 15:15:11 rivoplus volumio[10162]: info: MRS: Pushing multiroomSync output May 27 15:15:11 rivoplus volumio[10162]: info: ------------------------------ 172ms May 27 15:15:11 rivoplus volumio[10162]: info: ------------------------------ 171ms May 27 15:15:11 rivoplus volumio[10162]: info: Signalling Playback active due to playback status change May 27 15:15:11 rivoplus volumio[10162]: info: MCU Signalled Playback Active May 27 15:15:14 rivoplus volumio[10162]: info: Executing endpoint metavolumio May 27 15:15:14 rivoplus volumio[10162]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 27 15:15:57 rivoplus volumio[10162]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 27 15:15:57 rivoplus volumio[10162]: Error: connect ETIMEDOUT 151.101.194.79:443 May 27 15:15:57 rivoplus volumio[10162]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { May 27 15:15:57 rivoplus volumio[10162]: errno: -110, May 27 15:15:57 rivoplus volumio[10162]: code: 'ETIMEDOUT', May 27 15:15:57 rivoplus volumio[10162]: syscall: 'connect', May 27 15:15:57 rivoplus volumio[10162]: address: '151.101.194.79', May 27 15:15:57 rivoplus volumio[10162]: port: 443 May 27 15:15:57 rivoplus volumio[10162]: } May 27 15:15:57 rivoplus volumio[10162]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 27 15:15:57 rivoplus sudo[11518]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-27 15:14 May 27 15:15:57 rivoplus sudo[11518]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 06:04:38 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="0064c1a7ac4363e567dacab062cb5da8"