-- Logs begin at Sat 2026-03-28 19:09:22 CET, end at Sat 2026-03-28 19:48:52 CET. -- Mar 28 19:47:02 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:02 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:02 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:02 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:22 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Mar 28 19:47:23 rivoplus volumio[3102]: info: handleBrowseUri took 642 milliseconds Mar 28 19:47:23 rivoplus volumio[3102]: info: Preload queue cleared Mar 28 19:47:23 rivoplus volumio[3102]: info: Preloading song: qobuz://song/348050595 Mar 28 19:47:23 rivoplus volumio[3102]: info: Preloading song: qobuz://song/348050596 Mar 28 19:47:23 rivoplus volumio[3102]: info: Preloading song: qobuz://song/348050597 Mar 28 19:47:23 rivoplus volumio[3102]: info: Preloading song: qobuz://song/348050598 Mar 28 19:47:23 rivoplus volumio[3102]: info: Preloading song: qobuz://song/348050599 Mar 28 19:47:23 rivoplus volumio[3102]: info: Preloading song: qobuz://song/348050600 Mar 28 19:47:23 rivoplus volumio[3102]: info: Preloading song: qobuz://song/348050601 Mar 28 19:47:23 rivoplus volumio[3102]: info: Preloading song: qobuz://song/348050602 Mar 28 19:47:23 rivoplus volumio[3102]: info: Preloading song: qobuz://song/348050603 Mar 28 19:47:23 rivoplus volumio[3102]: info: Preloading song: qobuz://song/348050604 Mar 28 19:47:23 rivoplus volumio[3102]: info: Preloading song: qobuz://song/348050605 Mar 28 19:47:23 rivoplus volumio[3102]: info: Preloading song: qobuz://song/348050606 Mar 28 19:47:23 rivoplus volumio[3102]: info: Exploding uri qobuz://song/348050595 in service qobuz Mar 28 19:47:23 rivoplus volumio[3102]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 28 19:47:23 rivoplus volumio[3102]: info: Exploding uri qobuz://song/348050596 in service qobuz Mar 28 19:47:23 rivoplus volumio[3102]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 28 19:47:23 rivoplus volumio[3102]: info: Exploding uri qobuz://song/348050597 in service qobuz Mar 28 19:47:23 rivoplus volumio[3102]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 28 19:47:23 rivoplus volumio[3102]: info: Executing endpoint getSimilarAlbums Mar 28 19:47:23 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 28 19:47:23 rivoplus volumio[3102]: info: Executing endpoint getSimilarAlbums Mar 28 19:47:23 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 28 19:47:23 rivoplus volumio[3102]: info: Executing endpoint getSimilarAlbums Mar 28 19:47:23 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 28 19:47:23 rivoplus volumio[3102]: info: Executing endpoint getSimilarAlbums Mar 28 19:47:23 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 28 19:47:23 rivoplus volumio[3102]: info: Executing endpoint getSimilarAlbums Mar 28 19:47:23 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 28 19:47:23 rivoplus volumio[3102]: info: Executing endpoint getSimilarAlbums Mar 28 19:47:23 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 28 19:47:23 rivoplus volumio[3102]: info: Exploding uri qobuz://song/348050598 in service qobuz Mar 28 19:47:23 rivoplus volumio[3102]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 28 19:47:23 rivoplus volumio[3102]: info: Exploding uri qobuz://song/348050599 in service qobuz Mar 28 19:47:23 rivoplus volumio[3102]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 28 19:47:23 rivoplus volumio[3102]: info: Exploding uri qobuz://song/348050600 in service qobuz Mar 28 19:47:23 rivoplus volumio[3102]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 28 19:47:23 rivoplus volumio[3102]: info: Exploding uri qobuz://song/348050601 in service qobuz Mar 28 19:47:23 rivoplus volumio[3102]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 28 19:47:23 rivoplus volumio[3102]: info: Exploding uri qobuz://song/348050602 in service qobuz Mar 28 19:47:23 rivoplus volumio[3102]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 28 19:47:23 rivoplus volumio[3102]: info: Exploding uri qobuz://song/348050603 in service qobuz Mar 28 19:47:23 rivoplus volumio[3102]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 28 19:47:23 rivoplus volumio[3102]: info: Exploding uri qobuz://song/348050604 in service qobuz Mar 28 19:47:23 rivoplus volumio[3102]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 28 19:47:23 rivoplus volumio[3102]: info: explodeUri took 456 milliseconds Mar 28 19:47:23 rivoplus volumio[3102]: info: Exploding uri qobuz://song/348050605 in service qobuz Mar 28 19:47:23 rivoplus volumio[3102]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 28 19:47:23 rivoplus volumio[3102]: info: explodeUri took 502 milliseconds Mar 28 19:47:23 rivoplus volumio[3102]: info: Exploding uri qobuz://song/348050606 in service qobuz Mar 28 19:47:23 rivoplus volumio[3102]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 28 19:47:23 rivoplus volumio[3102]: info: explodeUri took 540 milliseconds Mar 28 19:47:23 rivoplus volumio[3102]: info: explodeUri took 499 milliseconds Mar 28 19:47:23 rivoplus volumio[3102]: info: explodeUri took 482 milliseconds Mar 28 19:47:23 rivoplus volumio[3102]: info: explodeUri took 459 milliseconds Mar 28 19:47:24 rivoplus volumio[3102]: info: explodeUri took 529 milliseconds Mar 28 19:47:24 rivoplus volumio[3102]: info: explodeUri took 464 milliseconds Mar 28 19:47:24 rivoplus volumio[3102]: info: explodeUri took 487 milliseconds Mar 28 19:47:24 rivoplus volumio[3102]: info: explodeUri took 598 milliseconds Mar 28 19:47:24 rivoplus volumio[3102]: info: explodeUri took 839 milliseconds Mar 28 19:47:24 rivoplus volumio[3102]: info: explodeUri took 903 milliseconds Mar 28 19:47:25 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:25 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:25 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:25 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:25 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:25 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:25 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:25 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:25 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:25 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:26 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:26 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:26 rivoplus volumio[3102]: info: Preload queue cleared Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreCommandRouter::volumioAddQueueItems Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreStateMachine::addQueueItems Mar 28 19:47:26 rivoplus volumio[3102]: info: CorePlayQueue::addQueueItems Mar 28 19:47:26 rivoplus volumio[3102]: info: Preload queue cleared Mar 28 19:47:26 rivoplus volumio[3102]: info: Adding Item to queue: qobuz://song/348050597 Mar 28 19:47:26 rivoplus volumio[3102]: info: Using cached record of: qobuz://song/348050597 Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushQueue Mar 28 19:47:26 rivoplus volumio[3102]: info: CorePlayQueue::saveQueue Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreStateMachine::updateTrackBlock Mar 28 19:47:26 rivoplus volumio[3102]: info: CorePlayQueue::getTrackBlock Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPlay Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreStateMachine::play index 425 Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreStateMachine::stop Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreStateMachine::stPlaybackTimer Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreStateMachine::updateTrackBlock Mar 28 19:47:26 rivoplus volumio[3102]: info: CorePlayQueue::getTrackBlock Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:47:26 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 424 Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:47:26 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 424 Mar 28 19:47:26 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:47:26 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreStateMachine::serviceStop Mar 28 19:47:26 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 424 Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreCommandRouter::serviceStop Mar 28 19:47:26 rivoplus volumio[3102]: info: [1774723646982] ControllerQobuz::stop Mar 28 19:47:26 rivoplus volumio[3102]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 28 19:47:26 rivoplus volumio[3102]: info: ControllerMpd::stop Mar 28 19:47:26 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 19:47:26 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:26.997+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_STOPPED positionMs=0 volume=100 Mar 28 19:47:26 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:26.998+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/141464791 title="Afoxé pra Oxum" Mar 28 19:47:27 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:47:27 rivoplus volumio[3102]: info: Mar 28 19:47:27 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:47:27 rivoplus volumio[3102]: info: sendMpdCommand stop took 143 milliseconds Mar 28 19:47:27 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:47:27 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:47:27 rivoplus volumio[3102]: info: CoreStateMachine::play index undefined Mar 28 19:47:27 rivoplus volumio[3102]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 19:47:27 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 425 Mar 28 19:47:27 rivoplus volumio[3102]: info: CoreStateMachine::startPlaybackTimer Mar 28 19:47:27 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 425 Mar 28 19:47:27 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetVisibleSources Mar 28 19:47:27 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:47:27 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 28 19:47:27 rivoplus volumio[3102]: info: [1774723647129] ControllerQobuz::clearAddPlayTrack Mar 28 19:47:27 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 19:47:27 rivoplus volumio[3102]: info: Mar 28 19:47:27 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:47:27 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:47:27 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:47:27 rivoplus volumio[3102]: info: Mar 28 19:47:27 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:47:27 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:47:27 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:47:27 rivoplus volumio[3102]: info: sendMpdCommand status took 12 milliseconds Mar 28 19:47:27 rivoplus volumio[3102]: info: sendMpdCommand stop took 8 milliseconds Mar 28 19:47:27 rivoplus volumio[3102]: info: sendMpdCommand status took 7 milliseconds Mar 28 19:47:27 rivoplus volumio[3102]: info: sendMpdCommand status took 5 milliseconds Mar 28 19:47:27 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:47:27 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:47:27 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand clear Mar 28 19:47:27 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:47:27 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:47:27 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:47:27 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:47:27 rivoplus volumio[3102]: info: Mar 28 19:47:27 rivoplus volumio[3102]: ---------------------------- MPD announces system playlist update Mar 28 19:47:27 rivoplus volumio[3102]: info: Ignoring MPD Status Update Mar 28 19:47:27 rivoplus volumio[3102]: info: sendMpdCommand playlistinfo took 6 milliseconds Mar 28 19:47:27 rivoplus volumio[3102]: info: sendMpdCommand clear took 6 milliseconds Mar 28 19:47:27 rivoplus volumio[3102]: info: sendMpdCommand playlistinfo took 5 milliseconds Mar 28 19:47:27 rivoplus volumio[3102]: info: sendMpdCommand playlistinfo took 6 milliseconds Mar 28 19:47:27 rivoplus volumio[3102]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:47:27 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/348050597" Mar 28 19:47:27 rivoplus volumio[3102]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:47:27 rivoplus volumio[3102]: info: ControllerMpd::pushState Mar 28 19:47:27 rivoplus volumio[3102]: info: CoreCommandRouter::servicePushState Mar 28 19:47:27 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:47:27 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 425 Mar 28 19:47:27 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:47:27 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:47:27 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:47:27 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 425 Mar 28 19:47:27 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:47:27 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:47:27 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 425 Mar 28 19:47:27 rivoplus volumio[3102]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Mar 28 19:47:27 rivoplus volumio[3102]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Mar 28 19:47:27 rivoplus volumio[3102]: STREAMING PROXY: Handling url /?data=qobuz://song/348050597 Mar 28 19:47:27 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:27.168+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_STOPPED positionMs=7 volume=100 Mar 28 19:47:27 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:27.168+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/348050597 title="Tenho Sede" Mar 28 19:47:27 rivoplus volumio[3102]: info: ------------------------------ 44ms Mar 28 19:47:27 rivoplus volumio[3102]: info: ------------------------------ 38ms Mar 28 19:47:27 rivoplus volumio[3102]: info: ------------------------------ 36ms Mar 28 19:47:27 rivoplus volumio[3102]: info: Mar 28 19:47:27 rivoplus volumio[3102]: ---------------------------- MPD announces system playlist update Mar 28 19:47:27 rivoplus volumio[3102]: info: Ignoring MPD Status Update Mar 28 19:47:27 rivoplus volumio[3102]: info: Mar 28 19:47:27 rivoplus volumio[3102]: ---------------------------- MPD announces system playlist update Mar 28 19:47:27 rivoplus volumio[3102]: info: Ignoring MPD Status Update Mar 28 19:47:27 rivoplus volumio[3102]: info: MCU Signalled Playback Inactive Mar 28 19:47:27 rivoplus volumio[3102]: error: updateQueue error: null Mar 28 19:47:27 rivoplus volumio[3102]: info: ------------------------------ 35ms Mar 28 19:47:27 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:27 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:27 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:47:27 rivoplus volumio[3102]: info: Executing endpoint getStreamUrlqobuz Mar 28 19:47:27 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Mar 28 19:47:27 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:27 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:27 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:27 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:27 rivoplus volumio[3102]: info: getStreamUrl took 700 milliseconds Mar 28 19:47:27 rivoplus volumio[3102]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=8278633&eid=348050597&fmt=7&profile=raw&app_id=539451548&cid=3333337&etsp=1774727247&hmac=Q3HR0_LilsxJuYAhv0GAtU4r4OU Mar 28 19:47:27 rivoplus volumio[3102]: STREAMING PROXY: Requesting upstream with range: none Mar 28 19:47:28 rivoplus volumio[3102]: STREAMING PROXY: Upstream status code: 200 Mar 28 19:47:28 rivoplus volumio[3102]: STREAMING PROXY: Client closed connection Mar 28 19:47:28 rivoplus volumio[3102]: STREAMING PROXY: Upstream closed. Received 550 bytes Mar 28 19:47:28 rivoplus volumio[3102]: STREAMING PROXY: Incomplete transfer. Expected 84940788, got 550 Mar 28 19:47:28 rivoplus volumio[3102]: STREAMING PROXY: Retrying with range: bytes=550- (attempt 1) Mar 28 19:47:28 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/348050597" Mar 28 19:47:28 rivoplus volumio[3102]: error: updateQueue error: null Mar 28 19:47:28 rivoplus volumio[3102]: error: updateQueue error: null Mar 28 19:47:28 rivoplus volumio[3102]: info: Mar 28 19:47:28 rivoplus volumio[3102]: ---------------------------- MPD announces system playlist update Mar 28 19:47:28 rivoplus volumio[3102]: info: Ignoring MPD Status Update Mar 28 19:47:28 rivoplus volumio[3102]: info: ------------------------------ 1262ms Mar 28 19:47:28 rivoplus volumio[3102]: info: ------------------------------ 1260ms Mar 28 19:47:28 rivoplus volumio[3102]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/348050597" took 5 milliseconds Mar 28 19:47:28 rivoplus volumio[3102]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 28 19:47:28 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand play Mar 28 19:47:28 rivoplus volumio[3102]: STREAMING PROXY: Handling url /?data=qobuz://song/348050597 Mar 28 19:47:28 rivoplus volumio[3102]: info: Mar 28 19:47:28 rivoplus volumio[3102]: ---------------------------- MPD announces system playlist update Mar 28 19:47:28 rivoplus volumio[3102]: info: Ignoring MPD Status Update Mar 28 19:47:28 rivoplus volumio[3102]: info: Mar 28 19:47:28 rivoplus volumio[3102]: ---------------------------- MPD announces system playlist update Mar 28 19:47:28 rivoplus volumio[3102]: info: Ignoring MPD Status Update Mar 28 19:47:28 rivoplus volumio[3102]: info: ------------------------------ 12ms Mar 28 19:47:28 rivoplus volumio[3102]: info: sendMpdCommand play took 8 milliseconds Mar 28 19:47:28 rivoplus volumio[3102]: info: ------------------------------ 4ms Mar 28 19:47:28 rivoplus volumio[3102]: info: ------------------------------ 2ms Mar 28 19:47:28 rivoplus volumio[3102]: info: Executing endpoint getStreamUrlqobuz Mar 28 19:47:28 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Mar 28 19:47:28 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:28 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:28 rivoplus volumio[3102]: info: getStreamUrl took 430 milliseconds Mar 28 19:47:28 rivoplus volumio[3102]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=8278633&eid=348050597&fmt=7&profile=raw&app_id=539451548&cid=3333337&etsp=1774727248&hmac=wztPiGsXNDC7i8yOObP17PGJkd0 Mar 28 19:47:28 rivoplus volumio[3102]: STREAMING PROXY: Requesting upstream with range: none Mar 28 19:47:29 rivoplus volumio[3102]: STREAMING PROXY: Upstream status code: 200 Mar 28 19:47:29 rivoplus volumio[3102]: info: Mar 28 19:47:29 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:47:29 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:47:29 rivoplus volumio[3102]: info: Mar 28 19:47:29 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:47:29 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:47:29 rivoplus volumio[3102]: info: Mar 28 19:47:29 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:47:29 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:47:29 rivoplus volumio[3102]: info: Mar 28 19:47:29 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:47:29 rivoplus volumio[3102]: info: sendMpdCommand status took 27 milliseconds Mar 28 19:47:29 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:47:29 rivoplus volumio[3102]: info: sendMpdCommand status took 26 milliseconds Mar 28 19:47:29 rivoplus volumio[3102]: info: sendMpdCommand status took 25 milliseconds Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:47:29 rivoplus volumio[3102]: info: Mar 28 19:47:29 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:47:29 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:47:29 rivoplus volumio[3102]: info: Mar 28 19:47:29 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:47:29 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:47:29 rivoplus volumio[3102]: info: sendMpdCommand status took 17 milliseconds Mar 28 19:47:29 rivoplus volumio[3102]: info: sendMpdCommand playlistinfo took 16 milliseconds Mar 28 19:47:29 rivoplus volumio[3102]: info: sendMpdCommand playlistinfo took 14 milliseconds Mar 28 19:47:29 rivoplus volumio[3102]: info: sendMpdCommand playlistinfo took 14 milliseconds Mar 28 19:47:29 rivoplus volumio[3102]: info: sendMpdCommand status took 11 milliseconds Mar 28 19:47:29 rivoplus volumio[3102]: info: sendMpdCommand status took 8 milliseconds Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:47:29 rivoplus volumio[3102]: info: ControllerMpd::pushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::servicePushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 425 Mar 28 19:47:29 rivoplus volumio[3102]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":272,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"348050597","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/348050597","trackType":"qobuz"} Mar 28 19:47:29 rivoplus volumio[3102]: verbose: CURRENT POSITION 425 Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::syncState stateService play Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::syncState currentStatus stop Mar 28 19:47:29 rivoplus volumio[3102]: info: ControllerMpd::pushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::servicePushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 425 Mar 28 19:47:29 rivoplus volumio[3102]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":272,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"348050597","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/348050597","trackType":"qobuz"} Mar 28 19:47:29 rivoplus volumio[3102]: verbose: CURRENT POSITION 425 Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::syncState stateService play Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::syncState currentStatus play Mar 28 19:47:29 rivoplus volumio[3102]: info: Received an update from plugin. extracting info from payload Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:47:29 rivoplus volumio[3102]: info: ControllerMpd::pushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::servicePushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 425 Mar 28 19:47:29 rivoplus volumio[3102]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":272,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"348050597","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/348050597","trackType":"qobuz"} Mar 28 19:47:29 rivoplus volumio[3102]: verbose: CURRENT POSITION 425 Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::syncState stateService play Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::syncState currentStatus play Mar 28 19:47:29 rivoplus volumio[3102]: info: Received an update from plugin. extracting info from payload Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:47:29 rivoplus volumio[3102]: info: ------------------------------ 83ms Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.128+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=0 volume=100 Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.128+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/348050597 title="Tenho Sede" Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.129+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=0 volume=100 Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.129+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/348050597 title="Tenho Sede" Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.130+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=0 volume=100 Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.130+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/348050597 title="Tenho Sede" Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.131+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=0 volume=100 Mar 28 19:47:29 rivoplus volumio[3102]: info: ------------------------------ 96ms Mar 28 19:47:29 rivoplus volumio[3102]: info: sendMpdCommand playlistinfo took 54 milliseconds Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.132+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/348050597 title="Tenho Sede" Mar 28 19:47:29 rivoplus volumio[3102]: info: sendMpdCommand playlistinfo took 52 milliseconds Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:47:29 rivoplus volumio[3102]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:47:29 rivoplus volumio[3102]: info: ControllerMpd::pushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::servicePushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 425 Mar 28 19:47:29 rivoplus volumio[3102]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":272,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"348050597","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/348050597","trackType":"qobuz"} Mar 28 19:47:29 rivoplus volumio[3102]: verbose: CURRENT POSITION 425 Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::syncState stateService play Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::syncState currentStatus play Mar 28 19:47:29 rivoplus volumio[3102]: info: Received an update from plugin. extracting info from payload Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:47:29 rivoplus volumio[3102]: info: ControllerMpd::pushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::servicePushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 425 Mar 28 19:47:29 rivoplus volumio[3102]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":272,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"348050597","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/348050597","trackType":"qobuz"} Mar 28 19:47:29 rivoplus volumio[3102]: verbose: CURRENT POSITION 425 Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::syncState stateService play Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::syncState currentStatus play Mar 28 19:47:29 rivoplus volumio[3102]: info: Received an update from plugin. extracting info from payload Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:47:29 rivoplus volumio[3102]: info: ControllerMpd::pushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::servicePushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 425 Mar 28 19:47:29 rivoplus volumio[3102]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":272,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"348050597","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/348050597","trackType":"qobuz"} Mar 28 19:47:29 rivoplus volumio[3102]: verbose: CURRENT POSITION 425 Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::syncState stateService play Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::syncState currentStatus play Mar 28 19:47:29 rivoplus volumio[3102]: info: Received an update from plugin. extracting info from payload Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:47:29 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.198+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=241 volume=100 Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.198+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/348050597 title="Tenho Sede" Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.204+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=241 volume=100 Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.205+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/348050597 title="Tenho Sede" Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.206+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=241 volume=100 Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.207+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/348050597 title="Tenho Sede" Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.208+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=241 volume=100 Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.208+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/348050597 title="Tenho Sede" Mar 28 19:47:29 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:29.207+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/348050597 title="Tenho Sede" Mar 28 19:47:29 rivoplus volumio[3102]: info: ------------------------------ 151ms Mar 28 19:47:29 rivoplus volumio[3102]: info: ------------------------------ 143ms Mar 28 19:47:29 rivoplus volumio[3102]: info: ------------------------------ 143ms Mar 28 19:47:29 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:47:29 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:47:29 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:47:29 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:47:29 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:47:29 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:47:29 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:47:29 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:47:29 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:47:29 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:47:29 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:47:29 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:47:29 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:47:29 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:47:29 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:47:29 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:47:29 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:47:29 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:47:29 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:47:29 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:29 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:29 rivoplus volumio[3102]: info: MCU Signalled Playback Active Mar 28 19:47:29 rivoplus volumio[3102]: STREAMING PROXY: Resuming with range: bytes=550- Mar 28 19:47:29 rivoplus volumio[3102]: STREAMING PROXY: Resume upstream status code: 206 Mar 28 19:47:32 rivoplus volumio[3102]: STREAMING PROXY: Upstream closed. Received 84940788 bytes Mar 28 19:47:32 rivoplus volumio[3102]: STREAMING PROXY: Client closed connection Mar 28 19:47:33 rivoplus volumio[3102]: STREAMING PROXY: Resume ended. Received 84940238 bytes Mar 28 19:47:47 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Mar 28 19:47:49 rivoplus volumio[3102]: info: handleBrowseUri took 1213 milliseconds Mar 28 19:47:49 rivoplus volumio[3102]: info: Preload queue cleared Mar 28 19:47:49 rivoplus volumio[3102]: info: Executing endpoint getSimilarArtists Mar 28 19:47:49 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Mar 28 19:47:49 rivoplus volumio[3102]: info: Executing endpoint getSimilarArtists Mar 28 19:47:49 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Mar 28 19:47:49 rivoplus volumio[3102]: info: Executing endpoint getSimilarArtists Mar 28 19:47:49 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Mar 28 19:47:49 rivoplus volumio[3102]: info: Executing endpoint getSimilarArtists Mar 28 19:47:49 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Mar 28 19:47:49 rivoplus volumio[3102]: info: Executing endpoint getSimilarArtists Mar 28 19:47:49 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Mar 28 19:47:49 rivoplus volumio[3102]: info: Executing endpoint getSimilarArtists Mar 28 19:47:49 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Mar 28 19:47:49 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:49 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:50 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:50 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:50 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:50 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:50 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:50 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:50 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:50 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:50 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:50 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:54 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Mar 28 19:47:54 rivoplus volumio[3102]: info: handleBrowseUri took 415 milliseconds Mar 28 19:47:54 rivoplus volumio[3102]: info: Preload queue cleared Mar 28 19:47:54 rivoplus volumio[3102]: info: Preloading song: qobuz://song/295379045 Mar 28 19:47:55 rivoplus volumio[3102]: info: Exploding uri qobuz://song/295379045 in service qobuz Mar 28 19:47:55 rivoplus volumio[3102]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 28 19:47:55 rivoplus volumio[3102]: info: Executing endpoint getSimilarAlbums Mar 28 19:47:55 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 28 19:47:55 rivoplus volumio[3102]: info: Executing endpoint getSimilarAlbums Mar 28 19:47:55 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 28 19:47:55 rivoplus volumio[3102]: info: Executing endpoint getSimilarAlbums Mar 28 19:47:55 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 28 19:47:55 rivoplus volumio[3102]: info: Executing endpoint getSimilarAlbums Mar 28 19:47:55 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 28 19:47:55 rivoplus volumio[3102]: info: Executing endpoint getSimilarAlbums Mar 28 19:47:55 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 28 19:47:55 rivoplus volumio[3102]: info: Executing endpoint getSimilarAlbums Mar 28 19:47:55 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 28 19:47:55 rivoplus volumio[3102]: info: explodeUri took 433 milliseconds Mar 28 19:47:56 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:56 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:56 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:56 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:56 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:56 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:56 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:56 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:57 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:57 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:57 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:57 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:58 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:58 rivoplus volumio[3102]: info: Preload queue cleared Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::volumioAddQueueItems Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::addQueueItems Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::addQueueItems Mar 28 19:47:58 rivoplus volumio[3102]: info: Preload queue cleared Mar 28 19:47:58 rivoplus volumio[3102]: info: Adding Item to queue: qobuz://song/295379045 Mar 28 19:47:58 rivoplus volumio[3102]: info: Using cached record of: qobuz://song/295379045 Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushQueue Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::saveQueue Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::updateTrackBlock Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::getTrackBlock Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPlay Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::play index 426 Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::stop Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::stPlaybackTimer Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::updateTrackBlock Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::getTrackBlock Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 425 Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 425 Mar 28 19:47:58 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:47:58 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::serviceStop Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 425 Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::serviceStop Mar 28 19:47:58 rivoplus volumio[3102]: info: [1774723678731] ControllerQobuz::stop Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 28 19:47:58 rivoplus volumio[3102]: info: ControllerMpd::stop Mar 28 19:47:58 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 19:47:58 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:58.736+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_STOPPED positionMs=0 volume=100 Mar 28 19:47:58 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:58.737+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/348050597 title="Tenho Sede" Mar 28 19:47:58 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:47:58 rivoplus volumio[3102]: info: Mar 28 19:47:58 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:47:58 rivoplus volumio[3102]: info: sendMpdCommand stop took 80 milliseconds Mar 28 19:47:58 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:47:58 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::play index undefined Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::startPlaybackTimer Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetVisibleSources Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 28 19:47:58 rivoplus volumio[3102]: info: [1774723678815] ControllerQobuz::clearAddPlayTrack Mar 28 19:47:58 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 19:47:58 rivoplus volumio[3102]: info: sendMpdCommand status took 19 milliseconds Mar 28 19:47:58 rivoplus volumio[3102]: info: sendMpdCommand stop took 17 milliseconds Mar 28 19:47:58 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:47:58 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:47:58 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand clear Mar 28 19:47:58 rivoplus volumio[3102]: info: Mar 28 19:47:58 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:47:58 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:47:58 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:47:58 rivoplus volumio[3102]: info: Mar 28 19:47:58 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:47:58 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:47:58 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:47:58 rivoplus volumio[3102]: info: Mar 28 19:47:58 rivoplus volumio[3102]: ---------------------------- MPD announces system playlist update Mar 28 19:47:58 rivoplus volumio[3102]: info: Ignoring MPD Status Update Mar 28 19:47:58 rivoplus volumio[3102]: info: sendMpdCommand playlistinfo took 13 milliseconds Mar 28 19:47:58 rivoplus volumio[3102]: info: sendMpdCommand clear took 13 milliseconds Mar 28 19:47:58 rivoplus volumio[3102]: info: sendMpdCommand status took 5 milliseconds Mar 28 19:47:58 rivoplus volumio[3102]: info: sendMpdCommand status took 3 milliseconds Mar 28 19:47:58 rivoplus volumio[3102]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:47:58 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/295379045" Mar 28 19:47:58 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:47:58 rivoplus volumio[3102]: info: ControllerMpd::pushState Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::servicePushState Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:47:58 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:47:58 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:47:58 rivoplus volumio[3102]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Mar 28 19:47:58 rivoplus volumio[3102]: info: ControllerMpd::pushState Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::servicePushState Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:47:58 rivoplus volumio[3102]: STREAMING PROXY: Handling url /?data=qobuz://song/295379045 Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:47:58 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:47:58 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:47:58 rivoplus volumio[3102]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Mar 28 19:47:58 rivoplus volumio[3102]: info: ControllerMpd::pushState Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::servicePushState Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:47:58 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:47:58 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:47:58 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:47:58 rivoplus volumio[3102]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Mar 28 19:47:58 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:58.871+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_STOPPED positionMs=0 volume=100 Mar 28 19:47:58 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:58.871+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/295379045 title="Céu e Mar" Mar 28 19:47:58 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:58.872+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_STOPPED positionMs=0 volume=100 Mar 28 19:47:58 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:58.872+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/295379045 title="Céu e Mar" Mar 28 19:47:58 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:58.873+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_STOPPED positionMs=0 volume=100 Mar 28 19:47:58 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:47:58.873+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/295379045 title="Céu e Mar" Mar 28 19:47:58 rivoplus volumio[3102]: info: ------------------------------ 63ms Mar 28 19:47:58 rivoplus volumio[3102]: info: ------------------------------ 35ms Mar 28 19:47:58 rivoplus volumio[3102]: info: ------------------------------ 33ms Mar 28 19:47:58 rivoplus volumio[3102]: info: Mar 28 19:47:58 rivoplus volumio[3102]: ---------------------------- MPD announces system playlist update Mar 28 19:47:58 rivoplus volumio[3102]: info: Ignoring MPD Status Update Mar 28 19:47:58 rivoplus volumio[3102]: info: Mar 28 19:47:58 rivoplus volumio[3102]: ---------------------------- MPD announces system playlist update Mar 28 19:47:58 rivoplus volumio[3102]: info: Ignoring MPD Status Update Mar 28 19:47:58 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:58 rivoplus volumio[3102]: error: updateQueue error: null Mar 28 19:47:58 rivoplus volumio[3102]: info: ------------------------------ 44ms Mar 28 19:47:58 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:47:58 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:47:58 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:47:58 rivoplus volumio[3102]: info: MCU Signalled Playback Inactive Mar 28 19:47:58 rivoplus volumio[3102]: info: Executing endpoint getStreamUrlqobuz Mar 28 19:47:58 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Mar 28 19:47:59 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:47:59 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:47:59 rivoplus volumio[3102]: info: getStreamUrl took 430 milliseconds Mar 28 19:47:59 rivoplus volumio[3102]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=8278633&eid=295379045&fmt=6&profile=raw&app_id=539451548&cid=3333337&etsp=1774727279&hmac=Bghr3jxsxNd6kAQ9dpXUalhPAIk Mar 28 19:47:59 rivoplus volumio[3102]: STREAMING PROXY: Requesting upstream with range: none Mar 28 19:47:59 rivoplus volumio[3102]: STREAMING PROXY: Upstream status code: 200 Mar 28 19:47:59 rivoplus volumio[3102]: STREAMING PROXY: Client closed connection Mar 28 19:47:59 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/295379045" Mar 28 19:47:59 rivoplus volumio[3102]: STREAMING PROXY: Upstream closed. Received 838 bytes Mar 28 19:47:59 rivoplus volumio[3102]: STREAMING PROXY: Incomplete transfer. Expected 50635832, got 838 Mar 28 19:47:59 rivoplus volumio[3102]: STREAMING PROXY: Retrying with range: bytes=838- (attempt 1) Mar 28 19:47:59 rivoplus volumio[3102]: error: updateQueue error: null Mar 28 19:47:59 rivoplus volumio[3102]: info: Mar 28 19:47:59 rivoplus volumio[3102]: ---------------------------- MPD announces system playlist update Mar 28 19:47:59 rivoplus volumio[3102]: info: Ignoring MPD Status Update Mar 28 19:47:59 rivoplus volumio[3102]: info: ------------------------------ 894ms Mar 28 19:47:59 rivoplus volumio[3102]: info: ------------------------------ 892ms Mar 28 19:47:59 rivoplus volumio[3102]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/295379045" took 3 milliseconds Mar 28 19:47:59 rivoplus volumio[3102]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 28 19:47:59 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand play Mar 28 19:47:59 rivoplus volumio[3102]: STREAMING PROXY: Handling url /?data=qobuz://song/295379045 Mar 28 19:47:59 rivoplus volumio[3102]: info: Mar 28 19:47:59 rivoplus volumio[3102]: ---------------------------- MPD announces system playlist update Mar 28 19:47:59 rivoplus volumio[3102]: info: Ignoring MPD Status Update Mar 28 19:47:59 rivoplus volumio[3102]: info: Mar 28 19:47:59 rivoplus volumio[3102]: ---------------------------- MPD announces system playlist update Mar 28 19:47:59 rivoplus volumio[3102]: info: Ignoring MPD Status Update Mar 28 19:47:59 rivoplus volumio[3102]: info: ------------------------------ 8ms Mar 28 19:47:59 rivoplus volumio[3102]: info: sendMpdCommand play took 7 milliseconds Mar 28 19:47:59 rivoplus volumio[3102]: info: ------------------------------ 4ms Mar 28 19:47:59 rivoplus volumio[3102]: info: ------------------------------ 3ms Mar 28 19:47:59 rivoplus volumio[3102]: info: Executing endpoint getStreamUrlqobuz Mar 28 19:47:59 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Mar 28 19:48:00 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:48:00 rivoplus volumio[3102]: info: getStreamUrl took 370 milliseconds Mar 28 19:48:00 rivoplus volumio[3102]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=8278633&eid=295379045&fmt=6&profile=raw&app_id=539451548&cid=3333337&etsp=1774727280&hmac=TnmQV1akUbm4dgDjmB1adQBpREY Mar 28 19:48:00 rivoplus volumio[3102]: STREAMING PROXY: Requesting upstream with range: none Mar 28 19:48:00 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:48:00 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:48:00 rivoplus volumio[3102]: STREAMING PROXY: Upstream status code: 200 Mar 28 19:48:00 rivoplus volumio[3102]: info: Mar 28 19:48:00 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:48:00 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:48:00 rivoplus volumio[3102]: info: Mar 28 19:48:00 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:48:00 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:48:00 rivoplus volumio[3102]: info: Mar 28 19:48:00 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:48:00 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:48:00 rivoplus volumio[3102]: info: sendMpdCommand status took 33 milliseconds Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:48:00 rivoplus volumio[3102]: info: Mar 28 19:48:00 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:48:00 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:48:00 rivoplus volumio[3102]: info: sendMpdCommand status took 37 milliseconds Mar 28 19:48:00 rivoplus volumio[3102]: info: sendMpdCommand status took 36 milliseconds Mar 28 19:48:00 rivoplus volumio[3102]: info: sendMpdCommand playlistinfo took 5 milliseconds Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:48:00 rivoplus volumio[3102]: info: ControllerMpd::pushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::servicePushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:48:00 rivoplus volumio[3102]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":437,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"650 Kbps","isStreaming":false,"title":"295379045","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/295379045","trackType":"qobuz"} Mar 28 19:48:00 rivoplus volumio[3102]: verbose: CURRENT POSITION 426 Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::syncState stateService play Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::syncState currentStatus stop Mar 28 19:48:00 rivoplus volumio[3102]: info: ------------------------------ 52ms Mar 28 19:48:00 rivoplus volumio[3102]: info: Mar 28 19:48:00 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:48:00 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:48:00 rivoplus volumio[3102]: info: Mar 28 19:48:00 rivoplus volumio[3102]: ---------------------------- MPD announces state update: player Mar 28 19:48:00 rivoplus volumio[3102]: info: ControllerMpd::getState Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand status Mar 28 19:48:00 rivoplus volumio[3102]: info: sendMpdCommand status took 19 milliseconds Mar 28 19:48:00 rivoplus volumio[3102]: info: sendMpdCommand playlistinfo took 12 milliseconds Mar 28 19:48:00 rivoplus volumio[3102]: info: sendMpdCommand playlistinfo took 11 milliseconds Mar 28 19:48:00 rivoplus volumio[3102]: info: sendMpdCommand status took 4 milliseconds Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:48:00 rivoplus volumio[3102]: info: ControllerMpd::pushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::servicePushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:48:00 rivoplus volumio[3102]: verbose: STATE SERVICE {"status":"play","position":0,"seek":274,"duration":437,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"650 Kbps","isStreaming":false,"title":"295379045","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/295379045","trackType":"qobuz"} Mar 28 19:48:00 rivoplus volumio[3102]: verbose: CURRENT POSITION 426 Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::syncState stateService play Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::syncState currentStatus play Mar 28 19:48:00 rivoplus volumio[3102]: info: Received an update from plugin. extracting info from payload Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:48:00 rivoplus volumio[3102]: info: ControllerMpd::pushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::servicePushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:48:00 rivoplus volumio[3102]: verbose: STATE SERVICE {"status":"play","position":0,"seek":274,"duration":437,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"650 Kbps","isStreaming":false,"title":"295379045","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/295379045","trackType":"qobuz"} Mar 28 19:48:00 rivoplus volumio[3102]: verbose: CURRENT POSITION 426 Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::syncState stateService play Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::syncState currentStatus play Mar 28 19:48:00 rivoplus volumio[3102]: info: Received an update from plugin. extracting info from payload Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.410+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=0 volume=100 Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.411+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/295379045 title="Céu e Mar" Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.415+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=0 volume=100 Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.415+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/295379045 title="Céu e Mar" Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.416+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=0 volume=100 Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.416+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/295379045 title="Céu e Mar" Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.418+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=0 volume=100 Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.419+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/295379045 title="Céu e Mar" Mar 28 19:48:00 rivoplus volumio[3102]: info: ------------------------------ 118ms Mar 28 19:48:00 rivoplus volumio[3102]: info: ------------------------------ 119ms Mar 28 19:48:00 rivoplus volumio[3102]: info: sendMpdCommand status took 72 milliseconds Mar 28 19:48:00 rivoplus volumio[3102]: info: sendMpdCommand playlistinfo took 70 milliseconds Mar 28 19:48:00 rivoplus volumio[3102]: info: sendMpdCommand playlistinfo took 69 milliseconds Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::parseState Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:48:00 rivoplus volumio[3102]: info: ControllerMpd::pushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::servicePushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:48:00 rivoplus volumio[3102]: verbose: STATE SERVICE {"status":"play","position":0,"seek":320,"duration":437,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"657 Kbps","isStreaming":false,"title":"295379045","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/295379045","trackType":"qobuz"} Mar 28 19:48:00 rivoplus volumio[3102]: verbose: CURRENT POSITION 426 Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::syncState stateService play Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::syncState currentStatus play Mar 28 19:48:00 rivoplus volumio[3102]: info: Received an update from plugin. extracting info from payload Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:48:00 rivoplus volumio[3102]: info: ControllerMpd::pushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::servicePushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:48:00 rivoplus volumio[3102]: verbose: STATE SERVICE {"status":"play","position":0,"seek":366,"duration":437,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"827 Kbps","isStreaming":false,"title":"295379045","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/295379045","trackType":"qobuz"} Mar 28 19:48:00 rivoplus volumio[3102]: verbose: CURRENT POSITION 426 Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::syncState stateService play Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::syncState currentStatus play Mar 28 19:48:00 rivoplus volumio[3102]: info: Received an update from plugin. extracting info from payload Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.509+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=0 volume=100 Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.509+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/295379045 title="Céu e Mar" Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.511+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=0 volume=100 Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.511+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/295379045 title="Céu e Mar" Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.513+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=0 volume=100 Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.514+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/295379045 title="Céu e Mar" Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.519+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=0 volume=100 Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.520+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/295379045 title="Céu e Mar" Mar 28 19:48:00 rivoplus volumio[3102]: info: ------------------------------ 181ms Mar 28 19:48:00 rivoplus volumio[3102]: info: ------------------------------ 166ms Mar 28 19:48:00 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:48:00 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:48:00 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:48:00 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:48:00 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:48:00 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:48:00 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:48:00 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:48:00 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:48:00 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:48:00 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:48:00 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:48:00 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:48:00 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:48:00 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:48:00 rivoplus volumio[3102]: info: sendMpdCommand playlistinfo took 175 milliseconds Mar 28 19:48:00 rivoplus volumio[3102]: verbose: ControllerMpd::parseTrackInfo Mar 28 19:48:00 rivoplus volumio[3102]: info: ControllerMpd::pushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::servicePushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CorePlayQueue::getTrack 426 Mar 28 19:48:00 rivoplus volumio[3102]: verbose: STATE SERVICE {"status":"play","position":0,"seek":434,"duration":437,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"827 Kbps","isStreaming":false,"title":"295379045","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/295379045","trackType":"qobuz"} Mar 28 19:48:00 rivoplus volumio[3102]: verbose: CURRENT POSITION 426 Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::syncState stateService play Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::syncState currentStatus play Mar 28 19:48:00 rivoplus volumio[3102]: info: Received an update from plugin. extracting info from payload Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreStateMachine::pushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioPushState Mar 28 19:48:00 rivoplus volumio[3102]: info: CoreCommandRouter::volumioGetState Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output update for this device Mar 28 19:48:00 rivoplus volumio[3102]: info: MRS: Pushing multiroomSync output Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.641+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=293 volume=100 Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.642+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/295379045 title="Céu e Mar" Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.643+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" state=STATUS_PLAYING positionMs=293 volume=100 Mar 28 19:48:00 rivoplus volumio5-onboarding[3821]: time=2026-03-28T19:48:00.643+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.5:52294 @ 0x3594720" id=qobuz://song/295379045 title="Céu e Mar" Mar 28 19:48:00 rivoplus volumio[3102]: info: ------------------------------ 283ms Mar 28 19:48:00 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:48:00 rivoplus volumio[3102]: info: Signalling Playback active due to playback status change Mar 28 19:48:00 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:48:00 rivoplus volumio[3102]: info: Updating RAAT Signal Path Mar 28 19:48:00 rivoplus volumio[3102]: info: MCU Signalled Playback Active Mar 28 19:48:00 rivoplus volumio[3102]: STREAMING PROXY: Resuming with range: bytes=838- Mar 28 19:48:01 rivoplus volumio[3102]: STREAMING PROXY: Resume upstream status code: 206 Mar 28 19:48:02 rivoplus volumio[3102]: STREAMING PROXY: Upstream closed. Received 50635832 bytes Mar 28 19:48:02 rivoplus volumio[3102]: STREAMING PROXY: Client closed connection Mar 28 19:48:02 rivoplus volumio[3102]: STREAMING PROXY: Resume ended. Received 50634994 bytes Mar 28 19:48:45 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Mar 28 19:48:48 rivoplus volumio[3102]: info: handleBrowseUri took 2521 milliseconds Mar 28 19:48:48 rivoplus volumio[3102]: info: Preload queue cleared Mar 28 19:48:48 rivoplus volumio[3102]: info: Executing endpoint getSimilarArtists Mar 28 19:48:48 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Mar 28 19:48:48 rivoplus volumio[3102]: info: Executing endpoint getSimilarArtists Mar 28 19:48:48 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Mar 28 19:48:48 rivoplus volumio[3102]: info: Executing endpoint getSimilarArtists Mar 28 19:48:48 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Mar 28 19:48:48 rivoplus volumio[3102]: info: Executing endpoint getSimilarArtists Mar 28 19:48:48 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Mar 28 19:48:48 rivoplus volumio[3102]: info: Executing endpoint getSimilarArtists Mar 28 19:48:48 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Mar 28 19:48:48 rivoplus volumio[3102]: info: Executing endpoint getSimilarArtists Mar 28 19:48:48 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Mar 28 19:48:49 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:48:49 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:48:49 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:48:49 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:48:49 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:48:49 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:48:49 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:48:49 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:48:49 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:48:49 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:48:50 rivoplus volumio[3102]: info: Executing endpoint metavolumio Mar 28 19:48:50 rivoplus volumio[3102]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 28 19:48:52 rivoplus volumio[3102]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 19:48:52 rivoplus volumio[3102]: TypeError: Cannot read property 'slice' of null Mar 28 19:48:52 rivoplus volumio[3102]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Mar 28 19:48:52 rivoplus volumio[3102]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Mar 28 19:48:52 rivoplus volumio[3102]: at Object.onceWrapper (events.js:520:26) Mar 28 19:48:52 rivoplus volumio[3102]: at ClientRequest.emit (events.js:400:28) Mar 28 19:48:52 rivoplus volumio[3102]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:647:27) Mar 28 19:48:52 rivoplus volumio[3102]: at HTTPParser.parserOnHeadersComplete (_http_common.js:127:17) Mar 28 19:48:52 rivoplus volumio[3102]: at TLSSocket.socketOnData (_http_client.js:515:22) Mar 28 19:48:52 rivoplus volumio[3102]: at TLSSocket.emit (events.js:400:28) Mar 28 19:48:52 rivoplus volumio[3102]: at addChunk (internal/streams/readable.js:293:12) Mar 28 19:48:52 rivoplus volumio[3102]: at readableAddChunk (internal/streams/readable.js:267:9) Mar 28 19:48:52 rivoplus volumio[3102]: at TLSSocket.Readable.push (internal/streams/readable.js:206:10) Mar 28 19:48:52 rivoplus volumio[3102]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:188:23) Mar 28 19:48:52 rivoplus volumio[3102]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 19:48:52 rivoplus sudo[11110]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-03-28 19:47 Mar 28 19:48:52 rivoplus sudo[11110]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 11:19:27 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo Plus" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo Plus" VOLUMIO_HASH="a7285124ffc88c43265bb2db03526f6a"