-- Logs begin at Tue 2025-07-08 16:33:04 CEST, end at Tue 2025-07-08 16:41:58 CEST. -- Jul 08 16:40:06 rivoplus volumio[3282]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/The%20Brand%20New%20Heavies/bc43c9c7-baf7-452e-a8cb-91f000585981.jpg' Jul 08 16:40:07 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Jul 08 16:40:08 rivoplus volumio[3282]: info: handleBrowseUri took 723 milliseconds Jul 08 16:40:08 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:40:08 rivoplus volumio[3282]: info: Preloading song: qobuz://song/40119266 Jul 08 16:40:08 rivoplus volumio[3282]: info: Preloading song: qobuz://song/40119267 Jul 08 16:40:08 rivoplus volumio[3282]: info: Preloading song: qobuz://song/40119268 Jul 08 16:40:08 rivoplus volumio[3282]: info: Preloading song: qobuz://song/40119269 Jul 08 16:40:08 rivoplus volumio[3282]: info: Preloading song: qobuz://song/40119270 Jul 08 16:40:08 rivoplus volumio[3282]: info: Preloading song: qobuz://song/40119271 Jul 08 16:40:08 rivoplus volumio[3282]: info: Preloading song: qobuz://song/40119272 Jul 08 16:40:08 rivoplus volumio[3282]: info: Preloading song: qobuz://song/40119273 Jul 08 16:40:08 rivoplus volumio[3282]: info: Preloading song: qobuz://song/40119274 Jul 08 16:40:08 rivoplus volumio[3282]: info: Preloading song: qobuz://song/40119275 Jul 08 16:40:08 rivoplus volumio[3282]: info: Preloading song: qobuz://song/40119276 Jul 08 16:40:08 rivoplus volumio[3282]: info: Preloading song: qobuz://song/40119277 Jul 08 16:40:08 rivoplus volumio[3282]: info: Exploding uri qobuz://song/40119266 in service qobuz Jul 08 16:40:08 rivoplus volumio[3282]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jul 08 16:40:08 rivoplus volumio[3282]: info: Exploding uri qobuz://song/40119267 in service qobuz Jul 08 16:40:08 rivoplus volumio[3282]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jul 08 16:40:08 rivoplus volumio[3282]: info: Exploding uri qobuz://song/40119268 in service qobuz Jul 08 16:40:08 rivoplus volumio[3282]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jul 08 16:40:08 rivoplus volumio[3282]: info: Exploding uri qobuz://song/40119269 in service qobuz Jul 08 16:40:08 rivoplus volumio[3282]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jul 08 16:40:08 rivoplus volumio[3282]: info: Executing endpoint getSimilarAlbums Jul 08 16:40:08 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Jul 08 16:40:08 rivoplus volumio[3282]: info: Executing endpoint getSimilarAlbums Jul 08 16:40:08 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Jul 08 16:40:08 rivoplus volumio[3282]: info: Exploding uri qobuz://song/40119270 in service qobuz Jul 08 16:40:08 rivoplus volumio[3282]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jul 08 16:40:08 rivoplus volumio[3282]: info: Exploding uri qobuz://song/40119271 in service qobuz Jul 08 16:40:08 rivoplus volumio[3282]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jul 08 16:40:08 rivoplus volumio[3282]: info: Executing endpoint getSimilarAlbums Jul 08 16:40:08 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Jul 08 16:40:08 rivoplus volumio[3282]: info: Executing endpoint metavolumio Jul 08 16:40:08 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 08 16:40:08 rivoplus volumio[3282]: info: Executing endpoint metavolumio Jul 08 16:40:08 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 08 16:40:08 rivoplus volumio[3282]: info: Executing endpoint metavolumio Jul 08 16:40:08 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 08 16:40:08 rivoplus volumio[3282]: info: Exploding uri qobuz://song/40119272 in service qobuz Jul 08 16:40:08 rivoplus volumio[3282]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jul 08 16:40:09 rivoplus volumio[3282]: info: Exploding uri qobuz://song/40119273 in service qobuz Jul 08 16:40:09 rivoplus volumio[3282]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jul 08 16:40:09 rivoplus volumio[3282]: info: Exploding uri qobuz://song/40119274 in service qobuz Jul 08 16:40:09 rivoplus volumio[3282]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jul 08 16:40:09 rivoplus volumio[3282]: info: Exploding uri qobuz://song/40119275 in service qobuz Jul 08 16:40:09 rivoplus volumio[3282]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jul 08 16:40:09 rivoplus volumio[3282]: info: Exploding uri qobuz://song/40119276 in service qobuz Jul 08 16:40:09 rivoplus volumio[3282]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jul 08 16:40:09 rivoplus volumio[3282]: info: explodeUri took 521 milliseconds Jul 08 16:40:09 rivoplus volumio[3282]: info: explodeUri took 504 milliseconds Jul 08 16:40:09 rivoplus volumio[3282]: info: Exploding uri qobuz://song/40119277 in service qobuz Jul 08 16:40:09 rivoplus volumio[3282]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jul 08 16:40:09 rivoplus volumio[3282]: info: explodeUri took 629 milliseconds Jul 08 16:40:09 rivoplus volumio[3282]: info: explodeUri took 729 milliseconds Jul 08 16:40:09 rivoplus volumio[3282]: info: explodeUri took 539 milliseconds Jul 08 16:40:09 rivoplus volumio[3282]: info: explodeUri took 593 milliseconds Jul 08 16:40:09 rivoplus volumio[3282]: info: explodeUri took 700 milliseconds Jul 08 16:40:09 rivoplus volumio[3282]: info: explodeUri took 691 milliseconds Jul 08 16:40:09 rivoplus volumio[3282]: info: explodeUri took 590 milliseconds Jul 08 16:40:09 rivoplus volumio[3282]: info: explodeUri took 691 milliseconds Jul 08 16:40:09 rivoplus volumio[3282]: info: explodeUri took 628 milliseconds Jul 08 16:40:09 rivoplus volumio[3282]: info: Executing endpoint metavolumio Jul 08 16:40:09 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 08 16:40:09 rivoplus volumio[3282]: info: Executing endpoint metavolumio Jul 08 16:40:09 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 08 16:40:09 rivoplus volumio[3282]: info: explodeUri took 647 milliseconds Jul 08 16:40:09 rivoplus volumio[3282]: info: Executing endpoint metavolumio Jul 08 16:40:09 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 08 16:40:10 rivoplus volumio[3282]: info: Discovery: Getting this device information Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 08 16:40:10 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::ClearQueue Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::stop Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::stPlaybackTimer Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::updateTrackBlock Jul 08 16:40:10 rivoplus volumio[3282]: info: CorePlayQueue::getTrackBlock Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:40:10 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 4 Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:40:10 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 4 Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::serviceStop Jul 08 16:40:10 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 4 Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreCommandRouter::serviceStop Jul 08 16:40:10 rivoplus volumio[3282]: info: [1751985610697] ControllerQobuz::stop Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 08 16:40:10 rivoplus volumio[3282]: info: ControllerMpd::stop Jul 08 16:40:10 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand stop Jul 08 16:40:10 rivoplus volumio[3282]: info: CorePlayQueue::clearPlayQueue Jul 08 16:40:10 rivoplus volumio[3282]: info: CorePlayQueue::saveQueue Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushQueue Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::addQueueItems Jul 08 16:40:10 rivoplus volumio[3282]: info: CorePlayQueue::addQueueItems Jul 08 16:40:10 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:40:10 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119266 Jul 08 16:40:10 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119266 Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushQueue Jul 08 16:40:10 rivoplus volumio[3282]: info: CorePlayQueue::saveQueue Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::updateTrackBlock Jul 08 16:40:10 rivoplus volumio[3282]: info: CorePlayQueue::getTrackBlock Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPlay Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::play index 0 Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::addQueueItems Jul 08 16:40:10 rivoplus volumio[3282]: info: CorePlayQueue::addQueueItems Jul 08 16:40:10 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:40:10 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119267 Jul 08 16:40:10 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119267 Jul 08 16:40:10 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119268 Jul 08 16:40:10 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119268 Jul 08 16:40:10 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119269 Jul 08 16:40:10 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119269 Jul 08 16:40:10 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119270 Jul 08 16:40:10 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119270 Jul 08 16:40:10 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119271 Jul 08 16:40:10 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119271 Jul 08 16:40:10 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119272 Jul 08 16:40:10 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119272 Jul 08 16:40:10 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119273 Jul 08 16:40:10 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119273 Jul 08 16:40:10 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119274 Jul 08 16:40:10 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119274 Jul 08 16:40:10 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119275 Jul 08 16:40:10 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119275 Jul 08 16:40:10 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119276 Jul 08 16:40:10 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119276 Jul 08 16:40:10 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119277 Jul 08 16:40:10 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119277 Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::stop Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushQueue Jul 08 16:40:10 rivoplus volumio[3282]: info: CorePlayQueue::saveQueue Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::play index undefined Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::updateTrackBlock Jul 08 16:40:10 rivoplus volumio[3282]: info: CorePlayQueue::getTrackBlock Jul 08 16:40:10 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 0 Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreStateMachine::startPlaybackTimer Jul 08 16:40:10 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 0 Jul 08 16:40:10 rivoplus volumio[3282]: info: [1751985610752] ControllerQobuz::clearAddPlayTrack Jul 08 16:40:10 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand stop Jul 08 16:40:10 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:40:10 rivoplus volumio[3282]: info: Jul 08 16:40:10 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:40:10 rivoplus volumio[3282]: info: sendMpdCommand stop took 84 milliseconds Jul 08 16:40:10 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:40:10 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:40:10 rivoplus volumio[3282]: info: sendMpdCommand stop took 30 milliseconds Jul 08 16:40:10 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand clear Jul 08 16:40:10 rivoplus volumio[3282]: info: Jul 08 16:40:10 rivoplus volumio[3282]: ---------------------------- MPD announces system playlist update Jul 08 16:40:10 rivoplus volumio[3282]: info: Ignoring MPD Status Update Jul 08 16:40:10 rivoplus volumio[3282]: info: sendMpdCommand status took 5 milliseconds Jul 08 16:40:10 rivoplus volumio[3282]: info: sendMpdCommand clear took 5 milliseconds Jul 08 16:40:10 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:40:10 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 16:40:10 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/40119266" Jul 08 16:40:10 rivoplus volumio[3282]: STREAMING PROXY: Handling url /?data=qobuz://song/40119266 Jul 08 16:40:10 rivoplus volumio[3282]: error: updateQueue error: null Jul 08 16:40:10 rivoplus volumio[3282]: info: ------------------------------ 9ms Jul 08 16:40:10 rivoplus volumio[3282]: info: sendMpdCommand playlistinfo took 6 milliseconds Jul 08 16:40:10 rivoplus volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jul 08 16:40:10 rivoplus volumio[3282]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jul 08 16:40:10 rivoplus volumio[3282]: info: ------------------------------ 18ms Jul 08 16:40:10 rivoplus volumio[3282]: info: Executing endpoint getStreamUrlqobuz Jul 08 16:40:10 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jul 08 16:40:10 rivoplus volumio[3282]: info: MCU Signalled Playback Inactive Jul 08 16:40:11 rivoplus volumio[3282]: info: getStreamUrl took 499 milliseconds Jul 08 16:40:11 rivoplus volumio[3282]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2904916&eid=40119266&fmt=7&profile=raw&app_id=539451548&cid=2588719&etsp=1751989211&hmac=zPdcWNzo0jieTVAhglwJI_fj-rI Jul 08 16:40:11 rivoplus volumio[3282]: STREAMING PROXY: Response: 200, length: 117833959 Jul 08 16:40:11 rivoplus volumio[3282]: STREAMING PROXY: Client dropped request, destroying Jul 08 16:40:11 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/40119266" Jul 08 16:40:11 rivoplus volumio[3282]: info: Jul 08 16:40:11 rivoplus volumio[3282]: ---------------------------- MPD announces system playlist update Jul 08 16:40:11 rivoplus volumio[3282]: info: Ignoring MPD Status Update Jul 08 16:40:11 rivoplus volumio[3282]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/40119266" took 2 milliseconds Jul 08 16:40:11 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 08 16:40:11 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand play Jul 08 16:40:11 rivoplus volumio[3282]: info: ------------------------------ 4ms Jul 08 16:40:11 rivoplus volumio[3282]: info: sendMpdCommand play took 3 milliseconds Jul 08 16:40:11 rivoplus volumio[3282]: STREAMING PROXY: Handling url /?data=qobuz://song/40119266 Jul 08 16:40:11 rivoplus volumio[3282]: info: Executing endpoint getStreamUrlqobuz Jul 08 16:40:11 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jul 08 16:40:12 rivoplus volumio[3282]: info: getStreamUrl took 489 milliseconds Jul 08 16:40:12 rivoplus volumio[3282]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2904916&eid=40119266&fmt=7&profile=raw&app_id=539451548&cid=2588719&etsp=1751989212&hmac=W3DLFbcGz3RGcjt8O07FWGw0ucc Jul 08 16:40:12 rivoplus volumio[3282]: STREAMING PROXY: Response: 200, length: 117833959 Jul 08 16:40:12 rivoplus volumio[3282]: info: Jul 08 16:40:12 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:40:12 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:40:12 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:40:12 rivoplus volumio[3282]: STREAMING PROXY: Error proxying request: Error: read ECONNRESET Jul 08 16:40:12 rivoplus volumio[3282]: STREAMING PROXY: Client dropped request, destroying Jul 08 16:40:12 rivoplus volumio[3282]: info: Jul 08 16:40:12 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:40:12 rivoplus volumio[3282]: info: sendMpdCommand status took 72 milliseconds Jul 08 16:40:12 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:40:12 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:40:12 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:40:12 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 16:40:12 rivoplus volumio[3282]: info: Jul 08 16:40:12 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:40:12 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:40:12 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:40:12 rivoplus volumio[3282]: info: sendMpdCommand status took 27 milliseconds Jul 08 16:40:12 rivoplus volumio[3282]: info: sendMpdCommand playlistinfo took 27 milliseconds Jul 08 16:40:12 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:40:12 rivoplus volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jul 08 16:40:12 rivoplus volumio[3282]: info: ControllerMpd::pushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::servicePushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:40:12 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 0 Jul 08 16:40:12 rivoplus volumio[3282]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jul 08 16:40:12 rivoplus volumio[3282]: verbose: CURRENT POSITION 0 Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreStateMachine::syncState stateService stop Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreStateMachine::syncState currentStatus stop Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:40:12 rivoplus volumio[3282]: info: No code Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:40:12 rivoplus volumio[3282]: info: ControllerMpd::pushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::servicePushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 0 Jul 08 16:40:12 rivoplus volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":314,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"40119266","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/40119266","trackType":"qobuz"} Jul 08 16:40:12 rivoplus volumio[3282]: verbose: CURRENT POSITION 0 Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreStateMachine::syncState stateService play Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreStateMachine::syncState currentStatus stop Jul 08 16:40:12 rivoplus volumio[3282]: info: ------------------------------ 73ms Jul 08 16:40:12 rivoplus volumio[3282]: info: ------------------------------ 146ms Jul 08 16:40:12 rivoplus volumio[3282]: info: sendMpdCommand status took 45 milliseconds Jul 08 16:40:12 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:40:12 rivoplus volumio[3282]: info: ControllerMpd::pushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::servicePushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:40:12 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 0 Jul 08 16:40:12 rivoplus volumio[3282]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jul 08 16:40:12 rivoplus volumio[3282]: verbose: CURRENT POSITION 0 Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreStateMachine::syncState stateService stop Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreStateMachine::syncState currentStatus play Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreStateMachine::play index undefined Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 1 Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:40:12 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 1 Jul 08 16:40:12 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 1 Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreStateMachine::startPlaybackTimer Jul 08 16:40:12 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 1 Jul 08 16:40:12 rivoplus volumio[3282]: info: [1751985612639] ControllerQobuz::clearAddPlayTrack Jul 08 16:40:12 rivoplus volumio[3282]: info: ------------------------------ 83ms Jul 08 16:40:12 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand stop Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 1 Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:40:12 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 1 Jul 08 16:40:12 rivoplus volumio[3282]: info: Signalling Playback active due to playback status change Jul 08 16:40:12 rivoplus volumio[3282]: info: Signalling Playback active due to playback status change Jul 08 16:40:12 rivoplus volumio[3282]: info: Signalling Playback active due to playback status change Jul 08 16:40:12 rivoplus volumio[3282]: info: Signalling Playback active due to playback status change Jul 08 16:40:12 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:40:12 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:40:12 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:40:12 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:40:12 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:40:12 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:40:12 rivoplus volumio[3282]: info: sendMpdCommand stop took 91 milliseconds Jul 08 16:40:12 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand clear Jul 08 16:40:12 rivoplus volumio[3282]: info: Jul 08 16:40:12 rivoplus volumio[3282]: ---------------------------- MPD announces system playlist update Jul 08 16:40:12 rivoplus volumio[3282]: info: Ignoring MPD Status Update Jul 08 16:40:12 rivoplus volumio[3282]: info: sendMpdCommand clear took 8 milliseconds Jul 08 16:40:12 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/40119267" Jul 08 16:40:12 rivoplus volumio[3282]: error: updateQueue error: null Jul 08 16:40:12 rivoplus volumio[3282]: STREAMING PROXY: Handling url /?data=qobuz://song/40119267 Jul 08 16:40:12 rivoplus volumio[3282]: info: ------------------------------ 7ms Jul 08 16:40:12 rivoplus volumio[3282]: info: Executing endpoint getStreamUrlqobuz Jul 08 16:40:12 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jul 08 16:40:12 rivoplus volumio[3282]: info: MCU Signalled Playback Active Jul 08 16:40:12 rivoplus volumio[3282]: info: MCU Signalled Playback Inactive Jul 08 16:40:13 rivoplus volumio[3282]: info: getStreamUrl took 584 milliseconds Jul 08 16:40:13 rivoplus volumio[3282]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2904916&eid=40119267&fmt=7&profile=raw&app_id=539451548&cid=2588719&etsp=1751989213&hmac=be5GjwLim4ZXcRXsnLOZ6PssyPk Jul 08 16:40:13 rivoplus volumio[3282]: STREAMING PROXY: Response: 200, length: 103780624 Jul 08 16:40:13 rivoplus volumio[3282]: STREAMING PROXY: Client dropped request, destroying Jul 08 16:40:13 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/40119267" Jul 08 16:40:13 rivoplus volumio[3282]: info: Jul 08 16:40:13 rivoplus volumio[3282]: ---------------------------- MPD announces system playlist update Jul 08 16:40:13 rivoplus volumio[3282]: info: Ignoring MPD Status Update Jul 08 16:40:13 rivoplus volumio[3282]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/40119267" took 3 milliseconds Jul 08 16:40:13 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 08 16:40:13 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand play Jul 08 16:40:13 rivoplus volumio[3282]: info: ------------------------------ 7ms Jul 08 16:40:13 rivoplus volumio[3282]: info: sendMpdCommand play took 5 milliseconds Jul 08 16:40:13 rivoplus volumio[3282]: STREAMING PROXY: Handling url /?data=qobuz://song/40119267 Jul 08 16:40:13 rivoplus volumio[3282]: info: Executing endpoint getStreamUrlqobuz Jul 08 16:40:13 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jul 08 16:40:14 rivoplus volumio[3282]: info: getStreamUrl took 601 milliseconds Jul 08 16:40:14 rivoplus volumio[3282]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2904916&eid=40119267&fmt=7&profile=raw&app_id=539451548&cid=2588719&etsp=1751989214&hmac=FxqtJ5rRgDaXGpPeiSQfuk723Dw Jul 08 16:40:14 rivoplus volumio[3282]: STREAMING PROXY: Response: 200, length: 103780624 Jul 08 16:40:14 rivoplus volumio[3282]: info: Jul 08 16:40:14 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:40:14 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:40:14 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:40:14 rivoplus volumio[3282]: info: Jul 08 16:40:14 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:40:14 rivoplus volumio[3282]: info: sendMpdCommand status took 29 milliseconds Jul 08 16:40:14 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:40:14 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:40:14 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:40:14 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 16:40:14 rivoplus volumio[3282]: info: sendMpdCommand status took 4 milliseconds Jul 08 16:40:14 rivoplus volumio[3282]: info: sendMpdCommand playlistinfo took 2 milliseconds Jul 08 16:40:14 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:40:14 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 16:40:14 rivoplus volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jul 08 16:40:14 rivoplus volumio[3282]: info: ControllerMpd::pushState Jul 08 16:40:14 rivoplus volumio[3282]: info: CoreCommandRouter::servicePushState Jul 08 16:40:14 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 1 Jul 08 16:40:14 rivoplus volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":288,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"40119267","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/40119267","trackType":"qobuz"} Jul 08 16:40:14 rivoplus volumio[3282]: verbose: CURRENT POSITION 1 Jul 08 16:40:14 rivoplus volumio[3282]: info: CoreStateMachine::syncState stateService play Jul 08 16:40:14 rivoplus volumio[3282]: info: CoreStateMachine::syncState currentStatus stop Jul 08 16:40:14 rivoplus volumio[3282]: info: ------------------------------ 49ms Jul 08 16:40:14 rivoplus volumio[3282]: info: sendMpdCommand playlistinfo took 11 milliseconds Jul 08 16:40:14 rivoplus volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jul 08 16:40:14 rivoplus volumio[3282]: info: ControllerMpd::pushState Jul 08 16:40:14 rivoplus volumio[3282]: info: CoreCommandRouter::servicePushState Jul 08 16:40:14 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 1 Jul 08 16:40:14 rivoplus volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":288,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"40119267","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/40119267","trackType":"qobuz"} Jul 08 16:40:14 rivoplus volumio[3282]: verbose: CURRENT POSITION 1 Jul 08 16:40:14 rivoplus volumio[3282]: info: CoreStateMachine::syncState stateService play Jul 08 16:40:14 rivoplus volumio[3282]: info: CoreStateMachine::syncState currentStatus play Jul 08 16:40:14 rivoplus volumio[3282]: info: Received an update from plugin. extracting info from payload Jul 08 16:40:14 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:40:14 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 16:40:14 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:40:14 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:40:14 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:40:14 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:40:14 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:40:14 rivoplus volumio[3282]: info: ------------------------------ 63ms Jul 08 16:40:14 rivoplus volumio[3282]: info: Signalling Playback active due to playback status change Jul 08 16:40:14 rivoplus volumio[3282]: info: Signalling Playback active due to playback status change Jul 08 16:40:14 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:40:14 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:40:14 rivoplus volumio[3282]: info: Executing endpoint metavolumio Jul 08 16:40:14 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 08 16:40:14 rivoplus volumio[3282]: info: Executing endpoint metavolumio Jul 08 16:40:14 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 08 16:40:14 rivoplus volumio[3282]: info: Executing endpoint metavolumio Jul 08 16:40:14 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 08 16:40:14 rivoplus volumio[3282]: info: MCU Signalled Playback Active Jul 08 16:40:20 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:40:20 rivoplus volumio[3282]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 08 16:40:20 rivoplus volumio[3282]: info: CoreStateMachine::ClearQueue Jul 08 16:40:20 rivoplus volumio[3282]: info: CoreStateMachine::stop Jul 08 16:40:20 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:40:20 rivoplus volumio[3282]: info: CoreStateMachine::stPlaybackTimer Jul 08 16:40:20 rivoplus volumio[3282]: info: CoreStateMachine::updateTrackBlock Jul 08 16:40:20 rivoplus volumio[3282]: info: CorePlayQueue::getTrackBlock Jul 08 16:40:20 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:40:20 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 1 Jul 08 16:40:20 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 16:40:20 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:40:20 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:40:20 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 1 Jul 08 16:40:20 rivoplus volumio[3282]: info: CoreStateMachine::serviceStop Jul 08 16:40:20 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 1 Jul 08 16:40:20 rivoplus volumio[3282]: info: CoreCommandRouter::serviceStop Jul 08 16:40:20 rivoplus volumio[3282]: info: [1751985620962] ControllerQobuz::stop Jul 08 16:40:20 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 08 16:40:20 rivoplus volumio[3282]: info: ControllerMpd::stop Jul 08 16:40:20 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand stop Jul 08 16:40:20 rivoplus volumio[3282]: info: CorePlayQueue::clearPlayQueue Jul 08 16:40:20 rivoplus volumio[3282]: info: CorePlayQueue::saveQueue Jul 08 16:40:20 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushQueue Jul 08 16:40:20 rivoplus volumio[3282]: info: CoreStateMachine::addQueueItems Jul 08 16:40:20 rivoplus volumio[3282]: info: CorePlayQueue::addQueueItems Jul 08 16:40:20 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:40:20 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119266 Jul 08 16:40:20 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119266 Jul 08 16:40:20 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119267 Jul 08 16:40:20 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119267 Jul 08 16:40:20 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119268 Jul 08 16:40:20 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119268 Jul 08 16:40:20 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119269 Jul 08 16:40:20 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119269 Jul 08 16:40:20 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119270 Jul 08 16:40:20 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119270 Jul 08 16:40:20 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119271 Jul 08 16:40:20 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119271 Jul 08 16:40:20 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushQueue Jul 08 16:40:20 rivoplus volumio[3282]: info: CorePlayQueue::saveQueue Jul 08 16:40:20 rivoplus volumio[3282]: STREAMING PROXY: Client dropped request, destroying Jul 08 16:40:21 rivoplus volumio[3282]: info: CoreStateMachine::updateTrackBlock Jul 08 16:40:21 rivoplus volumio[3282]: info: CorePlayQueue::getTrackBlock Jul 08 16:40:21 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPlay Jul 08 16:40:21 rivoplus volumio[3282]: info: CoreStateMachine::play index 5 Jul 08 16:40:21 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:40:21 rivoplus volumio[3282]: info: CoreStateMachine::addQueueItems Jul 08 16:40:21 rivoplus volumio[3282]: info: CorePlayQueue::addQueueItems Jul 08 16:40:21 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:40:21 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119272 Jul 08 16:40:21 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119272 Jul 08 16:40:21 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119273 Jul 08 16:40:21 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119273 Jul 08 16:40:21 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119274 Jul 08 16:40:21 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119274 Jul 08 16:40:21 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119275 Jul 08 16:40:21 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119275 Jul 08 16:40:21 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119276 Jul 08 16:40:21 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119276 Jul 08 16:40:21 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119277 Jul 08 16:40:21 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119277 Jul 08 16:40:21 rivoplus volumio[3282]: info: CoreStateMachine::stop Jul 08 16:40:21 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:40:21 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushQueue Jul 08 16:40:21 rivoplus volumio[3282]: info: CorePlayQueue::saveQueue Jul 08 16:40:21 rivoplus volumio[3282]: info: CoreStateMachine::play index undefined Jul 08 16:40:21 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:40:21 rivoplus volumio[3282]: info: CoreStateMachine::updateTrackBlock Jul 08 16:40:21 rivoplus volumio[3282]: info: CorePlayQueue::getTrackBlock Jul 08 16:40:21 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 5 Jul 08 16:40:21 rivoplus volumio[3282]: info: CoreStateMachine::startPlaybackTimer Jul 08 16:40:21 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 5 Jul 08 16:40:21 rivoplus volumio[3282]: info: [1751985621044] ControllerQobuz::clearAddPlayTrack Jul 08 16:40:21 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand stop Jul 08 16:40:21 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:40:21 rivoplus volumio[3282]: info: Jul 08 16:40:21 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:40:21 rivoplus volumio[3282]: info: sendMpdCommand stop took 104 milliseconds Jul 08 16:40:21 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:40:21 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:40:21 rivoplus volumio[3282]: info: sendMpdCommand stop took 24 milliseconds Jul 08 16:40:21 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand clear Jul 08 16:40:21 rivoplus volumio[3282]: info: Jul 08 16:40:21 rivoplus volumio[3282]: ---------------------------- MPD announces system playlist update Jul 08 16:40:21 rivoplus volumio[3282]: info: Ignoring MPD Status Update Jul 08 16:40:21 rivoplus volumio[3282]: info: sendMpdCommand status took 6 milliseconds Jul 08 16:40:21 rivoplus volumio[3282]: info: sendMpdCommand clear took 5 milliseconds Jul 08 16:40:21 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:40:21 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 16:40:21 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/40119271" Jul 08 16:40:21 rivoplus volumio[3282]: STREAMING PROXY: Handling url /?data=qobuz://song/40119271 Jul 08 16:40:21 rivoplus volumio[3282]: error: updateQueue error: null Jul 08 16:40:21 rivoplus volumio[3282]: info: ------------------------------ 9ms Jul 08 16:40:21 rivoplus volumio[3282]: info: sendMpdCommand playlistinfo took 6 milliseconds Jul 08 16:40:21 rivoplus volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jul 08 16:40:21 rivoplus volumio[3282]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jul 08 16:40:21 rivoplus volumio[3282]: info: ------------------------------ 18ms Jul 08 16:40:21 rivoplus volumio[3282]: info: Executing endpoint getStreamUrlqobuz Jul 08 16:40:21 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jul 08 16:40:21 rivoplus volumio[3282]: info: MCU Signalled Playback Inactive Jul 08 16:40:21 rivoplus volumio[3282]: info: getStreamUrl took 453 milliseconds Jul 08 16:40:21 rivoplus volumio[3282]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2904916&eid=40119271&fmt=7&profile=raw&app_id=539451548&cid=2588719&etsp=1751989221&hmac=0AKb_WhYZfs2K0E2sBNmIesuZ4g Jul 08 16:40:21 rivoplus volumio[3282]: STREAMING PROXY: Response: 200, length: 87487250 Jul 08 16:40:21 rivoplus volumio[3282]: STREAMING PROXY: Client dropped request, destroying Jul 08 16:40:21 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/40119271" Jul 08 16:40:21 rivoplus volumio[3282]: info: Jul 08 16:40:21 rivoplus volumio[3282]: ---------------------------- MPD announces system playlist update Jul 08 16:40:21 rivoplus volumio[3282]: info: Ignoring MPD Status Update Jul 08 16:40:21 rivoplus volumio[3282]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/40119271" took 4 milliseconds Jul 08 16:40:21 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 08 16:40:21 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand play Jul 08 16:40:21 rivoplus volumio[3282]: info: ------------------------------ 8ms Jul 08 16:40:21 rivoplus volumio[3282]: info: sendMpdCommand play took 2 milliseconds Jul 08 16:40:21 rivoplus volumio[3282]: STREAMING PROXY: Handling url /?data=qobuz://song/40119271 Jul 08 16:40:21 rivoplus volumio[3282]: info: Executing endpoint getStreamUrlqobuz Jul 08 16:40:21 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jul 08 16:40:22 rivoplus volumio[3282]: info: getStreamUrl took 419 milliseconds Jul 08 16:40:22 rivoplus volumio[3282]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2904916&eid=40119271&fmt=7&profile=raw&app_id=539451548&cid=2588719&etsp=1751989222&hmac=fhZ15zas9rWuNEO9hbq_ku5rzmk Jul 08 16:40:22 rivoplus volumio[3282]: STREAMING PROXY: Response: 200, length: 87487250 Jul 08 16:40:22 rivoplus volumio[3282]: info: Jul 08 16:40:22 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:40:22 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:40:22 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:40:22 rivoplus volumio[3282]: info: Jul 08 16:40:22 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:40:22 rivoplus volumio[3282]: info: sendMpdCommand status took 26 milliseconds Jul 08 16:40:22 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:40:22 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:40:22 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:40:22 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 16:40:22 rivoplus volumio[3282]: info: sendMpdCommand status took 3 milliseconds Jul 08 16:40:22 rivoplus volumio[3282]: info: sendMpdCommand playlistinfo took 2 milliseconds Jul 08 16:40:22 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:40:22 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 16:40:22 rivoplus volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jul 08 16:40:22 rivoplus volumio[3282]: info: ControllerMpd::pushState Jul 08 16:40:22 rivoplus volumio[3282]: info: CoreCommandRouter::servicePushState Jul 08 16:40:22 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 5 Jul 08 16:40:22 rivoplus volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"40119271","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/40119271","trackType":"qobuz"} Jul 08 16:40:22 rivoplus volumio[3282]: verbose: CURRENT POSITION 5 Jul 08 16:40:22 rivoplus volumio[3282]: info: CoreStateMachine::syncState stateService play Jul 08 16:40:22 rivoplus volumio[3282]: info: CoreStateMachine::syncState currentStatus stop Jul 08 16:40:22 rivoplus volumio[3282]: info: ------------------------------ 42ms Jul 08 16:40:22 rivoplus volumio[3282]: info: sendMpdCommand playlistinfo took 7 milliseconds Jul 08 16:40:22 rivoplus volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jul 08 16:40:22 rivoplus volumio[3282]: info: ControllerMpd::pushState Jul 08 16:40:22 rivoplus volumio[3282]: info: CoreCommandRouter::servicePushState Jul 08 16:40:22 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 5 Jul 08 16:40:22 rivoplus volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"40119271","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/40119271","trackType":"qobuz"} Jul 08 16:40:22 rivoplus volumio[3282]: verbose: CURRENT POSITION 5 Jul 08 16:40:22 rivoplus volumio[3282]: info: CoreStateMachine::syncState stateService play Jul 08 16:40:22 rivoplus volumio[3282]: info: CoreStateMachine::syncState currentStatus play Jul 08 16:40:22 rivoplus volumio[3282]: info: Received an update from plugin. extracting info from payload Jul 08 16:40:22 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:40:22 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 16:40:22 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:40:22 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:40:22 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:40:22 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:40:22 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:40:22 rivoplus volumio[3282]: info: ------------------------------ 54ms Jul 08 16:40:22 rivoplus volumio[3282]: info: Signalling Playback active due to playback status change Jul 08 16:40:22 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:40:22 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:40:22 rivoplus volumio[3282]: info: MCU Signalled Playback Active Jul 08 16:40:40 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 08 16:40:40 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 08 16:40:40 rivoplus volumio[3282]: info: Discovery: Getting this device information Jul 08 16:40:40 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:40:40 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 08 16:41:10 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 08 16:41:10 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 08 16:41:10 rivoplus volumio[3282]: info: Discovery: Getting this device information Jul 08 16:41:10 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:41:10 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 08 16:41:11 rivoplus volumio[3282]: STREAMING PROXY: Client dropped request, destroying Jul 08 16:41:14 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::ClearQueue Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::stop Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::stPlaybackTimer Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::updateTrackBlock Jul 08 16:41:14 rivoplus volumio[3282]: info: CorePlayQueue::getTrackBlock Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:41:14 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 5 Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:41:14 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 5 Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::serviceStop Jul 08 16:41:14 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 5 Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreCommandRouter::serviceStop Jul 08 16:41:14 rivoplus volumio[3282]: info: [1751985674797] ControllerQobuz::stop Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 08 16:41:14 rivoplus volumio[3282]: info: ControllerMpd::stop Jul 08 16:41:14 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand stop Jul 08 16:41:14 rivoplus volumio[3282]: info: CorePlayQueue::clearPlayQueue Jul 08 16:41:14 rivoplus volumio[3282]: info: CorePlayQueue::saveQueue Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushQueue Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::addQueueItems Jul 08 16:41:14 rivoplus volumio[3282]: info: CorePlayQueue::addQueueItems Jul 08 16:41:14 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:41:14 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119266 Jul 08 16:41:14 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119266 Jul 08 16:41:14 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119267 Jul 08 16:41:14 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119267 Jul 08 16:41:14 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119268 Jul 08 16:41:14 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119268 Jul 08 16:41:14 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119269 Jul 08 16:41:14 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119269 Jul 08 16:41:14 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119270 Jul 08 16:41:14 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119270 Jul 08 16:41:14 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119271 Jul 08 16:41:14 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119271 Jul 08 16:41:14 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119272 Jul 08 16:41:14 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119272 Jul 08 16:41:14 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119273 Jul 08 16:41:14 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119273 Jul 08 16:41:14 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119274 Jul 08 16:41:14 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119274 Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushQueue Jul 08 16:41:14 rivoplus volumio[3282]: info: CorePlayQueue::saveQueue Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::updateTrackBlock Jul 08 16:41:14 rivoplus volumio[3282]: info: CorePlayQueue::getTrackBlock Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPlay Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::play index 8 Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::addQueueItems Jul 08 16:41:14 rivoplus volumio[3282]: info: CorePlayQueue::addQueueItems Jul 08 16:41:14 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:41:14 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119275 Jul 08 16:41:14 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119275 Jul 08 16:41:14 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119276 Jul 08 16:41:14 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119276 Jul 08 16:41:14 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119277 Jul 08 16:41:14 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119277 Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::stop Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushQueue Jul 08 16:41:14 rivoplus volumio[3282]: info: CorePlayQueue::saveQueue Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::play index undefined Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::updateTrackBlock Jul 08 16:41:14 rivoplus volumio[3282]: info: CorePlayQueue::getTrackBlock Jul 08 16:41:14 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 8 Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreStateMachine::startPlaybackTimer Jul 08 16:41:14 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 8 Jul 08 16:41:14 rivoplus volumio[3282]: info: [1751985674879] ControllerQobuz::clearAddPlayTrack Jul 08 16:41:14 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand stop Jul 08 16:41:14 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:41:14 rivoplus volumio[3282]: info: Jul 08 16:41:14 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:41:14 rivoplus volumio[3282]: info: sendMpdCommand stop took 108 milliseconds Jul 08 16:41:14 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:41:14 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:41:14 rivoplus volumio[3282]: info: sendMpdCommand stop took 27 milliseconds Jul 08 16:41:14 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand clear Jul 08 16:41:14 rivoplus volumio[3282]: info: Jul 08 16:41:14 rivoplus volumio[3282]: ---------------------------- MPD announces system playlist update Jul 08 16:41:14 rivoplus volumio[3282]: info: Ignoring MPD Status Update Jul 08 16:41:14 rivoplus volumio[3282]: info: sendMpdCommand status took 14 milliseconds Jul 08 16:41:14 rivoplus volumio[3282]: info: sendMpdCommand clear took 8 milliseconds Jul 08 16:41:14 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:41:14 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 16:41:14 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/40119274" Jul 08 16:41:14 rivoplus volumio[3282]: STREAMING PROXY: Handling url /?data=qobuz://song/40119274 Jul 08 16:41:14 rivoplus volumio[3282]: error: updateQueue error: null Jul 08 16:41:14 rivoplus volumio[3282]: info: ------------------------------ 11ms Jul 08 16:41:14 rivoplus volumio[3282]: info: sendMpdCommand playlistinfo took 9 milliseconds Jul 08 16:41:14 rivoplus volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jul 08 16:41:14 rivoplus volumio[3282]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jul 08 16:41:14 rivoplus volumio[3282]: info: ------------------------------ 40ms Jul 08 16:41:14 rivoplus volumio[3282]: info: Executing endpoint getStreamUrlqobuz Jul 08 16:41:14 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jul 08 16:41:14 rivoplus volumio[3282]: info: MCU Signalled Playback Inactive Jul 08 16:41:15 rivoplus volumio[3282]: info: getStreamUrl took 458 milliseconds Jul 08 16:41:15 rivoplus volumio[3282]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2904916&eid=40119274&fmt=7&profile=raw&app_id=539451548&cid=2588719&etsp=1751989275&hmac=axv4lHnMEPVn1altcnmctRybWBc Jul 08 16:41:16 rivoplus volumio[3282]: STREAMING PROXY: Response: 200, length: 143728141 Jul 08 16:41:16 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/40119274" Jul 08 16:41:16 rivoplus volumio[3282]: STREAMING PROXY: Client dropped request, destroying Jul 08 16:41:16 rivoplus volumio[3282]: info: Jul 08 16:41:16 rivoplus volumio[3282]: ---------------------------- MPD announces system playlist update Jul 08 16:41:16 rivoplus volumio[3282]: info: Ignoring MPD Status Update Jul 08 16:41:16 rivoplus volumio[3282]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/40119274" took 3 milliseconds Jul 08 16:41:16 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 08 16:41:16 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand play Jul 08 16:41:16 rivoplus volumio[3282]: info: ------------------------------ 4ms Jul 08 16:41:16 rivoplus volumio[3282]: info: sendMpdCommand play took 2 milliseconds Jul 08 16:41:16 rivoplus volumio[3282]: STREAMING PROXY: Handling url /?data=qobuz://song/40119274 Jul 08 16:41:16 rivoplus volumio[3282]: info: Executing endpoint getStreamUrlqobuz Jul 08 16:41:16 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jul 08 16:41:16 rivoplus volumio[3282]: info: getStreamUrl took 483 milliseconds Jul 08 16:41:16 rivoplus volumio[3282]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2904916&eid=40119274&fmt=7&profile=raw&app_id=539451548&cid=2588719&etsp=1751989276&hmac=xVdjDBTLP8V8fuhv3uLiUTqmFjI Jul 08 16:41:16 rivoplus volumio[3282]: STREAMING PROXY: Response: 200, length: 143728141 Jul 08 16:41:16 rivoplus volumio[3282]: info: Jul 08 16:41:16 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:41:16 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:41:16 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:41:16 rivoplus volumio[3282]: info: sendMpdCommand status took 20 milliseconds Jul 08 16:41:16 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:41:16 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 16:41:16 rivoplus volumio[3282]: info: Jul 08 16:41:16 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:41:16 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:41:16 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:41:16 rivoplus volumio[3282]: info: sendMpdCommand playlistinfo took 4 milliseconds Jul 08 16:41:16 rivoplus volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jul 08 16:41:16 rivoplus volumio[3282]: info: ControllerMpd::pushState Jul 08 16:41:16 rivoplus volumio[3282]: info: CoreCommandRouter::servicePushState Jul 08 16:41:16 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 8 Jul 08 16:41:16 rivoplus volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":362,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"40119274","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/40119274","trackType":"qobuz"} Jul 08 16:41:16 rivoplus volumio[3282]: verbose: CURRENT POSITION 8 Jul 08 16:41:16 rivoplus volumio[3282]: info: CoreStateMachine::syncState stateService play Jul 08 16:41:16 rivoplus volumio[3282]: info: CoreStateMachine::syncState currentStatus stop Jul 08 16:41:16 rivoplus volumio[3282]: info: ------------------------------ 35ms Jul 08 16:41:16 rivoplus volumio[3282]: info: sendMpdCommand status took 10 milliseconds Jul 08 16:41:16 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:41:16 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 16:41:16 rivoplus volumio[3282]: info: sendMpdCommand playlistinfo took 5 milliseconds Jul 08 16:41:16 rivoplus volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jul 08 16:41:16 rivoplus volumio[3282]: info: ControllerMpd::pushState Jul 08 16:41:16 rivoplus volumio[3282]: info: CoreCommandRouter::servicePushState Jul 08 16:41:16 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 8 Jul 08 16:41:16 rivoplus volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":362,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"40119274","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/40119274","trackType":"qobuz"} Jul 08 16:41:16 rivoplus volumio[3282]: verbose: CURRENT POSITION 8 Jul 08 16:41:16 rivoplus volumio[3282]: info: CoreStateMachine::syncState stateService play Jul 08 16:41:16 rivoplus volumio[3282]: info: CoreStateMachine::syncState currentStatus play Jul 08 16:41:16 rivoplus volumio[3282]: info: Received an update from plugin. extracting info from payload Jul 08 16:41:16 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:41:16 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 16:41:16 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:41:16 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:41:16 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:41:16 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:41:16 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:41:16 rivoplus volumio[3282]: info: ------------------------------ 51ms Jul 08 16:41:16 rivoplus volumio[3282]: info: Signalling Playback active due to playback status change Jul 08 16:41:16 rivoplus volumio[3282]: info: Signalling Playback active due to playback status change Jul 08 16:41:16 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:41:16 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:41:16 rivoplus volumio[3282]: info: MCU Signalled Playback Active Jul 08 16:41:16 rivoplus volumio[3282]: STREAMING PROXY: Error proxying request: Error: read ECONNRESET Jul 08 16:41:16 rivoplus volumio[3282]: STREAMING PROXY: Client dropped request, destroying Jul 08 16:41:17 rivoplus volumio[3282]: info: Jul 08 16:41:17 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:41:17 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:41:17 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:41:17 rivoplus volumio[3282]: info: sendMpdCommand status took 1 milliseconds Jul 08 16:41:17 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:41:17 rivoplus volumio[3282]: info: ControllerMpd::pushState Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreCommandRouter::servicePushState Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:41:17 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 8 Jul 08 16:41:17 rivoplus volumio[3282]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jul 08 16:41:17 rivoplus volumio[3282]: verbose: CURRENT POSITION 8 Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreStateMachine::syncState stateService stop Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreStateMachine::syncState currentStatus play Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreStateMachine::play index undefined Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:41:17 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 9 Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:41:17 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 9 Jul 08 16:41:17 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 9 Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreStateMachine::startPlaybackTimer Jul 08 16:41:17 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 9 Jul 08 16:41:17 rivoplus volumio[3282]: info: [1751985677047] ControllerQobuz::clearAddPlayTrack Jul 08 16:41:17 rivoplus volumio[3282]: info: ------------------------------ 42ms Jul 08 16:41:17 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand stop Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:41:17 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 9 Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:41:17 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 9 Jul 08 16:41:17 rivoplus volumio[3282]: info: sendMpdCommand stop took 17 milliseconds Jul 08 16:41:17 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand clear Jul 08 16:41:17 rivoplus volumio[3282]: info: Signalling Playback active due to playback status change Jul 08 16:41:17 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:41:17 rivoplus volumio[3282]: info: Jul 08 16:41:17 rivoplus volumio[3282]: ---------------------------- MPD announces system playlist update Jul 08 16:41:17 rivoplus volumio[3282]: info: Ignoring MPD Status Update Jul 08 16:41:17 rivoplus volumio[3282]: info: sendMpdCommand clear took 38 milliseconds Jul 08 16:41:17 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/40119275" Jul 08 16:41:17 rivoplus volumio[3282]: STREAMING PROXY: Handling url /?data=qobuz://song/40119275 Jul 08 16:41:17 rivoplus volumio[3282]: error: updateQueue error: null Jul 08 16:41:17 rivoplus volumio[3282]: info: ------------------------------ 18ms Jul 08 16:41:17 rivoplus volumio[3282]: info: Executing endpoint getStreamUrlqobuz Jul 08 16:41:17 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jul 08 16:41:17 rivoplus volumio[3282]: info: MCU Signalled Playback Inactive Jul 08 16:41:17 rivoplus volumio[3282]: info: getStreamUrl took 452 milliseconds Jul 08 16:41:17 rivoplus volumio[3282]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2904916&eid=40119275&fmt=7&profile=raw&app_id=539451548&cid=2588719&etsp=1751989277&hmac=l7naFYQfPEooy-8E7Q-qH0SgtRE Jul 08 16:41:18 rivoplus volumio[3282]: STREAMING PROXY: Response: 200, length: 92560001 Jul 08 16:41:18 rivoplus volumio[3282]: STREAMING PROXY: Client dropped request, destroying Jul 08 16:41:18 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/40119275" Jul 08 16:41:18 rivoplus volumio[3282]: info: Jul 08 16:41:18 rivoplus volumio[3282]: ---------------------------- MPD announces system playlist update Jul 08 16:41:18 rivoplus volumio[3282]: info: Ignoring MPD Status Update Jul 08 16:41:18 rivoplus volumio[3282]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/40119275" took 2 milliseconds Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 08 16:41:18 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand play Jul 08 16:41:18 rivoplus volumio[3282]: info: ------------------------------ 3ms Jul 08 16:41:18 rivoplus volumio[3282]: info: sendMpdCommand play took 2 milliseconds Jul 08 16:41:18 rivoplus volumio[3282]: STREAMING PROXY: Handling url /?data=qobuz://song/40119275 Jul 08 16:41:18 rivoplus volumio[3282]: info: Executing endpoint getStreamUrlqobuz Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jul 08 16:41:18 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreStateMachine::ClearQueue Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreStateMachine::stop Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:41:18 rivoplus volumio[3282]: info: CorePlayQueue::clearPlayQueue Jul 08 16:41:18 rivoplus volumio[3282]: info: CorePlayQueue::saveQueue Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushQueue Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreStateMachine::addQueueItems Jul 08 16:41:18 rivoplus volumio[3282]: info: CorePlayQueue::addQueueItems Jul 08 16:41:18 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:41:18 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119266 Jul 08 16:41:18 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119266 Jul 08 16:41:18 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119267 Jul 08 16:41:18 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119267 Jul 08 16:41:18 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119268 Jul 08 16:41:18 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119268 Jul 08 16:41:18 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119269 Jul 08 16:41:18 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119269 Jul 08 16:41:18 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119270 Jul 08 16:41:18 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119270 Jul 08 16:41:18 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119271 Jul 08 16:41:18 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119271 Jul 08 16:41:18 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119272 Jul 08 16:41:18 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119272 Jul 08 16:41:18 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119273 Jul 08 16:41:18 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119273 Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushQueue Jul 08 16:41:18 rivoplus volumio[3282]: info: CorePlayQueue::saveQueue Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreStateMachine::updateTrackBlock Jul 08 16:41:18 rivoplus volumio[3282]: info: CorePlayQueue::getTrackBlock Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPlay Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreStateMachine::play index 7 Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreStateMachine::addQueueItems Jul 08 16:41:18 rivoplus volumio[3282]: info: CorePlayQueue::addQueueItems Jul 08 16:41:18 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:41:18 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119274 Jul 08 16:41:18 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119274 Jul 08 16:41:18 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119275 Jul 08 16:41:18 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119275 Jul 08 16:41:18 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119276 Jul 08 16:41:18 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119276 Jul 08 16:41:18 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/40119277 Jul 08 16:41:18 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/40119277 Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreStateMachine::stop Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushQueue Jul 08 16:41:18 rivoplus volumio[3282]: info: CorePlayQueue::saveQueue Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreStateMachine::play index undefined Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreStateMachine::updateTrackBlock Jul 08 16:41:18 rivoplus volumio[3282]: info: CorePlayQueue::getTrackBlock Jul 08 16:41:18 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 7 Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreStateMachine::startPlaybackTimer Jul 08 16:41:18 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 7 Jul 08 16:41:18 rivoplus volumio[3282]: info: [1751985678442] ControllerQobuz::clearAddPlayTrack Jul 08 16:41:18 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand stop Jul 08 16:41:18 rivoplus volumio[3282]: info: Jul 08 16:41:18 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:41:18 rivoplus volumio[3282]: info: sendMpdCommand stop took 11 milliseconds Jul 08 16:41:18 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:41:18 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:41:18 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand clear Jul 08 16:41:18 rivoplus volumio[3282]: info: Jul 08 16:41:18 rivoplus volumio[3282]: ---------------------------- MPD announces system playlist update Jul 08 16:41:18 rivoplus volumio[3282]: info: Ignoring MPD Status Update Jul 08 16:41:18 rivoplus volumio[3282]: info: sendMpdCommand status took 3 milliseconds Jul 08 16:41:18 rivoplus volumio[3282]: info: sendMpdCommand clear took 3 milliseconds Jul 08 16:41:18 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:41:18 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 16:41:18 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/40119273" Jul 08 16:41:18 rivoplus volumio[3282]: error: updateQueue error: null Jul 08 16:41:18 rivoplus volumio[3282]: info: ------------------------------ 5ms Jul 08 16:41:18 rivoplus volumio[3282]: info: sendMpdCommand playlistinfo took 3 milliseconds Jul 08 16:41:18 rivoplus volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jul 08 16:41:18 rivoplus volumio[3282]: STREAMING PROXY: Handling url /?data=qobuz://song/40119273 Jul 08 16:41:18 rivoplus volumio[3282]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jul 08 16:41:18 rivoplus volumio[3282]: info: ------------------------------ 12ms Jul 08 16:41:18 rivoplus volumio[3282]: info: Executing endpoint getStreamUrlqobuz Jul 08 16:41:18 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jul 08 16:41:18 rivoplus volumio[3282]: info: getStreamUrl took 412 milliseconds Jul 08 16:41:18 rivoplus volumio[3282]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2904916&eid=40119275&fmt=7&profile=raw&app_id=539451548&cid=2588719&etsp=1751989278&hmac=5BWriRhRVqomjG_7hf1sygG4n9w Jul 08 16:41:18 rivoplus volumio[3282]: STREAMING PROXY: Response: 200, length: 92560001 Jul 08 16:41:18 rivoplus volumio[3282]: STREAMING PROXY: Error proxying request: Error: read ECONNRESET Jul 08 16:41:18 rivoplus volumio[3282]: info: getStreamUrl took 430 milliseconds Jul 08 16:41:18 rivoplus volumio[3282]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2904916&eid=40119273&fmt=7&profile=raw&app_id=539451548&cid=2588719&etsp=1751989278&hmac=3r77GTstcU42RMw7hvT005doo0w Jul 08 16:41:19 rivoplus volumio[3282]: STREAMING PROXY: Response: 200, length: 117620065 Jul 08 16:41:19 rivoplus volumio[3282]: STREAMING PROXY: Client dropped request, destroying Jul 08 16:41:19 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/40119273" Jul 08 16:41:19 rivoplus volumio[3282]: info: Jul 08 16:41:19 rivoplus volumio[3282]: ---------------------------- MPD announces system playlist update Jul 08 16:41:19 rivoplus volumio[3282]: info: Ignoring MPD Status Update Jul 08 16:41:19 rivoplus volumio[3282]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/40119273" took 2 milliseconds Jul 08 16:41:19 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 08 16:41:19 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand play Jul 08 16:41:19 rivoplus volumio[3282]: info: ------------------------------ 4ms Jul 08 16:41:19 rivoplus volumio[3282]: STREAMING PROXY: Handling url /?data=qobuz://song/40119273 Jul 08 16:41:19 rivoplus volumio[3282]: info: sendMpdCommand play took 3 milliseconds Jul 08 16:41:19 rivoplus volumio[3282]: info: Executing endpoint getStreamUrlqobuz Jul 08 16:41:19 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jul 08 16:41:19 rivoplus volumio[3282]: info: getStreamUrl took 489 milliseconds Jul 08 16:41:19 rivoplus volumio[3282]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2904916&eid=40119273&fmt=7&profile=raw&app_id=539451548&cid=2588719&etsp=1751989279&hmac=0xGvPnviVxwRd72h5Tq6hbqTC54 Jul 08 16:41:19 rivoplus volumio[3282]: STREAMING PROXY: Response: 200, length: 117620065 Jul 08 16:41:19 rivoplus volumio[3282]: info: Jul 08 16:41:19 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:41:19 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:41:19 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:41:19 rivoplus volumio[3282]: info: sendMpdCommand status took 7 milliseconds Jul 08 16:41:19 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:41:19 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 16:41:19 rivoplus volumio[3282]: info: Jul 08 16:41:19 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:41:19 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:41:19 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:41:19 rivoplus volumio[3282]: info: sendMpdCommand playlistinfo took 3 milliseconds Jul 08 16:41:19 rivoplus volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jul 08 16:41:19 rivoplus volumio[3282]: info: ControllerMpd::pushState Jul 08 16:41:19 rivoplus volumio[3282]: info: CoreCommandRouter::servicePushState Jul 08 16:41:19 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 7 Jul 08 16:41:19 rivoplus volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":309,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"40119273","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/40119273","trackType":"qobuz"} Jul 08 16:41:19 rivoplus volumio[3282]: verbose: CURRENT POSITION 7 Jul 08 16:41:19 rivoplus volumio[3282]: info: CoreStateMachine::syncState stateService play Jul 08 16:41:19 rivoplus volumio[3282]: info: CoreStateMachine::syncState currentStatus stop Jul 08 16:41:19 rivoplus volumio[3282]: info: ------------------------------ 16ms Jul 08 16:41:19 rivoplus volumio[3282]: info: sendMpdCommand status took 4 milliseconds Jul 08 16:41:19 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:41:19 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 16:41:19 rivoplus volumio[3282]: info: sendMpdCommand playlistinfo took 1 milliseconds Jul 08 16:41:19 rivoplus volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jul 08 16:41:19 rivoplus volumio[3282]: info: ControllerMpd::pushState Jul 08 16:41:19 rivoplus volumio[3282]: info: CoreCommandRouter::servicePushState Jul 08 16:41:19 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 7 Jul 08 16:41:19 rivoplus volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":309,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"40119273","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/40119273","trackType":"qobuz"} Jul 08 16:41:19 rivoplus volumio[3282]: verbose: CURRENT POSITION 7 Jul 08 16:41:19 rivoplus volumio[3282]: info: CoreStateMachine::syncState stateService play Jul 08 16:41:19 rivoplus volumio[3282]: info: CoreStateMachine::syncState currentStatus play Jul 08 16:41:19 rivoplus volumio[3282]: info: Received an update from plugin. extracting info from payload Jul 08 16:41:19 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:41:19 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 16:41:19 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:41:19 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:41:19 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:41:19 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:41:19 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:41:20 rivoplus volumio[3282]: info: ------------------------------ 36ms Jul 08 16:41:20 rivoplus volumio[3282]: info: Signalling Playback active due to playback status change Jul 08 16:41:20 rivoplus volumio[3282]: info: Signalling Playback active due to playback status change Jul 08 16:41:20 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:41:20 rivoplus volumio[3282]: info: MCU Signalled Playback Active Jul 08 16:41:40 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 08 16:41:40 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 08 16:41:40 rivoplus volumio[3282]: info: Discovery: Getting this device information Jul 08 16:41:40 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:41:40 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 08 16:41:54 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Jul 08 16:41:55 rivoplus volumio[3282]: info: handleBrowseUri took 824 milliseconds Jul 08 16:41:55 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:41:55 rivoplus volumio[3282]: info: Preloading song: qobuz://song/140492615 Jul 08 16:41:55 rivoplus volumio[3282]: info: Preloading song: qobuz://song/140492616 Jul 08 16:41:55 rivoplus volumio[3282]: info: Exploding uri qobuz://song/140492615 in service qobuz Jul 08 16:41:55 rivoplus volumio[3282]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jul 08 16:41:55 rivoplus volumio[3282]: info: Exploding uri qobuz://song/140492616 in service qobuz Jul 08 16:41:55 rivoplus volumio[3282]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jul 08 16:41:55 rivoplus volumio[3282]: info: Executing endpoint getSimilarAlbums Jul 08 16:41:55 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Jul 08 16:41:55 rivoplus volumio[3282]: info: Executing endpoint getSimilarAlbums Jul 08 16:41:55 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Jul 08 16:41:55 rivoplus volumio[3282]: info: Executing endpoint getSimilarAlbums Jul 08 16:41:55 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Jul 08 16:41:55 rivoplus volumio[3282]: info: Executing endpoint metavolumio Jul 08 16:41:55 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 08 16:41:55 rivoplus volumio[3282]: info: Executing endpoint metavolumio Jul 08 16:41:55 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 08 16:41:55 rivoplus volumio[3282]: info: Executing endpoint metavolumio Jul 08 16:41:55 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 08 16:41:56 rivoplus volumio[3282]: info: explodeUri took 741 milliseconds Jul 08 16:41:56 rivoplus volumio[3282]: info: explodeUri took 760 milliseconds Jul 08 16:41:56 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreCommandRouter::volumioReplaceandPlayItems Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::ClearQueue Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::stop Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::stPlaybackTimer Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::updateTrackBlock Jul 08 16:41:56 rivoplus volumio[3282]: info: CorePlayQueue::getTrackBlock Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::pushState Jul 08 16:41:56 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 7 Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushState Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreCommandRouter::volumioGetState Jul 08 16:41:56 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 7 Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::serviceStop Jul 08 16:41:56 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 7 Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreCommandRouter::serviceStop Jul 08 16:41:56 rivoplus volumio[3282]: info: [1751985716742] ControllerQobuz::stop Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 08 16:41:56 rivoplus volumio[3282]: info: ControllerMpd::stop Jul 08 16:41:56 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand stop Jul 08 16:41:56 rivoplus volumio[3282]: info: CorePlayQueue::clearPlayQueue Jul 08 16:41:56 rivoplus volumio[3282]: info: CorePlayQueue::saveQueue Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushQueue Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::addQueueItems Jul 08 16:41:56 rivoplus volumio[3282]: info: CorePlayQueue::addQueueItems Jul 08 16:41:56 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:41:56 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/140492615 Jul 08 16:41:56 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/140492615 Jul 08 16:41:56 rivoplus volumio[3282]: STREAMING PROXY: Client dropped request, destroying Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushQueue Jul 08 16:41:56 rivoplus volumio[3282]: info: CorePlayQueue::saveQueue Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::updateTrackBlock Jul 08 16:41:56 rivoplus volumio[3282]: info: CorePlayQueue::getTrackBlock Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPlay Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::play index 0 Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::addQueueItems Jul 08 16:41:56 rivoplus volumio[3282]: info: CorePlayQueue::addQueueItems Jul 08 16:41:56 rivoplus volumio[3282]: info: Preload queue cleared Jul 08 16:41:56 rivoplus volumio[3282]: info: Adding Item to queue: qobuz://song/140492616 Jul 08 16:41:56 rivoplus volumio[3282]: info: Using cached record of: qobuz://song/140492616 Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::stop Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreCommandRouter::volumioPushQueue Jul 08 16:41:56 rivoplus volumio[3282]: info: CorePlayQueue::saveQueue Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::play index undefined Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::updateTrackBlock Jul 08 16:41:56 rivoplus volumio[3282]: info: CorePlayQueue::getTrackBlock Jul 08 16:41:56 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 0 Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreStateMachine::startPlaybackTimer Jul 08 16:41:56 rivoplus volumio[3282]: info: CorePlayQueue::getTrack 0 Jul 08 16:41:56 rivoplus volumio[3282]: info: [1751985716805] ControllerQobuz::clearAddPlayTrack Jul 08 16:41:56 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand stop Jul 08 16:41:56 rivoplus volumio[3282]: info: Executing endpoint metavolumio Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 08 16:41:56 rivoplus volumio[3282]: info: Updating RAAT Signal Path Jul 08 16:41:56 rivoplus volumio[3282]: info: Jul 08 16:41:56 rivoplus volumio[3282]: ---------------------------- MPD announces state update: player Jul 08 16:41:56 rivoplus volumio[3282]: info: sendMpdCommand stop took 105 milliseconds Jul 08 16:41:56 rivoplus volumio[3282]: info: ControllerMpd::getState Jul 08 16:41:56 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jul 08 16:41:56 rivoplus volumio[3282]: info: sendMpdCommand stop took 43 milliseconds Jul 08 16:41:56 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand clear Jul 08 16:41:56 rivoplus volumio[3282]: info: Jul 08 16:41:56 rivoplus volumio[3282]: ---------------------------- MPD announces system playlist update Jul 08 16:41:56 rivoplus volumio[3282]: info: Ignoring MPD Status Update Jul 08 16:41:56 rivoplus volumio[3282]: info: sendMpdCommand status took 8 milliseconds Jul 08 16:41:56 rivoplus volumio[3282]: info: sendMpdCommand clear took 8 milliseconds Jul 08 16:41:56 rivoplus volumio[3282]: verbose: ControllerMpd::parseState Jul 08 16:41:56 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 08 16:41:56 rivoplus volumio[3282]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/140492615" Jul 08 16:41:56 rivoplus volumio[3282]: error: updateQueue error: null Jul 08 16:41:56 rivoplus volumio[3282]: info: ------------------------------ 8ms Jul 08 16:41:56 rivoplus volumio[3282]: STREAMING PROXY: Handling url /?data=qobuz://song/140492615 Jul 08 16:41:56 rivoplus volumio[3282]: info: sendMpdCommand playlistinfo took 6 milliseconds Jul 08 16:41:56 rivoplus volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jul 08 16:41:56 rivoplus volumio[3282]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jul 08 16:41:56 rivoplus volumio[3282]: info: ------------------------------ 22ms Jul 08 16:41:56 rivoplus volumio[3282]: info: Executing endpoint getStreamUrlqobuz Jul 08 16:41:56 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jul 08 16:41:56 rivoplus volumio[3282]: info: MCU Signalled Playback Inactive Jul 08 16:41:57 rivoplus volumio[3282]: info: Executing endpoint metavolumio Jul 08 16:41:57 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 08 16:41:57 rivoplus volumio[3282]: info: Executing endpoint metavolumio Jul 08 16:41:57 rivoplus volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 08 16:41:57 rivoplus volumio[3282]: info: getStreamUrl took 556 milliseconds Jul 08 16:41:57 rivoplus volumio[3282]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2904916&eid=140492615&fmt=7&profile=raw&app_id=539451548&cid=2588719&etsp=1751989317&hmac=Rhil3s2C-7kqBVkrd53WxCSOkss Jul 08 16:41:58 rivoplus volumio[3282]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 08 16:41:58 rivoplus volumio[3282]: Error: read ECONNRESET Jul 08 16:41:58 rivoplus volumio[3282]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:209:20) { Jul 08 16:41:58 rivoplus volumio[3282]: errno: -104, Jul 08 16:41:58 rivoplus volumio[3282]: code: 'ECONNRESET', Jul 08 16:41:58 rivoplus volumio[3282]: syscall: 'read' Jul 08 16:41:58 rivoplus volumio[3282]: } Jul 08 16:41:58 rivoplus volumio[3282]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 08 16:41:58 rivoplus volumio[3282]: STREAMING PROXY: Response: 200, length: 66341527 Jul 08 16:41:58 rivoplus volumio[3282]: STREAMING PROXY: Client dropped request, destroying Jul 08 16:41:58 rivoplus sudo[5680]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-08 16:40 Jul 08 16:41:58 rivoplus sudo[5680]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="811ff8312d42f9da0260be1d353081a805678820" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 02 Jul 2025 04:55:44 PM CEST" VOLUMIO_VERSION="3.819" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="66719bc94798fca30ca68a8e6d955a83"