-- Logs begin at Wed 2025-09-03 09:03:54 +07, end at Wed 2025-09-03 09:21:17 +07. -- Sep 03 09:20:07 rivoplus volumio[3477]: info: Preload queue cleared Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::ClearQueue Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::stop Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::stPlaybackTimer Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::updateTrackBlock Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::getTrackBlock Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:07 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:07 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::serviceStop Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::serviceStop Sep 03 09:20:07 rivoplus volumio[3477]: info: [1756866007098] ControllerTidal::stop Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 03 09:20:07 rivoplus volumio[3477]: info: ControllerMpd::stop Sep 03 09:20:07 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand stop Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::clearPlayQueue Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::saveQueue Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushQueue Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::addQueueItems Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::addQueueItems Sep 03 09:20:07 rivoplus volumio[3477]: info: Preload queue cleared Sep 03 09:20:07 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/325727418 Sep 03 09:20:07 rivoplus volumio[3477]: info: Using cached record of: tidal://song/325727418 Sep 03 09:20:07 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/325727420 Sep 03 09:20:07 rivoplus volumio[3477]: info: Using cached record of: tidal://song/325727420 Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushQueue Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::saveQueue Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::updateTrackBlock Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::getTrackBlock Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPlay Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::play index 1 Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::addQueueItems Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::addQueueItems Sep 03 09:20:07 rivoplus volumio[3477]: info: Preload queue cleared Sep 03 09:20:07 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/325727421 Sep 03 09:20:07 rivoplus volumio[3477]: info: Using cached record of: tidal://song/325727421 Sep 03 09:20:07 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/325727422 Sep 03 09:20:07 rivoplus volumio[3477]: info: Using cached record of: tidal://song/325727422 Sep 03 09:20:07 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/325727423 Sep 03 09:20:07 rivoplus volumio[3477]: info: Using cached record of: tidal://song/325727423 Sep 03 09:20:07 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/325727424 Sep 03 09:20:07 rivoplus volumio[3477]: info: Using cached record of: tidal://song/325727424 Sep 03 09:20:07 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/325727426 Sep 03 09:20:07 rivoplus volumio[3477]: info: Using cached record of: tidal://song/325727426 Sep 03 09:20:07 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/325727427 Sep 03 09:20:07 rivoplus volumio[3477]: info: Using cached record of: tidal://song/325727427 Sep 03 09:20:07 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/325727428 Sep 03 09:20:07 rivoplus volumio[3477]: info: Using cached record of: tidal://song/325727428 Sep 03 09:20:07 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/325727429 Sep 03 09:20:07 rivoplus volumio[3477]: info: Using cached record of: tidal://song/325727429 Sep 03 09:20:07 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/325727430 Sep 03 09:20:07 rivoplus volumio[3477]: info: Using cached record of: tidal://song/325727430 Sep 03 09:20:07 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/325727431 Sep 03 09:20:07 rivoplus volumio[3477]: info: Using cached record of: tidal://song/325727431 Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::stop Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushQueue Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::saveQueue Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::play index undefined Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::updateTrackBlock Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::getTrackBlock Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::startPlaybackTimer Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:07 rivoplus volumio[3477]: info: [1756866007146] ControllerTidal::clearAddPlayTrack Sep 03 09:20:07 rivoplus volumio[3477]: info: Getting stream with soundQuality HI_RES Sep 03 09:20:07 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand stop Sep 03 09:20:07 rivoplus volumio[3477]: info: sendMpdCommand stop took 66 milliseconds Sep 03 09:20:07 rivoplus volumio[3477]: info: Sep 03 09:20:07 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:07 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:07 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:07 rivoplus volumio[3477]: info: sendMpdCommand stop took 22 milliseconds Sep 03 09:20:07 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand clear Sep 03 09:20:07 rivoplus volumio[3477]: info: Sep 03 09:20:07 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:07 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:07 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:07 rivoplus volumio[3477]: info: Sep 03 09:20:07 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:07 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:07 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:07 rivoplus volumio[3477]: info: Sep 03 09:20:07 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:20:07 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:20:07 rivoplus volumio[3477]: info: sendMpdCommand status took 10 milliseconds Sep 03 09:20:07 rivoplus volumio[3477]: info: sendMpdCommand clear took 10 milliseconds Sep 03 09:20:07 rivoplus volumio[3477]: info: sendMpdCommand status took 7 milliseconds Sep 03 09:20:07 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:07 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:07 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/325727420&soundQuality=HI_RES" Sep 03 09:20:07 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:07 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:07 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:07 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:07 rivoplus volumio[3477]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Sep 03 09:20:07 rivoplus volumio[3477]: info: ------------------------------ 39ms Sep 03 09:20:07 rivoplus volumio[3477]: info: Sep 03 09:20:07 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:20:07 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:20:07 rivoplus volumio[3477]: info: Sep 03 09:20:07 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:20:07 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:20:07 rivoplus volumio[3477]: error: updateQueue error: null Sep 03 09:20:07 rivoplus volumio[3477]: info: Sep 03 09:20:07 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:20:07 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:20:07 rivoplus volumio[3477]: info: sendMpdCommand status took 49 milliseconds Sep 03 09:20:07 rivoplus volumio[3477]: info: ------------------------------ 46ms Sep 03 09:20:07 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 44 milliseconds Sep 03 09:20:07 rivoplus volumio[3477]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/325727420&soundQuality=HI_RES" took 44 milliseconds Sep 03 09:20:07 rivoplus volumio[3477]: info: ------------------------------ 12ms Sep 03 09:20:07 rivoplus volumio[3477]: info: ------------------------------ 10ms Sep 03 09:20:07 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:07 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 03 09:20:07 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand play Sep 03 09:20:07 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:07 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:07 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:07 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:07 rivoplus volumio[3477]: 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} Sep 03 09:20:07 rivoplus volumio[3477]: verbose: CURRENT POSITION 1 Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService stop Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus stop Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:07 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:07 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:07 rivoplus volumio[3477]: info: No code Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:07 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:07 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:07 rivoplus volumio[3477]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Sep 03 09:20:07 rivoplus volumio[3477]: STREAMING PROXY: Handling url /?data=tidal://song/325727420&soundQuality=HI_RES Sep 03 09:20:07 rivoplus volumio[3477]: info: ------------------------------ 96ms Sep 03 09:20:07 rivoplus volumio[3477]: info: ------------------------------ 103ms Sep 03 09:20:07 rivoplus volumio[3477]: info: Sep 03 09:20:07 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:20:07 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:20:07 rivoplus volumio[3477]: info: Sep 03 09:20:07 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:20:07 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:20:07 rivoplus volumio[3477]: info: Signalling Playback active due to playback status change Sep 03 09:20:07 rivoplus volumio[3477]: info: ------------------------------ 105ms Sep 03 09:20:07 rivoplus volumio[3477]: info: sendMpdCommand play took 101 milliseconds Sep 03 09:20:07 rivoplus volumio[3477]: info: ------------------------------ 46ms Sep 03 09:20:07 rivoplus volumio[3477]: info: ------------------------------ 44ms Sep 03 09:20:07 rivoplus volumio[3477]: info: MCU Signalled Playback Inactive Sep 03 09:20:07 rivoplus volumio[3477]: info: Executing endpoint getStreamUrltidal Sep 03 09:20:07 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Sep 03 09:20:07 rivoplus volumio[3477]: info: MCU Signalled Playback Active Sep 03 09:20:08 rivoplus volumio[3477]: info: getStreamUrl took 807 milliseconds Sep 03 09:20:08 rivoplus volumio[3477]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEiczM2M1ZDRiMTU5ZTA1NmVhZGYwMTE0YWRlZGMxNGQ0Y182MS5tcDQ/0.flac?token=1756869608~N2E4NDZkOWUwMGQ4ODlkZDBlM2I2OGNjMjY3OWU5MWJkNmYyODNlZg== Sep 03 09:20:08 rivoplus volumio[3477]: STREAMING PROXY: Response: 200, length: 25470751 Sep 03 09:20:08 rivoplus volumio[3477]: info: Sep 03 09:20:08 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:08 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:08 rivoplus volumio[3477]: info: Sep 03 09:20:08 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:08 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:08 rivoplus volumio[3477]: info: Sep 03 09:20:08 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:08 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:08 rivoplus volumio[3477]: info: sendMpdCommand status took 11 milliseconds Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:08 rivoplus volumio[3477]: info: Sep 03 09:20:08 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:08 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:08 rivoplus volumio[3477]: info: sendMpdCommand status took 13 milliseconds Sep 03 09:20:08 rivoplus volumio[3477]: info: sendMpdCommand status took 13 milliseconds Sep 03 09:20:08 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 4 milliseconds Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:20:08 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:08 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":233,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"325727420&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/325727420&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:20:08 rivoplus volumio[3477]: verbose: CURRENT POSITION 1 Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus stop Sep 03 09:20:08 rivoplus volumio[3477]: info: ------------------------------ 22ms Sep 03 09:20:08 rivoplus volumio[3477]: info: Sep 03 09:20:08 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:08 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:08 rivoplus volumio[3477]: info: Sep 03 09:20:08 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:08 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:08 rivoplus volumio[3477]: info: sendMpdCommand status took 11 milliseconds Sep 03 09:20:08 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 9 milliseconds Sep 03 09:20:08 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 9 milliseconds Sep 03 09:20:08 rivoplus volumio[3477]: info: sendMpdCommand status took 6 milliseconds Sep 03 09:20:08 rivoplus volumio[3477]: info: sendMpdCommand status took 4 milliseconds Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:08 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:08 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":233,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"325727420&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/325727420&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:20:08 rivoplus volumio[3477]: verbose: CURRENT POSITION 1 Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus play Sep 03 09:20:08 rivoplus volumio[3477]: info: Received an update from plugin. extracting info from payload Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:08 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:08 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":233,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"325727420&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/325727420&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:20:08 rivoplus volumio[3477]: verbose: CURRENT POSITION 1 Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus play Sep 03 09:20:08 rivoplus volumio[3477]: info: Received an update from plugin. extracting info from payload Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:08 rivoplus volumio[3477]: info: ------------------------------ 87ms Sep 03 09:20:08 rivoplus volumio[3477]: info: ------------------------------ 88ms Sep 03 09:20:08 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 64 milliseconds Sep 03 09:20:08 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 63 milliseconds Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:20:08 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:20:08 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:08 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":233,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"325727420&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/325727420&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:20:08 rivoplus volumio[3477]: verbose: CURRENT POSITION 1 Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus play Sep 03 09:20:08 rivoplus volumio[3477]: info: Received an update from plugin. extracting info from payload Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:08 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:08 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":233,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"325727420&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/325727420&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:20:08 rivoplus volumio[3477]: verbose: CURRENT POSITION 1 Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus play Sep 03 09:20:08 rivoplus volumio[3477]: info: Received an update from plugin. extracting info from payload Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:08 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:08 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":233,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"325727420&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/325727420&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:20:08 rivoplus volumio[3477]: verbose: CURRENT POSITION 1 Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus play Sep 03 09:20:08 rivoplus volumio[3477]: info: Received an update from plugin. extracting info from payload Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:08 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:08 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:08 rivoplus volumio[3477]: info: ------------------------------ 180ms Sep 03 09:20:08 rivoplus volumio[3477]: info: ------------------------------ 175ms Sep 03 09:20:08 rivoplus volumio[3477]: info: ------------------------------ 176ms Sep 03 09:20:11 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 03 09:20:11 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 03 09:20:11 rivoplus volumio[3477]: info: Discovery: Getting this device information Sep 03 09:20:11 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:11 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 03 09:20:11 rivoplus ntpd[8365]: Soliciting pool server 103.70.115.65 Sep 03 09:20:13 rivoplus ntpd[8365]: Soliciting pool server 103.70.115.65 Sep 03 09:20:15 rivoplus ntpd[8365]: Soliciting pool server 103.70.115.65 Sep 03 09:20:16 rivoplus ntpd[8365]: Soliciting pool server 103.70.115.65 Sep 03 09:20:20 rivoplus volumio[3477]: STREAMING PROXY: Client dropped request, destroying Sep 03 09:20:20 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Sep 03 09:20:21 rivoplus volumio[3477]: info: browseTIDALUri took 884 milliseconds Sep 03 09:20:21 rivoplus volumio[3477]: info: Preload queue cleared Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087206 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087207 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087208 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087209 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087210 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087211 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087212 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087213 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087214 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087215 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087216 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087217 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087218 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087219 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087220 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087221 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087222 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087223 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087224 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087225 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087226 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087227 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087228 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087229 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087230 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087231 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087232 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087233 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087234 Sep 03 09:20:21 rivoplus volumio[3477]: info: Preloading song: tidal://song/328087235 Sep 03 09:20:21 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087206 in service tidal Sep 03 09:20:21 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087207 in service tidal Sep 03 09:20:21 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087208 in service tidal Sep 03 09:20:21 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087209 in service tidal Sep 03 09:20:21 rivoplus volumio[3477]: info: Executing endpoint getSimilarAlbums Sep 03 09:20:21 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Sep 03 09:20:21 rivoplus volumio[3477]: info: Executing endpoint getSimilarAlbums Sep 03 09:20:21 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Sep 03 09:20:21 rivoplus volumio[3477]: info: Executing endpoint getSimilarAlbums Sep 03 09:20:21 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Sep 03 09:20:21 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087210 in service tidal Sep 03 09:20:21 rivoplus volumio[3477]: info: Executing endpoint getSimilarAlbums Sep 03 09:20:21 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Sep 03 09:20:21 rivoplus volumio[3477]: info: Executing endpoint getSimilarAlbums Sep 03 09:20:21 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Sep 03 09:20:21 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087211 in service tidal Sep 03 09:20:21 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087212 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087213 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087214 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087215 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087216 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087217 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: explodeTIDALUri took 556 milliseconds Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087218 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087219 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087220 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: explodeTIDALUri took 693 milliseconds Sep 03 09:20:22 rivoplus volumio[3477]: info: explodeTIDALUri took 646 milliseconds Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087221 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087222 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087223 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: explodeTIDALUri took 736 milliseconds Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087224 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: explodeTIDALUri took 657 milliseconds Sep 03 09:20:22 rivoplus volumio[3477]: info: explodeTIDALUri took 643 milliseconds Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087225 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: explodeTIDALUri took 623 milliseconds Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087226 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: explodeTIDALUri took 524 milliseconds Sep 03 09:20:22 rivoplus volumio[3477]: info: explodeTIDALUri took 626 milliseconds Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087227 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087228 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: explodeTIDALUri took 590 milliseconds Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087229 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087230 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: explodeTIDALUri took 574 milliseconds Sep 03 09:20:22 rivoplus volumio[3477]: info: explodeTIDALUri took 1029 milliseconds Sep 03 09:20:22 rivoplus volumio[3477]: info: explodeTIDALUri took 789 milliseconds Sep 03 09:20:22 rivoplus volumio[3477]: info: explodeTIDALUri took 644 milliseconds Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087231 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087232 in service tidal Sep 03 09:20:22 rivoplus volumio[3477]: info: explodeTIDALUri took 579 milliseconds Sep 03 09:20:23 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087233 in service tidal Sep 03 09:20:23 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087234 in service tidal Sep 03 09:20:23 rivoplus volumio[3477]: info: Exploding uri tidal://song/328087235 in service tidal Sep 03 09:20:23 rivoplus volumio[3477]: info: explodeTIDALUri took 625 milliseconds Sep 03 09:20:23 rivoplus volumio[3477]: info: explodeTIDALUri took 591 milliseconds Sep 03 09:20:23 rivoplus volumio[3477]: info: explodeTIDALUri took 843 milliseconds Sep 03 09:20:23 rivoplus volumio[3477]: info: explodeTIDALUri took 746 milliseconds Sep 03 09:20:23 rivoplus volumio[3477]: info: explodeTIDALUri took 581 milliseconds Sep 03 09:20:23 rivoplus volumio[3477]: info: explodeTIDALUri took 598 milliseconds Sep 03 09:20:23 rivoplus volumio[3477]: info: explodeTIDALUri took 555 milliseconds Sep 03 09:20:23 rivoplus volumio[3477]: info: explodeTIDALUri took 571 milliseconds Sep 03 09:20:23 rivoplus volumio[3477]: info: explodeTIDALUri took 543 milliseconds Sep 03 09:20:23 rivoplus volumio[3477]: info: explodeTIDALUri took 549 milliseconds Sep 03 09:20:23 rivoplus volumio[3477]: info: explodeTIDALUri took 514 milliseconds Sep 03 09:20:23 rivoplus volumio[3477]: info: explodeTIDALUri took 592 milliseconds Sep 03 09:20:23 rivoplus volumio[3477]: info: explodeTIDALUri took 667 milliseconds Sep 03 09:20:23 rivoplus volumio[3477]: info: explodeTIDALUri took 590 milliseconds Sep 03 09:20:23 rivoplus volumio[3477]: info: explodeTIDALUri took 569 milliseconds Sep 03 09:20:23 rivoplus volumio[3477]: info: Preload queue cleared Sep 03 09:20:23 rivoplus volumio[3477]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 03 09:20:23 rivoplus volumio[3477]: info: CoreStateMachine::ClearQueue Sep 03 09:20:23 rivoplus volumio[3477]: info: CoreStateMachine::stop Sep 03 09:20:23 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 09:20:23 rivoplus volumio[3477]: info: CoreStateMachine::stPlaybackTimer Sep 03 09:20:23 rivoplus volumio[3477]: info: CoreStateMachine::updateTrackBlock Sep 03 09:20:23 rivoplus volumio[3477]: info: CorePlayQueue::getTrackBlock Sep 03 09:20:23 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:23 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:23 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 09:20:23 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:23 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:23 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:23 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:23 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:23 rivoplus volumio[3477]: info: CoreStateMachine::serviceStop Sep 03 09:20:23 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:23 rivoplus volumio[3477]: info: CoreCommandRouter::serviceStop Sep 03 09:20:23 rivoplus volumio[3477]: info: [1756866023993] ControllerTidal::stop Sep 03 09:20:23 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 03 09:20:23 rivoplus volumio[3477]: info: ControllerMpd::stop Sep 03 09:20:23 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand stop Sep 03 09:20:23 rivoplus volumio[3477]: info: CorePlayQueue::clearPlayQueue Sep 03 09:20:23 rivoplus volumio[3477]: info: CorePlayQueue::saveQueue Sep 03 09:20:23 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushQueue Sep 03 09:20:23 rivoplus volumio[3477]: info: CoreStateMachine::addQueueItems Sep 03 09:20:23 rivoplus volumio[3477]: info: CorePlayQueue::addQueueItems Sep 03 09:20:23 rivoplus volumio[3477]: info: Preload queue cleared Sep 03 09:20:23 rivoplus volumio[3477]: info: Adding Item to queue: tidal://album/328087197 Sep 03 09:20:23 rivoplus volumio[3477]: info: Exploding uri tidal://album/328087197 in service tidal Sep 03 09:20:24 rivoplus volumio[3477]: info: Sep 03 09:20:24 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:24 rivoplus volumio[3477]: info: sendMpdCommand stop took 69 milliseconds Sep 03 09:20:24 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:24 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:24 rivoplus volumio[3477]: info: Sep 03 09:20:24 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:24 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:24 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:24 rivoplus volumio[3477]: info: Sep 03 09:20:24 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:24 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:24 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:24 rivoplus volumio[3477]: info: sendMpdCommand status took 8 milliseconds Sep 03 09:20:24 rivoplus volumio[3477]: info: sendMpdCommand status took 5 milliseconds Sep 03 09:20:24 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:24 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:24 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:24 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:24 rivoplus volumio[3477]: info: sendMpdCommand status took 6 milliseconds Sep 03 09:20:24 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:24 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:24 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 5 milliseconds Sep 03 09:20:24 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 2 milliseconds Sep 03 09:20:24 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:20:24 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:24 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:24 rivoplus volumio[3477]: 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":"325727420&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/325727420&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:20:24 rivoplus volumio[3477]: verbose: CURRENT POSITION 1 Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService stop Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus stop Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:24 rivoplus volumio[3477]: info: No code Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:24 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:24 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:24 rivoplus volumio[3477]: 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":"325727420&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/325727420&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:20:24 rivoplus volumio[3477]: verbose: CURRENT POSITION 1 Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService stop Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus stop Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:24 rivoplus volumio[3477]: info: No code Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:24 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:24 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 1 Sep 03 09:20:24 rivoplus volumio[3477]: 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":"325727420&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/325727420&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:20:24 rivoplus volumio[3477]: verbose: CURRENT POSITION 1 Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService stop Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus stop Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:24 rivoplus volumio[3477]: info: No code Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:24 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:24 rivoplus volumio[3477]: info: ------------------------------ 123ms Sep 03 09:20:24 rivoplus volumio[3477]: info: ------------------------------ 120ms Sep 03 09:20:24 rivoplus volumio[3477]: info: ------------------------------ 120ms Sep 03 09:20:24 rivoplus volumio[3477]: info: Signalling Playback active due to playback status change Sep 03 09:20:24 rivoplus volumio[3477]: info: MCU Signalled Playback Inactive Sep 03 09:20:24 rivoplus volumio[3477]: info: MCU Signalled Playback Active Sep 03 09:20:24 rivoplus volumio[3477]: info: explodeTIDALUri took 585 milliseconds Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushQueue Sep 03 09:20:24 rivoplus volumio[3477]: info: CorePlayQueue::saveQueue Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::updateTrackBlock Sep 03 09:20:24 rivoplus volumio[3477]: info: CorePlayQueue::getTrackBlock Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPlay Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::play index 0 Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::stop Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::play index undefined Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 09:20:24 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::startPlaybackTimer Sep 03 09:20:24 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:24 rivoplus volumio[3477]: info: [1756866024599] ControllerTidal::clearAddPlayTrack Sep 03 09:20:24 rivoplus volumio[3477]: info: Getting stream with soundQuality HI_RES Sep 03 09:20:24 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand stop Sep 03 09:20:24 rivoplus volumio[3477]: info: sendMpdCommand stop took 9 milliseconds Sep 03 09:20:24 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand clear Sep 03 09:20:24 rivoplus volumio[3477]: info: Sep 03 09:20:24 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:20:24 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:20:24 rivoplus volumio[3477]: info: sendMpdCommand clear took 1 milliseconds Sep 03 09:20:24 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/328087206&soundQuality=HI_RES" Sep 03 09:20:24 rivoplus volumio[3477]: info: Sep 03 09:20:24 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:20:24 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:20:24 rivoplus volumio[3477]: info: Sep 03 09:20:24 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:20:24 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:20:24 rivoplus volumio[3477]: error: updateQueue error: null Sep 03 09:20:24 rivoplus volumio[3477]: info: Sep 03 09:20:24 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:20:24 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:20:24 rivoplus volumio[3477]: info: ------------------------------ 6ms Sep 03 09:20:24 rivoplus volumio[3477]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/328087206&soundQuality=HI_RES" took 5 milliseconds Sep 03 09:20:24 rivoplus volumio[3477]: info: ------------------------------ 4ms Sep 03 09:20:24 rivoplus volumio[3477]: info: ------------------------------ 6ms Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 03 09:20:24 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand play Sep 03 09:20:24 rivoplus volumio[3477]: info: Sep 03 09:20:24 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:20:24 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:20:24 rivoplus volumio[3477]: info: Sep 03 09:20:24 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:20:24 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:20:24 rivoplus volumio[3477]: STREAMING PROXY: Handling url /?data=tidal://song/328087206&soundQuality=HI_RES Sep 03 09:20:24 rivoplus volumio[3477]: info: ------------------------------ 9ms Sep 03 09:20:24 rivoplus volumio[3477]: info: sendMpdCommand play took 5 milliseconds Sep 03 09:20:24 rivoplus volumio[3477]: info: Executing endpoint getStreamUrltidal Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Sep 03 09:20:24 rivoplus volumio[3477]: info: ------------------------------ 17ms Sep 03 09:20:24 rivoplus volumio[3477]: info: ------------------------------ 16ms Sep 03 09:20:24 rivoplus volumio[3477]: info: Executing endpoint metavolumio Sep 03 09:20:24 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 09:20:25 rivoplus volumio[3477]: info: getStreamUrl took 714 milliseconds Sep 03 09:20:25 rivoplus volumio[3477]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ4ZTdhMWI2ZDEyZDYxMWI2ZjlmNTE2ZmY0NjAwOWQzZS5tcDQ/0.flac?token=1756869625~NmJiNDg2ZmIzZDIxYmJhYmI0ZGFhMzViMjhiNDJhNmE4ZDgzMGUwMQ== Sep 03 09:20:25 rivoplus volumio[3477]: STREAMING PROXY: Response: 200, length: 28017769 Sep 03 09:20:25 rivoplus volumio[3477]: info: Sep 03 09:20:25 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:25 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:25 rivoplus volumio[3477]: info: Sep 03 09:20:25 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:25 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:25 rivoplus volumio[3477]: info: Sep 03 09:20:25 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:25 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:25 rivoplus volumio[3477]: info: Sep 03 09:20:25 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:25 rivoplus volumio[3477]: info: sendMpdCommand status took 35 milliseconds Sep 03 09:20:25 rivoplus volumio[3477]: info: sendMpdCommand status took 34 milliseconds Sep 03 09:20:25 rivoplus volumio[3477]: info: sendMpdCommand status took 34 milliseconds Sep 03 09:20:25 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:25 rivoplus volumio[3477]: info: Sep 03 09:20:25 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:25 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:25 rivoplus volumio[3477]: info: Sep 03 09:20:25 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:25 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:25 rivoplus volumio[3477]: info: sendMpdCommand status took 15 milliseconds Sep 03 09:20:25 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 14 milliseconds Sep 03 09:20:25 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 15 milliseconds Sep 03 09:20:25 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 14 milliseconds Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:20:25 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:25 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":288,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"328087206&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/328087206&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:20:25 rivoplus volumio[3477]: verbose: CURRENT POSITION 0 Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus stop Sep 03 09:20:25 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:25 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":22,"duration":288,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"328087206&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/328087206&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:20:25 rivoplus volumio[3477]: verbose: CURRENT POSITION 0 Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus play Sep 03 09:20:25 rivoplus volumio[3477]: info: Received an update from plugin. extracting info from payload Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:25 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:25 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":288,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"328087206&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/328087206&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:20:25 rivoplus volumio[3477]: verbose: CURRENT POSITION 0 Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus play Sep 03 09:20:25 rivoplus volumio[3477]: info: Received an update from plugin. extracting info from payload Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:25 rivoplus volumio[3477]: info: ------------------------------ 94ms Sep 03 09:20:25 rivoplus volumio[3477]: info: ------------------------------ 118ms Sep 03 09:20:25 rivoplus volumio[3477]: info: ------------------------------ 118ms Sep 03 09:20:25 rivoplus volumio[3477]: info: sendMpdCommand status took 80 milliseconds Sep 03 09:20:25 rivoplus volumio[3477]: info: sendMpdCommand status took 72 milliseconds Sep 03 09:20:25 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 64 milliseconds Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:20:25 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:25 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1075,"duration":288,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"401 Kbps","isStreaming":false,"title":"328087206&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/328087206&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:20:25 rivoplus volumio[3477]: verbose: CURRENT POSITION 0 Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus play Sep 03 09:20:25 rivoplus volumio[3477]: info: Received an update from plugin. extracting info from payload Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:25 rivoplus volumio[3477]: info: ------------------------------ 117ms Sep 03 09:20:25 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 75 milliseconds Sep 03 09:20:25 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:20:25 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:25 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1075,"duration":288,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"401 Kbps","isStreaming":false,"title":"328087206&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/328087206&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:20:25 rivoplus volumio[3477]: verbose: CURRENT POSITION 0 Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus play Sep 03 09:20:25 rivoplus volumio[3477]: info: Received an update from plugin. extracting info from payload Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:25 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:25 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1075,"duration":288,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"401 Kbps","isStreaming":false,"title":"328087206&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/328087206&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:20:25 rivoplus volumio[3477]: verbose: CURRENT POSITION 0 Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus play Sep 03 09:20:25 rivoplus volumio[3477]: info: Received an update from plugin. extracting info from payload Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:25 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:25 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:26 rivoplus volumio[3477]: info: ------------------------------ 251ms Sep 03 09:20:26 rivoplus volumio[3477]: info: ------------------------------ 246ms Sep 03 09:20:26 rivoplus volumio[3477]: info: Executing endpoint metavolumio Sep 03 09:20:26 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 09:20:26 rivoplus volumio[3477]: info: Executing endpoint metavolumio Sep 03 09:20:26 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 09:20:26 rivoplus volumio[3477]: info: Executing endpoint metavolumio Sep 03 09:20:26 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 09:20:27 rivoplus volumio[3477]: info: Executing endpoint metavolumio Sep 03 09:20:27 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 09:20:27 rivoplus volumio[3477]: info: Executing endpoint metavolumio Sep 03 09:20:27 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 09:20:27 rivoplus volumio[3477]: info: Executing endpoint metavolumio Sep 03 09:20:27 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 09:20:28 rivoplus volumio[3477]: info: Executing endpoint metavolumio Sep 03 09:20:28 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 09:20:30 rivoplus volumio[3477]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/BTS/Love%20Yourself%3A%20Tear/f968dcac-fd8b-4b1a-a2c2-079a412b91ba.jpg' Sep 03 09:20:34 rivoplus volumio[3477]: error: Failed request for metavolumio API Sep 03 09:20:37 rivoplus volumio[3477]: info: Preload queue cleared Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::ClearQueue Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::stop Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::stPlaybackTimer Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::updateTrackBlock Sep 03 09:20:37 rivoplus volumio[3477]: info: CorePlayQueue::getTrackBlock Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:37 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:37 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:37 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::serviceStop Sep 03 09:20:37 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::serviceStop Sep 03 09:20:37 rivoplus volumio[3477]: info: [1756866037354] ControllerTidal::stop Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 03 09:20:37 rivoplus volumio[3477]: info: ControllerMpd::stop Sep 03 09:20:37 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand stop Sep 03 09:20:37 rivoplus volumio[3477]: info: CorePlayQueue::clearPlayQueue Sep 03 09:20:37 rivoplus volumio[3477]: info: CorePlayQueue::saveQueue Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushQueue Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::addQueueItems Sep 03 09:20:37 rivoplus volumio[3477]: info: CorePlayQueue::addQueueItems Sep 03 09:20:37 rivoplus volumio[3477]: info: Preload queue cleared Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087206 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087206 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087207 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087207 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087208 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087208 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087209 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087209 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087210 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087210 Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushQueue Sep 03 09:20:37 rivoplus volumio[3477]: info: CorePlayQueue::saveQueue Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::updateTrackBlock Sep 03 09:20:37 rivoplus volumio[3477]: info: CorePlayQueue::getTrackBlock Sep 03 09:20:37 rivoplus volumio[3477]: STREAMING PROXY: Client dropped request, destroying Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPlay Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::play index 4 Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::addQueueItems Sep 03 09:20:37 rivoplus volumio[3477]: info: CorePlayQueue::addQueueItems Sep 03 09:20:37 rivoplus volumio[3477]: info: Preload queue cleared Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087211 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087211 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087212 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087212 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087213 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087213 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087214 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087214 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087215 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087215 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087216 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087216 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087217 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087217 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087218 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087218 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087219 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087219 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087220 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087220 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087221 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087221 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087222 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087222 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087223 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087223 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087224 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087224 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087225 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087225 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087226 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087226 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087227 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087227 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087228 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087228 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087229 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087229 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087230 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087230 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087231 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087231 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087232 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087232 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087233 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087233 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087234 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087234 Sep 03 09:20:37 rivoplus volumio[3477]: info: Adding Item to queue: tidal://song/328087235 Sep 03 09:20:37 rivoplus volumio[3477]: info: Using cached record of: tidal://song/328087235 Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::stop Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushQueue Sep 03 09:20:37 rivoplus volumio[3477]: info: CorePlayQueue::saveQueue Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::play index undefined Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::updateTrackBlock Sep 03 09:20:37 rivoplus volumio[3477]: info: CorePlayQueue::getTrackBlock Sep 03 09:20:37 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 4 Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::startPlaybackTimer Sep 03 09:20:37 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 4 Sep 03 09:20:37 rivoplus volumio[3477]: info: [1756866037417] ControllerTidal::clearAddPlayTrack Sep 03 09:20:37 rivoplus volumio[3477]: info: Getting stream with soundQuality HI_RES Sep 03 09:20:37 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand stop Sep 03 09:20:37 rivoplus volumio[3477]: info: Sep 03 09:20:37 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:37 rivoplus volumio[3477]: info: sendMpdCommand stop took 90 milliseconds Sep 03 09:20:37 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:37 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:37 rivoplus volumio[3477]: info: sendMpdCommand stop took 27 milliseconds Sep 03 09:20:37 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand clear Sep 03 09:20:37 rivoplus volumio[3477]: info: Sep 03 09:20:37 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:20:37 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:20:37 rivoplus volumio[3477]: info: sendMpdCommand status took 5 milliseconds Sep 03 09:20:37 rivoplus volumio[3477]: info: sendMpdCommand clear took 5 milliseconds Sep 03 09:20:37 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:37 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:20:37 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/328087210&soundQuality=HI_RES" Sep 03 09:20:37 rivoplus volumio[3477]: info: Sep 03 09:20:37 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:37 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:37 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:37 rivoplus volumio[3477]: info: Sep 03 09:20:37 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:20:37 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:20:37 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:20:37 rivoplus volumio[3477]: error: updateQueue error: null Sep 03 09:20:37 rivoplus volumio[3477]: info: Sep 03 09:20:37 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:20:37 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:20:37 rivoplus volumio[3477]: info: ------------------------------ 12ms Sep 03 09:20:37 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 10 milliseconds Sep 03 09:20:37 rivoplus volumio[3477]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/328087210&soundQuality=HI_RES" took 10 milliseconds Sep 03 09:20:37 rivoplus volumio[3477]: info: sendMpdCommand status took 8 milliseconds Sep 03 09:20:37 rivoplus volumio[3477]: info: sendMpdCommand status took 6 milliseconds Sep 03 09:20:37 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 03 09:20:37 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand play Sep 03 09:20:37 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:37 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:20:37 rivoplus volumio[3477]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Sep 03 09:20:37 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:37 rivoplus volumio[3477]: STREAMING PROXY: Handling url /?data=tidal://song/328087210&soundQuality=HI_RES Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:37 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:37 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:37 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 4 Sep 03 09:20:37 rivoplus volumio[3477]: 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} Sep 03 09:20:37 rivoplus volumio[3477]: verbose: CURRENT POSITION 4 Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService stop Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus stop Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:37 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:37 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:37 rivoplus volumio[3477]: info: No code Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:37 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:37 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:37 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:37 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:37 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:37 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 4 Sep 03 09:20:37 rivoplus volumio[3477]: 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} Sep 03 09:20:37 rivoplus volumio[3477]: verbose: CURRENT POSITION 4 Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService stop Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus stop Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:37 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:37 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:37 rivoplus volumio[3477]: info: No code Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:37 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:20:37 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:20:37 rivoplus volumio[3477]: info: ------------------------------ 58ms Sep 03 09:20:37 rivoplus volumio[3477]: info: ------------------------------ 71ms Sep 03 09:20:37 rivoplus volumio[3477]: info: Sep 03 09:20:37 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:20:37 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:20:37 rivoplus volumio[3477]: info: Sep 03 09:20:37 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:20:37 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:20:37 rivoplus volumio[3477]: info: ------------------------------ 81ms Sep 03 09:20:37 rivoplus volumio[3477]: info: sendMpdCommand play took 77 milliseconds Sep 03 09:20:37 rivoplus volumio[3477]: info: ------------------------------ 8ms Sep 03 09:20:37 rivoplus volumio[3477]: info: ------------------------------ 6ms Sep 03 09:20:37 rivoplus volumio[3477]: info: Signalling Playback active due to playback status change Sep 03 09:20:37 rivoplus volumio[3477]: info: Executing endpoint getStreamUrltidal Sep 03 09:20:37 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Sep 03 09:20:37 rivoplus volumio[3477]: info: MCU Signalled Playback Inactive Sep 03 09:20:37 rivoplus volumio[3477]: info: MCU Signalled Playback Active Sep 03 09:20:38 rivoplus volumio[3477]: info: getStreamUrl took 809 milliseconds Sep 03 09:20:38 rivoplus volumio[3477]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ5OTdhZGQ4MDE3OTc4MDZlYTRkOTgxMjU2ZjA5M2EyZC5tcDQ/0.flac?token=1756869638~MzEwYTcyZWMzODU0ZDgxNGM5MmM1YzA2YmM5MzU1Y2ViYTY4NDVmYQ== Sep 03 09:20:41 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 03 09:20:41 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 03 09:20:41 rivoplus volumio[3477]: info: Discovery: Getting this device information Sep 03 09:20:41 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:20:41 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 03 09:20:41 rivoplus volumio[3477]: error: Failed request for metavolumio API Sep 03 09:20:41 rivoplus volumio[3477]: error: Failed request for metavolumio API Sep 03 09:21:10 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Sep 03 09:21:11 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 03 09:21:11 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 03 09:21:11 rivoplus volumio[3477]: info: Discovery: Getting this device information Sep 03 09:21:11 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:11 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 03 09:21:11 rivoplus volumio[3477]: info: browseTIDALUri took 891 milliseconds Sep 03 09:21:11 rivoplus volumio[3477]: info: Preload queue cleared Sep 03 09:21:11 rivoplus volumio[3477]: info: Preloading song: tidal://song/17819610 Sep 03 09:21:11 rivoplus volumio[3477]: info: Preloading song: tidal://song/17819611 Sep 03 09:21:11 rivoplus volumio[3477]: info: Preloading song: tidal://song/17819612 Sep 03 09:21:11 rivoplus volumio[3477]: info: Preloading song: tidal://song/17819613 Sep 03 09:21:11 rivoplus volumio[3477]: info: Preloading song: tidal://song/17819614 Sep 03 09:21:11 rivoplus volumio[3477]: info: Preloading song: tidal://song/17819615 Sep 03 09:21:11 rivoplus volumio[3477]: info: Preloading song: tidal://song/17819616 Sep 03 09:21:11 rivoplus volumio[3477]: info: Preloading song: tidal://song/17819617 Sep 03 09:21:11 rivoplus volumio[3477]: info: Preloading song: tidal://song/17819618 Sep 03 09:21:11 rivoplus volumio[3477]: info: Preloading song: tidal://song/17819619 Sep 03 09:21:11 rivoplus volumio[3477]: info: Preloading song: tidal://song/17819620 Sep 03 09:21:11 rivoplus volumio[3477]: info: Preloading song: tidal://song/17819621 Sep 03 09:21:11 rivoplus volumio[3477]: info: Preloading song: tidal://song/17819622 Sep 03 09:21:11 rivoplus volumio[3477]: info: Exploding uri tidal://song/17819610 in service tidal Sep 03 09:21:11 rivoplus volumio[3477]: info: Executing endpoint getSimilarAlbums Sep 03 09:21:11 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Sep 03 09:21:11 rivoplus volumio[3477]: info: Executing endpoint getSimilarAlbums Sep 03 09:21:11 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Sep 03 09:21:11 rivoplus volumio[3477]: info: Executing endpoint getSimilarAlbums Sep 03 09:21:11 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Sep 03 09:21:11 rivoplus volumio[3477]: info: Executing endpoint getSimilarAlbums Sep 03 09:21:11 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Sep 03 09:21:11 rivoplus volumio[3477]: info: Exploding uri tidal://song/17819611 in service tidal Sep 03 09:21:11 rivoplus volumio[3477]: info: Exploding uri tidal://song/17819612 in service tidal Sep 03 09:21:11 rivoplus volumio[3477]: info: Exploding uri tidal://song/17819613 in service tidal Sep 03 09:21:11 rivoplus volumio[3477]: info: Exploding uri tidal://song/17819614 in service tidal Sep 03 09:21:11 rivoplus volumio[3477]: info: Exploding uri tidal://song/17819615 in service tidal Sep 03 09:21:12 rivoplus volumio[3477]: info: Exploding uri tidal://song/17819616 in service tidal Sep 03 09:21:12 rivoplus volumio[3477]: info: Exploding uri tidal://song/17819617 in service tidal Sep 03 09:21:12 rivoplus volumio[3477]: info: Exploding uri tidal://song/17819618 in service tidal Sep 03 09:21:12 rivoplus volumio[3477]: info: Exploding uri tidal://song/17819619 in service tidal Sep 03 09:21:12 rivoplus volumio[3477]: info: Exploding uri tidal://song/17819620 in service tidal Sep 03 09:21:12 rivoplus volumio[3477]: info: Exploding uri tidal://song/17819621 in service tidal Sep 03 09:21:12 rivoplus volumio[3477]: info: explodeTIDALUri took 601 milliseconds Sep 03 09:21:12 rivoplus volumio[3477]: info: Exploding uri tidal://song/17819622 in service tidal Sep 03 09:21:12 rivoplus volumio[3477]: info: explodeTIDALUri took 569 milliseconds Sep 03 09:21:12 rivoplus volumio[3477]: info: explodeTIDALUri took 643 milliseconds Sep 03 09:21:12 rivoplus volumio[3477]: info: explodeTIDALUri took 610 milliseconds Sep 03 09:21:12 rivoplus volumio[3477]: info: explodeTIDALUri took 537 milliseconds Sep 03 09:21:12 rivoplus volumio[3477]: info: explodeTIDALUri took 639 milliseconds Sep 03 09:21:12 rivoplus volumio[3477]: info: explodeTIDALUri took 749 milliseconds Sep 03 09:21:12 rivoplus volumio[3477]: info: explodeTIDALUri took 620 milliseconds Sep 03 09:21:12 rivoplus volumio[3477]: info: explodeTIDALUri took 560 milliseconds Sep 03 09:21:12 rivoplus volumio[3477]: info: explodeTIDALUri took 527 milliseconds Sep 03 09:21:12 rivoplus volumio[3477]: info: explodeTIDALUri took 651 milliseconds Sep 03 09:21:12 rivoplus volumio[3477]: info: explodeTIDALUri took 585 milliseconds Sep 03 09:21:12 rivoplus volumio[3477]: info: explodeTIDALUri took 641 milliseconds Sep 03 09:21:13 rivoplus volumio[3477]: info: Executing endpoint getSimilarAlbums Sep 03 09:21:13 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Sep 03 09:21:13 rivoplus volumio[3477]: info: Executing endpoint metavolumio Sep 03 09:21:13 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 09:21:14 rivoplus volumio[3477]: info: Preload queue cleared Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::ClearQueue Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::stop Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 09:21:14 rivoplus volumio[3477]: info: CorePlayQueue::clearPlayQueue Sep 03 09:21:14 rivoplus volumio[3477]: info: CorePlayQueue::saveQueue Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushQueue Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::addQueueItems Sep 03 09:21:14 rivoplus volumio[3477]: info: CorePlayQueue::addQueueItems Sep 03 09:21:14 rivoplus volumio[3477]: info: Preload queue cleared Sep 03 09:21:14 rivoplus volumio[3477]: info: Adding Item to queue: tidal://album/17819609 Sep 03 09:21:14 rivoplus volumio[3477]: info: Exploding uri tidal://album/17819609 in service tidal Sep 03 09:21:14 rivoplus volumio[3477]: info: explodeTIDALUri took 408 milliseconds Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushQueue Sep 03 09:21:14 rivoplus volumio[3477]: info: CorePlayQueue::saveQueue Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::updateTrackBlock Sep 03 09:21:14 rivoplus volumio[3477]: info: CorePlayQueue::getTrackBlock Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPlay Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::play index 0 Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::stop Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::play index undefined Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 09:21:14 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::startPlaybackTimer Sep 03 09:21:14 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:21:14 rivoplus volumio[3477]: info: [1756866074813] ControllerTidal::clearAddPlayTrack Sep 03 09:21:14 rivoplus volumio[3477]: info: Getting stream with soundQuality HI_RES Sep 03 09:21:14 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand stop Sep 03 09:21:14 rivoplus volumio[3477]: STREAMING PROXY: Client dropped request, destroying Sep 03 09:21:14 rivoplus volumio[3477]: STREAMING PROXY: Error proxying request: Error: socket hang up Sep 03 09:21:14 rivoplus volumio[3477]: info: Sep 03 09:21:14 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:21:14 rivoplus volumio[3477]: info: sendMpdCommand stop took 9 milliseconds Sep 03 09:21:14 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:21:14 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:21:14 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand clear Sep 03 09:21:14 rivoplus volumio[3477]: info: Sep 03 09:21:14 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:21:14 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:21:14 rivoplus volumio[3477]: info: sendMpdCommand status took 3 milliseconds Sep 03 09:21:14 rivoplus volumio[3477]: info: sendMpdCommand clear took 3 milliseconds Sep 03 09:21:14 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:21:14 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:21:14 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/17819610&soundQuality=HI_RES" Sep 03 09:21:14 rivoplus volumio[3477]: info: Sep 03 09:21:14 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:21:14 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:21:14 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:21:14 rivoplus volumio[3477]: info: Sep 03 09:21:14 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:21:14 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:21:14 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:21:14 rivoplus volumio[3477]: error: updateQueue error: null Sep 03 09:21:14 rivoplus volumio[3477]: info: Sep 03 09:21:14 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:21:14 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:21:14 rivoplus volumio[3477]: info: ------------------------------ 13ms Sep 03 09:21:14 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 12 milliseconds Sep 03 09:21:14 rivoplus volumio[3477]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/17819610&soundQuality=HI_RES" took 12 milliseconds Sep 03 09:21:14 rivoplus volumio[3477]: info: sendMpdCommand status took 9 milliseconds Sep 03 09:21:14 rivoplus volumio[3477]: info: sendMpdCommand status took 8 milliseconds Sep 03 09:21:14 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 03 09:21:14 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand play Sep 03 09:21:14 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:21:14 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:21:14 rivoplus volumio[3477]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Sep 03 09:21:14 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:21:14 rivoplus volumio[3477]: STREAMING PROXY: Handling url /?data=tidal://song/17819610&soundQuality=HI_RES Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:14 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:21:14 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:21:14 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:21:14 rivoplus volumio[3477]: 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} Sep 03 09:21:14 rivoplus volumio[3477]: verbose: CURRENT POSITION 0 Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService stop Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus stop Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:14 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:21:14 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:21:14 rivoplus volumio[3477]: info: No code Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:14 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:21:14 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:21:14 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:14 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:21:14 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:21:14 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:21:14 rivoplus volumio[3477]: 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} Sep 03 09:21:14 rivoplus volumio[3477]: verbose: CURRENT POSITION 0 Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService stop Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus stop Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:14 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:21:14 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:21:14 rivoplus volumio[3477]: info: No code Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:14 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:21:14 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:21:14 rivoplus volumio[3477]: info: ------------------------------ 51ms Sep 03 09:21:14 rivoplus volumio[3477]: info: ------------------------------ 73ms Sep 03 09:21:14 rivoplus volumio[3477]: info: ------------------------------ 74ms Sep 03 09:21:14 rivoplus volumio[3477]: info: Sep 03 09:21:14 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:21:14 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:21:14 rivoplus volumio[3477]: info: Sep 03 09:21:14 rivoplus volumio[3477]: ---------------------------- MPD announces system playlist update Sep 03 09:21:14 rivoplus volumio[3477]: info: Ignoring MPD Status Update Sep 03 09:21:14 rivoplus volumio[3477]: info: ------------------------------ 78ms Sep 03 09:21:14 rivoplus volumio[3477]: info: sendMpdCommand play took 70 milliseconds Sep 03 09:21:14 rivoplus volumio[3477]: info: ------------------------------ 7ms Sep 03 09:21:14 rivoplus volumio[3477]: info: ------------------------------ 5ms Sep 03 09:21:14 rivoplus volumio[3477]: info: Executing endpoint getStreamUrltidal Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Sep 03 09:21:14 rivoplus volumio[3477]: info: Executing endpoint metavolumio Sep 03 09:21:14 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 09:21:15 rivoplus volumio[3477]: info: Executing endpoint metavolumio Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 09:21:15 rivoplus volumio[3477]: info: Executing endpoint metavolumio Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 09:21:15 rivoplus volumio[3477]: info: getStreamUrl took 547 milliseconds Sep 03 09:21:15 rivoplus volumio[3477]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidkMjM4NzI5NTZiZGVlMGU5NjFhNDM5NWFkN2U1NDM5Yl82MS5tcDQ/0.flac?token=1756869675~MWMwMDU4NjA3ZGVhNWVhMGU3M2JmMTdjMzA3ZGM2NjkzMmVlNmY3NQ== Sep 03 09:21:15 rivoplus volumio[3477]: STREAMING PROXY: Response: 200, length: 26060242 Sep 03 09:21:15 rivoplus volumio[3477]: info: Sep 03 09:21:15 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:21:15 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:21:15 rivoplus volumio[3477]: info: Sep 03 09:21:15 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:21:15 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:21:15 rivoplus volumio[3477]: info: Sep 03 09:21:15 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:21:15 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:21:15 rivoplus volumio[3477]: info: Sep 03 09:21:15 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:21:15 rivoplus volumio[3477]: info: sendMpdCommand status took 17 milliseconds Sep 03 09:21:15 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:21:15 rivoplus volumio[3477]: info: sendMpdCommand status took 18 milliseconds Sep 03 09:21:15 rivoplus volumio[3477]: info: sendMpdCommand status took 17 milliseconds Sep 03 09:21:15 rivoplus volumio[3477]: info: sendMpdCommand status took 3 milliseconds Sep 03 09:21:15 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 3 milliseconds Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:21:15 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:21:15 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17819610&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/17819610&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:21:15 rivoplus volumio[3477]: verbose: CURRENT POSITION 0 Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus stop Sep 03 09:21:15 rivoplus volumio[3477]: info: ------------------------------ 27ms Sep 03 09:21:15 rivoplus volumio[3477]: info: Sep 03 09:21:15 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:21:15 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:21:15 rivoplus volumio[3477]: info: Sep 03 09:21:15 rivoplus volumio[3477]: ---------------------------- MPD announces state update: player Sep 03 09:21:15 rivoplus volumio[3477]: info: ControllerMpd::getState Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand status Sep 03 09:21:15 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 10 milliseconds Sep 03 09:21:15 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 11 milliseconds Sep 03 09:21:15 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 10 milliseconds Sep 03 09:21:15 rivoplus volumio[3477]: info: sendMpdCommand status took 6 milliseconds Sep 03 09:21:15 rivoplus volumio[3477]: info: sendMpdCommand status took 4 milliseconds Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::parseState Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 03 09:21:15 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:21:15 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17819610&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/17819610&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:21:15 rivoplus volumio[3477]: verbose: CURRENT POSITION 0 Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus play Sep 03 09:21:15 rivoplus volumio[3477]: info: Received an update from plugin. extracting info from payload Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:21:15 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:21:15 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17819610&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/17819610&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:21:15 rivoplus volumio[3477]: verbose: CURRENT POSITION 0 Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus play Sep 03 09:21:15 rivoplus volumio[3477]: info: Received an update from plugin. extracting info from payload Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:21:15 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:21:15 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17819610&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/17819610&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:21:15 rivoplus volumio[3477]: verbose: CURRENT POSITION 0 Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus play Sep 03 09:21:15 rivoplus volumio[3477]: info: Received an update from plugin. extracting info from payload Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:21:15 rivoplus volumio[3477]: info: ------------------------------ 100ms Sep 03 09:21:15 rivoplus volumio[3477]: info: ------------------------------ 100ms Sep 03 09:21:15 rivoplus volumio[3477]: info: ------------------------------ 88ms Sep 03 09:21:15 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 71 milliseconds Sep 03 09:21:15 rivoplus volumio[3477]: info: sendMpdCommand playlistinfo took 72 milliseconds Sep 03 09:21:15 rivoplus volumio[3477]: verbose: ControllerMpd::parseTrackInfo Sep 03 09:21:15 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:21:15 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17819610&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/17819610&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:21:15 rivoplus volumio[3477]: verbose: CURRENT POSITION 0 Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus play Sep 03 09:21:15 rivoplus volumio[3477]: info: Received an update from plugin. extracting info from payload Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:21:15 rivoplus volumio[3477]: info: ControllerMpd::pushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::servicePushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CorePlayQueue::getTrack 0 Sep 03 09:21:15 rivoplus volumio[3477]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1166,"duration":239,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"514 Kbps","isStreaming":false,"title":"17819610&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/17819610&soundQuality=HI_RES","trackType":"tidal"} Sep 03 09:21:15 rivoplus volumio[3477]: verbose: CURRENT POSITION 0 Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::syncState stateService play Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::syncState currentStatus play Sep 03 09:21:15 rivoplus volumio[3477]: info: Received an update from plugin. extracting info from payload Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:21:15 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:15 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:21:16 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:21:16 rivoplus volumio[3477]: info: CoreStateMachine::pushState Sep 03 09:21:16 rivoplus volumio[3477]: info: CoreCommandRouter::volumioPushState Sep 03 09:21:16 rivoplus volumio[3477]: info: CoreCommandRouter::volumioGetState Sep 03 09:21:16 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output update for this device Sep 03 09:21:16 rivoplus volumio[3477]: info: MRS: Pushing multiroomSync output Sep 03 09:21:16 rivoplus volumio[3477]: info: ------------------------------ 168ms Sep 03 09:21:16 rivoplus volumio[3477]: info: ------------------------------ 168ms Sep 03 09:21:16 rivoplus volumio[3477]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 03 09:21:16 rivoplus volumio[3477]: Error: connect ETIMEDOUT 151.101.194.79:443 Sep 03 09:21:16 rivoplus volumio[3477]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Sep 03 09:21:16 rivoplus volumio[3477]: errno: -110, Sep 03 09:21:16 rivoplus volumio[3477]: code: 'ETIMEDOUT', Sep 03 09:21:16 rivoplus volumio[3477]: syscall: 'connect', Sep 03 09:21:16 rivoplus volumio[3477]: address: '151.101.194.79', Sep 03 09:21:16 rivoplus volumio[3477]: port: 443 Sep 03 09:21:16 rivoplus volumio[3477]: } Sep 03 09:21:16 rivoplus volumio[3477]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 03 09:21:17 rivoplus ntpd[8365]: Soliciting pool server 103.70.115.65 Sep 03 09:21:17 rivoplus sudo[8995]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-03 09:20 Sep 03 09:21:17 rivoplus sudo[8995]: 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="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 11:23:19 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="ca35d8983c8e34dfa9cca80071cf9105"