-- Logs begin at Thu 2025-04-24 02:46:54 CEST, end at Thu 2025-04-24 03:03:36 CEST. -- Apr 24 03:02:04 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 24 03:02:04 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 24 03:02:04 rivoplus volumio[20010]: info: Discovery: Getting this device information Apr 24 03:02:04 rivoplus volumio[20010]: info: CoreCommandRouter::volumioGetState Apr 24 03:02:04 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 24 03:02:04 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Apr 24 03:02:04 rivoplus volumio[20010]: info: handleBrowseUri took 443 milliseconds Apr 24 03:02:05 rivoplus volumio[20010]: info: Preload queue cleared Apr 24 03:02:05 rivoplus volumio[20010]: info: Preloading song: qobuz://song/3200821 Apr 24 03:02:05 rivoplus volumio[20010]: info: Preloading song: qobuz://song/3200822 Apr 24 03:02:05 rivoplus volumio[20010]: info: Preloading song: qobuz://song/3200823 Apr 24 03:02:05 rivoplus volumio[20010]: info: Preloading song: qobuz://song/3200824 Apr 24 03:02:05 rivoplus volumio[20010]: info: Preloading song: qobuz://song/3200825 Apr 24 03:02:05 rivoplus volumio[20010]: info: Preloading song: qobuz://song/3200826 Apr 24 03:02:05 rivoplus volumio[20010]: info: Preloading song: qobuz://song/3200827 Apr 24 03:02:05 rivoplus volumio[20010]: info: Preloading song: qobuz://song/3200828 Apr 24 03:02:05 rivoplus volumio[20010]: info: Exploding uri qobuz://song/3200821 in service qobuz Apr 24 03:02:05 rivoplus volumio[20010]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 24 03:02:05 rivoplus volumio[20010]: info: Exploding uri qobuz://song/3200822 in service qobuz Apr 24 03:02:05 rivoplus volumio[20010]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 24 03:02:05 rivoplus volumio[20010]: info: Exploding uri qobuz://song/3200823 in service qobuz Apr 24 03:02:05 rivoplus volumio[20010]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 24 03:02:05 rivoplus volumio[20010]: info: Exploding uri qobuz://song/3200824 in service qobuz Apr 24 03:02:05 rivoplus volumio[20010]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 24 03:02:05 rivoplus volumio[20010]: info: Exploding uri qobuz://song/3200825 in service qobuz Apr 24 03:02:05 rivoplus volumio[20010]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 24 03:02:05 rivoplus volumio[20010]: info: Exploding uri qobuz://song/3200826 in service qobuz Apr 24 03:02:05 rivoplus volumio[20010]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 24 03:02:05 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:05 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:05 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:05 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:05 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:05 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:05 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:05 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:05 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:05 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:05 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:05 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:05 rivoplus volumio[20010]: info: Exploding uri qobuz://song/3200827 in service qobuz Apr 24 03:02:05 rivoplus volumio[20010]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 24 03:02:05 rivoplus volumio[20010]: info: Exploding uri qobuz://song/3200828 in service qobuz Apr 24 03:02:05 rivoplus volumio[20010]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 24 03:02:05 rivoplus volumio[20010]: info: explodeUri took 461 milliseconds Apr 24 03:02:05 rivoplus volumio[20010]: info: explodeUri took 433 milliseconds Apr 24 03:02:05 rivoplus volumio[20010]: info: explodeUri took 489 milliseconds Apr 24 03:02:05 rivoplus volumio[20010]: info: explodeUri took 454 milliseconds Apr 24 03:02:05 rivoplus volumio[20010]: info: explodeUri took 470 milliseconds Apr 24 03:02:05 rivoplus volumio[20010]: info: explodeUri took 438 milliseconds Apr 24 03:02:05 rivoplus volumio[20010]: info: explodeUri took 526 milliseconds Apr 24 03:02:05 rivoplus volumio[20010]: info: explodeUri took 450 milliseconds Apr 24 03:02:07 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:07 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:07 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:07 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:07 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:07 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:07 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:07 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:07 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:07 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:07 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:07 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:07 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:07 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:07 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:07 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:07 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:07 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:07 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:07 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:07 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:07 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:08 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:08 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:08 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:08 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:08 rivoplus volumio[20010]: error: Failed request for metavolumio API Apr 24 03:02:09 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:09 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:09 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:09 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:09 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:09 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:10 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:10 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:10 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:10 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:11 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:11 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:20 rivoplus volumio[20010]: info: Preload queue cleared Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::ClearQueue Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::stop Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::stPlaybackTimer Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::updateTrackBlock Apr 24 03:02:20 rivoplus volumio[20010]: info: CorePlayQueue::getTrackBlock Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:20 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 4 Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:20 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:20 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::serviceStop Apr 24 03:02:20 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 4 Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreCommandRouter::serviceStop Apr 24 03:02:20 rivoplus volumio[20010]: info: [1745456540430] ControllerQobuz::stop Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 24 03:02:20 rivoplus volumio[20010]: info: ControllerMpd::stop Apr 24 03:02:20 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand stop Apr 24 03:02:20 rivoplus volumio[20010]: info: CorePlayQueue::clearPlayQueue Apr 24 03:02:20 rivoplus volumio[20010]: info: CorePlayQueue::saveQueue Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushQueue Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::addQueueItems Apr 24 03:02:20 rivoplus volumio[20010]: info: CorePlayQueue::addQueueItems Apr 24 03:02:20 rivoplus volumio[20010]: info: Preload queue cleared Apr 24 03:02:20 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/3200821 Apr 24 03:02:20 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/3200821 Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushQueue Apr 24 03:02:20 rivoplus volumio[20010]: info: CorePlayQueue::saveQueue Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::updateTrackBlock Apr 24 03:02:20 rivoplus volumio[20010]: info: CorePlayQueue::getTrackBlock Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPlay Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::play index 0 Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::addQueueItems Apr 24 03:02:20 rivoplus volumio[20010]: info: CorePlayQueue::addQueueItems Apr 24 03:02:20 rivoplus volumio[20010]: info: Preload queue cleared Apr 24 03:02:20 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/3200822 Apr 24 03:02:20 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/3200822 Apr 24 03:02:20 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/3200823 Apr 24 03:02:20 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/3200823 Apr 24 03:02:20 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/3200824 Apr 24 03:02:20 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/3200824 Apr 24 03:02:20 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/3200825 Apr 24 03:02:20 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/3200825 Apr 24 03:02:20 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/3200826 Apr 24 03:02:20 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/3200826 Apr 24 03:02:20 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/3200827 Apr 24 03:02:20 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/3200827 Apr 24 03:02:20 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/3200828 Apr 24 03:02:20 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/3200828 Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::stop Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushQueue Apr 24 03:02:20 rivoplus volumio[20010]: info: CorePlayQueue::saveQueue Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::play index undefined Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::updateTrackBlock Apr 24 03:02:20 rivoplus volumio[20010]: info: CorePlayQueue::getTrackBlock Apr 24 03:02:20 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 0 Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreStateMachine::startPlaybackTimer Apr 24 03:02:20 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 0 Apr 24 03:02:20 rivoplus volumio[20010]: info: [1745456540504] ControllerQobuz::clearAddPlayTrack Apr 24 03:02:20 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand stop Apr 24 03:02:20 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:20 rivoplus volumio[20010]: info: Apr 24 03:02:20 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:02:20 rivoplus volumio[20010]: info: sendMpdCommand stop took 103 milliseconds Apr 24 03:02:20 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:02:20 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:02:20 rivoplus volumio[20010]: info: sendMpdCommand stop took 29 milliseconds Apr 24 03:02:20 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand clear Apr 24 03:02:20 rivoplus volumio[20010]: info: Apr 24 03:02:20 rivoplus volumio[20010]: ---------------------------- MPD announces system playlist update Apr 24 03:02:20 rivoplus volumio[20010]: info: Ignoring MPD Status Update Apr 24 03:02:20 rivoplus volumio[20010]: info: sendMpdCommand status took 6 milliseconds Apr 24 03:02:20 rivoplus volumio[20010]: info: sendMpdCommand clear took 6 milliseconds Apr 24 03:02:20 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:02:20 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 24 03:02:20 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/3200821" Apr 24 03:02:20 rivoplus volumio[20010]: info: Apr 24 03:02:20 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:02:20 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:02:20 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:02:20 rivoplus volumio[20010]: STREAMING PROXY: Handling url /?data=qobuz://song/3200821 Apr 24 03:02:20 rivoplus volumio[20010]: info: Apr 24 03:02:20 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:02:20 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:02:20 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:02:20 rivoplus volumio[20010]: error: updateQueue error: null Apr 24 03:02:20 rivoplus volumio[20010]: info: ------------------------------ 14ms Apr 24 03:02:20 rivoplus volumio[20010]: info: sendMpdCommand playlistinfo took 10 milliseconds Apr 24 03:02:20 rivoplus volumio[20010]: verbose: ControllerMpd::parseTrackInfo Apr 24 03:02:20 rivoplus volumio[20010]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 24 03:02:20 rivoplus volumio[20010]: info: ------------------------------ 27ms Apr 24 03:02:20 rivoplus volumio[20010]: info: Executing endpoint getStreamUrlqobuz Apr 24 03:02:20 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 24 03:02:20 rivoplus volumio[20010]: info: MCU Signalled Playback Inactive Apr 24 03:02:21 rivoplus volumio[20010]: info: getStreamUrl took 426 milliseconds Apr 24 03:02:21 rivoplus volumio[20010]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3019079&eid=3200821&fmt=6&profile=raw&app_id=539451548&cid=2699454&etsp=1745460140&hmac=SUoQHRckuPnNxzloudvpABHVefw Apr 24 03:02:21 rivoplus volumio[20010]: STREAMING PROXY: Response: 200, length: 25338313 Apr 24 03:02:21 rivoplus volumio[20010]: STREAMING PROXY: Client dropped request, destroying Apr 24 03:02:21 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/3200821" Apr 24 03:02:21 rivoplus volumio[20010]: info: Apr 24 03:02:21 rivoplus volumio[20010]: ---------------------------- MPD announces system playlist update Apr 24 03:02:21 rivoplus volumio[20010]: info: Ignoring MPD Status Update Apr 24 03:02:21 rivoplus volumio[20010]: info: Apr 24 03:02:21 rivoplus volumio[20010]: ---------------------------- MPD announces system playlist update Apr 24 03:02:21 rivoplus volumio[20010]: info: Ignoring MPD Status Update Apr 24 03:02:21 rivoplus volumio[20010]: info: Apr 24 03:02:21 rivoplus volumio[20010]: ---------------------------- MPD announces system playlist update Apr 24 03:02:21 rivoplus volumio[20010]: info: Ignoring MPD Status Update Apr 24 03:02:21 rivoplus volumio[20010]: info: sendMpdCommand status took 1055 milliseconds Apr 24 03:02:21 rivoplus volumio[20010]: info: sendMpdCommand status took 1054 milliseconds Apr 24 03:02:21 rivoplus volumio[20010]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/3200821" took 12 milliseconds Apr 24 03:02:21 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:02:21 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 24 03:02:21 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand play Apr 24 03:02:21 rivoplus volumio[20010]: info: ControllerMpd::pushState Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreCommandRouter::servicePushState Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:21 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:21 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:21 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 0 Apr 24 03:02:21 rivoplus volumio[20010]: 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} Apr 24 03:02:21 rivoplus volumio[20010]: verbose: CURRENT POSITION 0 Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreStateMachine::syncState stateService stop Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreStateMachine::syncState currentStatus stop Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:21 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:21 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:21 rivoplus volumio[20010]: info: No code Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:21 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:21 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:21 rivoplus volumio[20010]: info: ControllerMpd::pushState Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreCommandRouter::servicePushState Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:21 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:21 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:21 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 0 Apr 24 03:02:21 rivoplus volumio[20010]: 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} Apr 24 03:02:21 rivoplus volumio[20010]: verbose: CURRENT POSITION 0 Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreStateMachine::syncState stateService stop Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreStateMachine::syncState currentStatus stop Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:21 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:21 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:21 rivoplus volumio[20010]: info: No code Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:21 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:21 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:21 rivoplus volumio[20010]: STREAMING PROXY: Handling url /?data=qobuz://song/3200821 Apr 24 03:02:21 rivoplus volumio[20010]: info: ------------------------------ 1170ms Apr 24 03:02:21 rivoplus volumio[20010]: info: ------------------------------ 1170ms Apr 24 03:02:21 rivoplus volumio[20010]: info: Apr 24 03:02:21 rivoplus volumio[20010]: ---------------------------- MPD announces system playlist update Apr 24 03:02:21 rivoplus volumio[20010]: info: Ignoring MPD Status Update Apr 24 03:02:21 rivoplus volumio[20010]: info: Apr 24 03:02:21 rivoplus volumio[20010]: ---------------------------- MPD announces system playlist update Apr 24 03:02:21 rivoplus volumio[20010]: info: Ignoring MPD Status Update Apr 24 03:02:21 rivoplus volumio[20010]: info: ------------------------------ 131ms Apr 24 03:02:21 rivoplus volumio[20010]: info: ------------------------------ 130ms Apr 24 03:02:21 rivoplus volumio[20010]: info: ------------------------------ 129ms Apr 24 03:02:21 rivoplus volumio[20010]: info: sendMpdCommand play took 117 milliseconds Apr 24 03:02:21 rivoplus volumio[20010]: info: ------------------------------ 6ms Apr 24 03:02:21 rivoplus volumio[20010]: info: ------------------------------ 4ms Apr 24 03:02:21 rivoplus volumio[20010]: info: Signalling Playback active due to playback status change Apr 24 03:02:21 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:21 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:21 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:21 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:21 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:21 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:21 rivoplus volumio[20010]: info: Executing endpoint getStreamUrlqobuz Apr 24 03:02:21 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 24 03:02:21 rivoplus volumio[20010]: info: MCU Signalled Playback Active Apr 24 03:02:22 rivoplus volumio[20010]: info: getStreamUrl took 380 milliseconds Apr 24 03:02:22 rivoplus volumio[20010]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3019079&eid=3200821&fmt=6&profile=raw&app_id=539451548&cid=2699454&etsp=1745460142&hmac=0X5lD_VS0oJvNNsIXWMrZ92QG6Y Apr 24 03:02:22 rivoplus volumio[20010]: STREAMING PROXY: Response: 200, length: 25338313 Apr 24 03:02:22 rivoplus volumio[20010]: info: Apr 24 03:02:22 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:02:22 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:02:22 rivoplus volumio[20010]: info: Apr 24 03:02:22 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:02:22 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:02:22 rivoplus volumio[20010]: info: Apr 24 03:02:22 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:02:22 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:02:22 rivoplus volumio[20010]: info: Apr 24 03:02:22 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:02:22 rivoplus volumio[20010]: info: sendMpdCommand status took 26 milliseconds Apr 24 03:02:22 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 24 03:02:22 rivoplus volumio[20010]: info: sendMpdCommand status took 27 milliseconds Apr 24 03:02:22 rivoplus volumio[20010]: info: sendMpdCommand status took 24 milliseconds Apr 24 03:02:22 rivoplus volumio[20010]: info: sendMpdCommand status took 4 milliseconds Apr 24 03:02:22 rivoplus volumio[20010]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::parseTrackInfo Apr 24 03:02:22 rivoplus volumio[20010]: info: ControllerMpd::pushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::servicePushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 0 Apr 24 03:02:22 rivoplus volumio[20010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":252,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"524 Kbps","isStreaming":false,"title":"3200821","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/3200821","trackType":"qobuz"} Apr 24 03:02:22 rivoplus volumio[20010]: verbose: CURRENT POSITION 0 Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::syncState stateService play Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::syncState currentStatus stop Apr 24 03:02:22 rivoplus volumio[20010]: info: ------------------------------ 44ms Apr 24 03:02:22 rivoplus volumio[20010]: info: Apr 24 03:02:22 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:02:22 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:02:22 rivoplus volumio[20010]: info: Apr 24 03:02:22 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:02:22 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:02:22 rivoplus volumio[20010]: info: sendMpdCommand playlistinfo took 22 milliseconds Apr 24 03:02:22 rivoplus volumio[20010]: info: sendMpdCommand playlistinfo took 21 milliseconds Apr 24 03:02:22 rivoplus volumio[20010]: info: sendMpdCommand status took 11 milliseconds Apr 24 03:02:22 rivoplus volumio[20010]: info: sendMpdCommand status took 8 milliseconds Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::parseTrackInfo Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 24 03:02:22 rivoplus volumio[20010]: info: ControllerMpd::pushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::servicePushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 0 Apr 24 03:02:22 rivoplus volumio[20010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":457,"duration":252,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"764 Kbps","isStreaming":false,"title":"3200821","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/3200821","trackType":"qobuz"} Apr 24 03:02:22 rivoplus volumio[20010]: verbose: CURRENT POSITION 0 Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::syncState stateService play Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::syncState currentStatus play Apr 24 03:02:22 rivoplus volumio[20010]: info: Received an update from plugin. extracting info from payload Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:22 rivoplus volumio[20010]: info: ControllerMpd::pushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::servicePushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 0 Apr 24 03:02:22 rivoplus volumio[20010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":709,"duration":252,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"764 Kbps","isStreaming":false,"title":"3200821","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/3200821","trackType":"qobuz"} Apr 24 03:02:22 rivoplus volumio[20010]: verbose: CURRENT POSITION 0 Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::syncState stateService play Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::syncState currentStatus play Apr 24 03:02:22 rivoplus volumio[20010]: info: Received an update from plugin. extracting info from payload Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:22 rivoplus volumio[20010]: info: ControllerMpd::pushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::servicePushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 0 Apr 24 03:02:22 rivoplus volumio[20010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":252,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"764 Kbps","isStreaming":false,"title":"3200821","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/3200821","trackType":"qobuz"} Apr 24 03:02:22 rivoplus volumio[20010]: verbose: CURRENT POSITION 0 Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::syncState stateService play Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::syncState currentStatus play Apr 24 03:02:22 rivoplus volumio[20010]: info: Received an update from plugin. extracting info from payload Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:22 rivoplus volumio[20010]: info: ------------------------------ 200ms Apr 24 03:02:22 rivoplus volumio[20010]: info: ------------------------------ 198ms Apr 24 03:02:22 rivoplus volumio[20010]: info: ------------------------------ 179ms Apr 24 03:02:22 rivoplus volumio[20010]: info: sendMpdCommand playlistinfo took 150 milliseconds Apr 24 03:02:22 rivoplus volumio[20010]: info: sendMpdCommand playlistinfo took 151 milliseconds Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::parseTrackInfo Apr 24 03:02:22 rivoplus volumio[20010]: verbose: ControllerMpd::parseTrackInfo Apr 24 03:02:22 rivoplus volumio[20010]: info: ControllerMpd::pushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::servicePushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 0 Apr 24 03:02:22 rivoplus volumio[20010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":252,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"709 Kbps","isStreaming":false,"title":"3200821","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/3200821","trackType":"qobuz"} Apr 24 03:02:22 rivoplus volumio[20010]: verbose: CURRENT POSITION 0 Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::syncState stateService play Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::syncState currentStatus play Apr 24 03:02:22 rivoplus volumio[20010]: info: Received an update from plugin. extracting info from payload Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:22 rivoplus volumio[20010]: info: ControllerMpd::pushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::servicePushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 0 Apr 24 03:02:22 rivoplus volumio[20010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":252,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"709 Kbps","isStreaming":false,"title":"3200821","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/3200821","trackType":"qobuz"} Apr 24 03:02:22 rivoplus volumio[20010]: verbose: CURRENT POSITION 0 Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::syncState stateService play Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::syncState currentStatus play Apr 24 03:02:22 rivoplus volumio[20010]: info: Received an update from plugin. extracting info from payload Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:02:22 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:02:22 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:02:22 rivoplus volumio[20010]: info: ------------------------------ 248ms Apr 24 03:02:22 rivoplus volumio[20010]: info: ------------------------------ 245ms Apr 24 03:02:22 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:22 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:22 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:22 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:22 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:22 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:22 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:22 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:22 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:22 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:02:23 rivoplus volumio[20010]: STREAMING PROXY: Client dropped request, destroying Apr 24 03:02:25 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:25 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:25 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:25 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:25 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:25 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:34 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 24 03:02:34 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 24 03:02:34 rivoplus volumio[20010]: info: Discovery: Getting this device information Apr 24 03:02:34 rivoplus volumio[20010]: info: CoreCommandRouter::volumioGetState Apr 24 03:02:34 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 24 03:02:38 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Apr 24 03:02:38 rivoplus volumio[20010]: info: handleBrowseUri took 558 milliseconds Apr 24 03:02:38 rivoplus volumio[20010]: info: Preload queue cleared Apr 24 03:02:38 rivoplus volumio[20010]: info: Preloading song: qobuz://song/60730149 Apr 24 03:02:38 rivoplus volumio[20010]: info: Exploding uri qobuz://song/60730149 in service qobuz Apr 24 03:02:38 rivoplus volumio[20010]: https://prod.vlmapi.io/v2/qobuz/explodeUri Apr 24 03:02:39 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:39 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:39 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:39 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:39 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:39 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:39 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:39 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:39 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:39 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:39 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:39 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:39 rivoplus volumio[20010]: info: explodeUri took 438 milliseconds Apr 24 03:02:40 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:40 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:40 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:40 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:40 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:40 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:40 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:40 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:40 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:40 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:40 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:40 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:40 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:02:40 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:02:40 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:40 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:41 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:41 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:41 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:41 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:42 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:42 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:42 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:42 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:43 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:43 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:43 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:43 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:44 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:44 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:44 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:44 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:44 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:44 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:44 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:44 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:02:45 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:02:45 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:04 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 24 03:03:04 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 24 03:03:04 rivoplus volumio[20010]: info: Discovery: Getting this device information Apr 24 03:03:04 rivoplus volumio[20010]: info: CoreCommandRouter::volumioGetState Apr 24 03:03:04 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 24 03:03:11 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Apr 24 03:03:12 rivoplus volumio[20010]: info: handleBrowseUri took 391 milliseconds Apr 24 03:03:12 rivoplus volumio[20010]: info: Preload queue cleared Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:12 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:27 rivoplus volumio[20010]: info: Preload queue cleared Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::ClearQueue Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::stop Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::stPlaybackTimer Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::updateTrackBlock Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::getTrackBlock Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 0 Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:03:27 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:03:27 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::serviceStop Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 0 Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreCommandRouter::serviceStop Apr 24 03:03:27 rivoplus volumio[20010]: info: [1745456607222] ControllerQobuz::stop Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 24 03:03:27 rivoplus volumio[20010]: info: ControllerMpd::stop Apr 24 03:03:27 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand stop Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::clearPlayQueue Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::saveQueue Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushQueue Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::addQueueItems Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::addQueueItems Apr 24 03:03:27 rivoplus volumio[20010]: info: Preload queue cleared Apr 24 03:03:27 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/2015665 Apr 24 03:03:27 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/2015665 Apr 24 03:03:27 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/2015666 Apr 24 03:03:27 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/2015666 Apr 24 03:03:27 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/2015667 Apr 24 03:03:27 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/2015667 Apr 24 03:03:27 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/2015668 Apr 24 03:03:27 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/2015668 Apr 24 03:03:27 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/2015669 Apr 24 03:03:27 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/2015669 Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushQueue Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::saveQueue Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::updateTrackBlock Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::getTrackBlock Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPlay Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::play index 4 Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::addQueueItems Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::addQueueItems Apr 24 03:03:27 rivoplus volumio[20010]: info: Preload queue cleared Apr 24 03:03:27 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/2015670 Apr 24 03:03:27 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/2015670 Apr 24 03:03:27 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/2015671 Apr 24 03:03:27 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/2015671 Apr 24 03:03:27 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/2015672 Apr 24 03:03:27 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/2015672 Apr 24 03:03:27 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/2015673 Apr 24 03:03:27 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/2015673 Apr 24 03:03:27 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/2015674 Apr 24 03:03:27 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/2015674 Apr 24 03:03:27 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/2015675 Apr 24 03:03:27 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/2015675 Apr 24 03:03:27 rivoplus volumio[20010]: info: Adding Item to queue: qobuz://song/2015676 Apr 24 03:03:27 rivoplus volumio[20010]: info: Using cached record of: qobuz://song/2015676 Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::stop Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushQueue Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::saveQueue Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::play index undefined Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::updateTrackBlock Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::getTrackBlock Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 4 Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::startPlaybackTimer Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 4 Apr 24 03:03:27 rivoplus volumio[20010]: info: [1745456607265] ControllerQobuz::clearAddPlayTrack Apr 24 03:03:27 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand stop Apr 24 03:03:27 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:03:27 rivoplus volumio[20010]: info: Apr 24 03:03:27 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:03:27 rivoplus volumio[20010]: info: sendMpdCommand stop took 75 milliseconds Apr 24 03:03:27 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:03:27 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:03:27 rivoplus volumio[20010]: info: sendMpdCommand stop took 31 milliseconds Apr 24 03:03:27 rivoplus volumio[20010]: info: sendMpdCommand status took 2 milliseconds Apr 24 03:03:27 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand clear Apr 24 03:03:27 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:03:27 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 24 03:03:27 rivoplus volumio[20010]: info: Apr 24 03:03:27 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:03:27 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:03:27 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:03:27 rivoplus volumio[20010]: info: Apr 24 03:03:27 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:03:27 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:03:27 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:03:27 rivoplus volumio[20010]: info: Apr 24 03:03:27 rivoplus volumio[20010]: ---------------------------- MPD announces system playlist update Apr 24 03:03:27 rivoplus volumio[20010]: info: Ignoring MPD Status Update Apr 24 03:03:27 rivoplus volumio[20010]: info: sendMpdCommand clear took 7 milliseconds Apr 24 03:03:27 rivoplus volumio[20010]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 24 03:03:27 rivoplus volumio[20010]: info: sendMpdCommand status took 5 milliseconds Apr 24 03:03:27 rivoplus volumio[20010]: info: sendMpdCommand status took 4 milliseconds Apr 24 03:03:27 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/2015669" Apr 24 03:03:27 rivoplus volumio[20010]: verbose: ControllerMpd::parseTrackInfo Apr 24 03:03:27 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:03:27 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:03:27 rivoplus volumio[20010]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 24 03:03:27 rivoplus volumio[20010]: info: ControllerMpd::pushState Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreCommandRouter::servicePushState Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 4 Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:03:27 rivoplus volumio[20010]: STREAMING PROXY: Handling url /?data=qobuz://song/2015669 Apr 24 03:03:27 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:03:27 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 4 Apr 24 03:03:27 rivoplus volumio[20010]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Apr 24 03:03:27 rivoplus volumio[20010]: info: ControllerMpd::pushState Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreCommandRouter::servicePushState Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 4 Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:03:27 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:03:27 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:03:27 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 4 Apr 24 03:03:27 rivoplus volumio[20010]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Apr 24 03:03:27 rivoplus volumio[20010]: info: ------------------------------ 32ms Apr 24 03:03:27 rivoplus volumio[20010]: info: ------------------------------ 37ms Apr 24 03:03:27 rivoplus volumio[20010]: info: ------------------------------ 36ms Apr 24 03:03:27 rivoplus volumio[20010]: info: Apr 24 03:03:27 rivoplus volumio[20010]: ---------------------------- MPD announces system playlist update Apr 24 03:03:27 rivoplus volumio[20010]: info: Ignoring MPD Status Update Apr 24 03:03:27 rivoplus volumio[20010]: info: Apr 24 03:03:27 rivoplus volumio[20010]: ---------------------------- MPD announces system playlist update Apr 24 03:03:27 rivoplus volumio[20010]: info: Ignoring MPD Status Update Apr 24 03:03:27 rivoplus volumio[20010]: error: updateQueue error: null Apr 24 03:03:27 rivoplus volumio[20010]: info: ------------------------------ 44ms Apr 24 03:03:27 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:03:27 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:03:27 rivoplus volumio[20010]: info: MCU Signalled Playback Inactive Apr 24 03:03:27 rivoplus volumio[20010]: info: Executing endpoint getStreamUrlqobuz Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 24 03:03:27 rivoplus volumio[20010]: info: getStreamUrl took 402 milliseconds Apr 24 03:03:27 rivoplus volumio[20010]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3019079&eid=2015669&fmt=6&profile=raw&app_id=539451548&cid=2699454&etsp=1745460207&hmac=FJHs9VGjDvd1pH8KYke0NTaT8v4 Apr 24 03:03:27 rivoplus volumio[20010]: STREAMING PROXY: Response: 200, length: 24253241 Apr 24 03:03:27 rivoplus volumio[20010]: STREAMING PROXY: Client dropped request, destroying Apr 24 03:03:27 rivoplus volumio[20010]: error: updateQueue error: null Apr 24 03:03:27 rivoplus volumio[20010]: error: updateQueue error: null Apr 24 03:03:27 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/2015669" Apr 24 03:03:27 rivoplus volumio[20010]: info: ------------------------------ 617ms Apr 24 03:03:27 rivoplus volumio[20010]: info: ------------------------------ 617ms Apr 24 03:03:27 rivoplus volumio[20010]: info: Apr 24 03:03:27 rivoplus volumio[20010]: ---------------------------- MPD announces system playlist update Apr 24 03:03:27 rivoplus volumio[20010]: info: Ignoring MPD Status Update Apr 24 03:03:27 rivoplus volumio[20010]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/2015669" took 3 milliseconds Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 24 03:03:27 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand play Apr 24 03:03:27 rivoplus volumio[20010]: info: Apr 24 03:03:27 rivoplus volumio[20010]: ---------------------------- MPD announces system playlist update Apr 24 03:03:27 rivoplus volumio[20010]: info: Ignoring MPD Status Update Apr 24 03:03:27 rivoplus volumio[20010]: info: Apr 24 03:03:27 rivoplus volumio[20010]: ---------------------------- MPD announces system playlist update Apr 24 03:03:27 rivoplus volumio[20010]: info: Ignoring MPD Status Update Apr 24 03:03:27 rivoplus volumio[20010]: info: ------------------------------ 8ms Apr 24 03:03:27 rivoplus volumio[20010]: info: sendMpdCommand play took 7 milliseconds Apr 24 03:03:27 rivoplus volumio[20010]: STREAMING PROXY: Handling url /?data=qobuz://song/2015669 Apr 24 03:03:27 rivoplus volumio[20010]: info: ------------------------------ 7ms Apr 24 03:03:27 rivoplus volumio[20010]: info: ------------------------------ 7ms Apr 24 03:03:27 rivoplus volumio[20010]: info: Executing endpoint getStreamUrlqobuz Apr 24 03:03:27 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 24 03:03:28 rivoplus volumio[20010]: info: getStreamUrl took 602 milliseconds Apr 24 03:03:28 rivoplus volumio[20010]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3019079&eid=2015669&fmt=6&profile=raw&app_id=539451548&cid=2699454&etsp=1745460208&hmac=NF8r4Flk5majzUnmISuKdCO2nDY Apr 24 03:03:28 rivoplus volumio[20010]: STREAMING PROXY: Response: 200, length: 24253241 Apr 24 03:03:28 rivoplus volumio[20010]: info: Apr 24 03:03:28 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:03:28 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:03:28 rivoplus volumio[20010]: info: Apr 24 03:03:28 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:03:28 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:03:28 rivoplus volumio[20010]: info: Apr 24 03:03:28 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:03:28 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:03:28 rivoplus volumio[20010]: info: Apr 24 03:03:28 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:03:28 rivoplus volumio[20010]: info: sendMpdCommand status took 24 milliseconds Apr 24 03:03:28 rivoplus volumio[20010]: info: sendMpdCommand status took 24 milliseconds Apr 24 03:03:28 rivoplus volumio[20010]: info: sendMpdCommand status took 23 milliseconds Apr 24 03:03:28 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 24 03:03:28 rivoplus volumio[20010]: info: Apr 24 03:03:28 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:03:28 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:03:28 rivoplus volumio[20010]: info: Apr 24 03:03:28 rivoplus volumio[20010]: ---------------------------- MPD announces state update: player Apr 24 03:03:28 rivoplus volumio[20010]: info: ControllerMpd::getState Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand status Apr 24 03:03:28 rivoplus volumio[20010]: info: sendMpdCommand status took 24 milliseconds Apr 24 03:03:28 rivoplus volumio[20010]: info: sendMpdCommand playlistinfo took 22 milliseconds Apr 24 03:03:28 rivoplus volumio[20010]: info: sendMpdCommand playlistinfo took 19 milliseconds Apr 24 03:03:28 rivoplus volumio[20010]: info: sendMpdCommand playlistinfo took 18 milliseconds Apr 24 03:03:28 rivoplus volumio[20010]: info: sendMpdCommand status took 9 milliseconds Apr 24 03:03:28 rivoplus volumio[20010]: info: sendMpdCommand status took 7 milliseconds Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::parseTrackInfo Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::parseState Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 24 03:03:28 rivoplus volumio[20010]: info: ControllerMpd::pushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreCommandRouter::servicePushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 4 Apr 24 03:03:28 rivoplus volumio[20010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":296,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2015669","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/2015669","trackType":"qobuz"} Apr 24 03:03:28 rivoplus volumio[20010]: verbose: CURRENT POSITION 4 Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::syncState stateService play Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::syncState currentStatus stop Apr 24 03:03:28 rivoplus volumio[20010]: info: ControllerMpd::pushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreCommandRouter::servicePushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 4 Apr 24 03:03:28 rivoplus volumio[20010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1006,"duration":296,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"459 Kbps","isStreaming":false,"title":"2015669","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/2015669","trackType":"qobuz"} Apr 24 03:03:28 rivoplus volumio[20010]: verbose: CURRENT POSITION 4 Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::syncState stateService play Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::syncState currentStatus play Apr 24 03:03:28 rivoplus volumio[20010]: info: Received an update from plugin. extracting info from payload Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:03:28 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:03:28 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:03:28 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:03:28 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:03:28 rivoplus volumio[20010]: info: ControllerMpd::pushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreCommandRouter::servicePushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 4 Apr 24 03:03:28 rivoplus volumio[20010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1052,"duration":296,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"468 Kbps","isStreaming":false,"title":"2015669","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/2015669","trackType":"qobuz"} Apr 24 03:03:28 rivoplus volumio[20010]: verbose: CURRENT POSITION 4 Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::syncState stateService play Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::syncState currentStatus play Apr 24 03:03:28 rivoplus volumio[20010]: info: Received an update from plugin. extracting info from payload Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:03:28 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:03:28 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:03:28 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:03:28 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:03:28 rivoplus volumio[20010]: info: ------------------------------ 121ms Apr 24 03:03:28 rivoplus volumio[20010]: info: ------------------------------ 178ms Apr 24 03:03:28 rivoplus volumio[20010]: info: ------------------------------ 179ms Apr 24 03:03:28 rivoplus volumio[20010]: info: sendMpdCommand playlistinfo took 115 milliseconds Apr 24 03:03:28 rivoplus volumio[20010]: info: sendMpdCommand playlistinfo took 113 milliseconds Apr 24 03:03:28 rivoplus volumio[20010]: info: sendMpdCommand playlistinfo took 113 milliseconds Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::parseTrackInfo Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::parseTrackInfo Apr 24 03:03:28 rivoplus volumio[20010]: verbose: ControllerMpd::parseTrackInfo Apr 24 03:03:28 rivoplus volumio[20010]: info: ControllerMpd::pushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreCommandRouter::servicePushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 4 Apr 24 03:03:28 rivoplus volumio[20010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":296,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"470 Kbps","isStreaming":false,"title":"2015669","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/2015669","trackType":"qobuz"} Apr 24 03:03:28 rivoplus volumio[20010]: verbose: CURRENT POSITION 4 Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::syncState stateService play Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::syncState currentStatus play Apr 24 03:03:28 rivoplus volumio[20010]: info: Received an update from plugin. extracting info from payload Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:03:28 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:03:28 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:03:28 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:03:28 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:03:28 rivoplus volumio[20010]: info: ControllerMpd::pushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreCommandRouter::servicePushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 4 Apr 24 03:03:28 rivoplus volumio[20010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":296,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"470 Kbps","isStreaming":false,"title":"2015669","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/2015669","trackType":"qobuz"} Apr 24 03:03:28 rivoplus volumio[20010]: verbose: CURRENT POSITION 4 Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::syncState stateService play Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::syncState currentStatus play Apr 24 03:03:28 rivoplus volumio[20010]: info: Received an update from plugin. extracting info from payload Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:03:28 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:03:28 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:03:28 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:03:29 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:03:29 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:03:29 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:03:29 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:03:29 rivoplus volumio[20010]: info: ControllerMpd::pushState Apr 24 03:03:29 rivoplus volumio[20010]: info: CoreCommandRouter::servicePushState Apr 24 03:03:29 rivoplus volumio[20010]: info: CorePlayQueue::getTrack 4 Apr 24 03:03:29 rivoplus volumio[20010]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":296,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"470 Kbps","isStreaming":false,"title":"2015669","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/2015669","trackType":"qobuz"} Apr 24 03:03:29 rivoplus volumio[20010]: verbose: CURRENT POSITION 4 Apr 24 03:03:29 rivoplus volumio[20010]: info: CoreStateMachine::syncState stateService play Apr 24 03:03:29 rivoplus volumio[20010]: info: CoreStateMachine::syncState currentStatus play Apr 24 03:03:29 rivoplus volumio[20010]: info: Received an update from plugin. extracting info from payload Apr 24 03:03:29 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:03:29 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:03:29 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:03:29 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:03:29 rivoplus volumio[20010]: info: CoreStateMachine::pushState Apr 24 03:03:29 rivoplus volumio[20010]: info: CoreCommandRouter::volumioPushState Apr 24 03:03:29 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output update for this device Apr 24 03:03:29 rivoplus volumio[20010]: info: MRS: Pushing multiroomSync output Apr 24 03:03:29 rivoplus volumio[20010]: info: ------------------------------ 294ms Apr 24 03:03:29 rivoplus volumio[20010]: info: ------------------------------ 267ms Apr 24 03:03:29 rivoplus volumio[20010]: info: ------------------------------ 260ms Apr 24 03:03:29 rivoplus volumio[20010]: info: Signalling Playback active due to playback status change Apr 24 03:03:29 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:03:29 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:03:29 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:03:29 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:03:29 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:03:29 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:03:29 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:03:29 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:03:29 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:03:29 rivoplus volumio[20010]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 03:03:29 rivoplus volumio[20010]: info: MCU Signalled Playback Active Apr 24 03:03:30 rivoplus volumio[20010]: STREAMING PROXY: Client dropped request, destroying Apr 24 03:03:30 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 24 03:03:30 rivoplus volumio[20010]: info: Received Get System Info Apr 24 03:03:30 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 24 03:03:30 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 24 03:03:30 rivoplus volumio[20010]: info: Discovery: Getting this device information Apr 24 03:03:30 rivoplus volumio[20010]: info: CoreCommandRouter::volumioGetState Apr 24 03:03:30 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 24 03:03:31 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:31 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:31 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:31 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:31 rivoplus volumio[20010]: info: Executing endpoint metavolumio Apr 24 03:03:31 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 24 03:03:34 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 24 03:03:34 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 24 03:03:34 rivoplus volumio[20010]: info: Discovery: Getting this device information Apr 24 03:03:34 rivoplus volumio[20010]: info: CoreCommandRouter::volumioGetState Apr 24 03:03:34 rivoplus volumio[20010]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 24 03:03:35 rivoplus volumio[20010]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 24 03:03:35 rivoplus volumio[20010]: Error: connect ETIMEDOUT 151.101.134.79:443 Apr 24 03:03:35 rivoplus volumio[20010]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Apr 24 03:03:35 rivoplus volumio[20010]: errno: -110, Apr 24 03:03:35 rivoplus volumio[20010]: code: 'ETIMEDOUT', Apr 24 03:03:35 rivoplus volumio[20010]: syscall: 'connect', Apr 24 03:03:35 rivoplus volumio[20010]: address: '151.101.134.79', Apr 24 03:03:35 rivoplus volumio[20010]: port: 443 Apr 24 03:03:35 rivoplus volumio[20010]: } Apr 24 03:03:35 rivoplus volumio[20010]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 24 03:03:36 rivoplus sudo[28666]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-24 03:02 Apr 24 03:03:36 rivoplus sudo[28666]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 07:42:11 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="4f5519a96ae5ba7dcfda362cc37343d4"