-- Logs begin at Mon 2025-03-10 10:09:43 JST, end at Tue 2025-03-11 07:31:52 JST. -- Mar 11 07:30:00 rivoplus volumio[7195]: info: Preload queue cleared Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::ClearQueue Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::stop Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::stPlaybackTimer Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::updateTrackBlock Mar 11 07:30:00 rivoplus volumio[7195]: info: CorePlayQueue::getTrackBlock Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::serviceStop Mar 11 07:30:00 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::serviceStop Mar 11 07:30:00 rivoplus volumio[7195]: info: [1741645800516] ControllerQobuz::stop Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 11 07:30:00 rivoplus volumio[7195]: info: ControllerMpd::stop Mar 11 07:30:00 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand stop Mar 11 07:30:00 rivoplus volumio[7195]: info: CorePlayQueue::clearPlayQueue Mar 11 07:30:00 rivoplus volumio[7195]: info: CorePlayQueue::saveQueue Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushQueue Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::addQueueItems Mar 11 07:30:00 rivoplus volumio[7195]: info: CorePlayQueue::addQueueItems Mar 11 07:30:00 rivoplus volumio[7195]: info: Preload queue cleared Mar 11 07:30:00 rivoplus volumio[7195]: info: Adding Item to queue: qobuz://album/wd9rpsma7bqdc Mar 11 07:30:00 rivoplus volumio[7195]: info: Exploding uri qobuz://album/wd9rpsma7bqdc in service qobuz Mar 11 07:30:00 rivoplus volumio[7195]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 11 07:30:00 rivoplus volumio[7195]: info: Mar 11 07:30:00 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:00 rivoplus volumio[7195]: info: sendMpdCommand stop took 54 milliseconds Mar 11 07:30:00 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:00 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:00 rivoplus volumio[7195]: info: Mar 11 07:30:00 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:00 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:00 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:00 rivoplus volumio[7195]: info: Mar 11 07:30:00 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:00 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:00 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:00 rivoplus volumio[7195]: info: sendMpdCommand status took 7 milliseconds Mar 11 07:30:00 rivoplus volumio[7195]: info: sendMpdCommand status took 6 milliseconds Mar 11 07:30:00 rivoplus volumio[7195]: info: sendMpdCommand status took 5 milliseconds Mar 11 07:30:00 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:00 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:00 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:00 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:00 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:00 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:00 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 11 07:30:00 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 11 07:30:00 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 11 07:30:00 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:00 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:00 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:00 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:00 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"207976222","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/207976222","trackType":"qobuz"} Mar 11 07:30:00 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService stop Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus stop Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:00 rivoplus volumio[7195]: info: No code Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:00 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:00 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"207976222","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/207976222","trackType":"qobuz"} Mar 11 07:30:00 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService stop Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus stop Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:00 rivoplus volumio[7195]: info: No code Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:00 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:00 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"207976222","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/207976222","trackType":"qobuz"} Mar 11 07:30:00 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService stop Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus stop Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:00 rivoplus volumio[7195]: info: No code Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:00 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:00 rivoplus volumio[7195]: info: ------------------------------ 48ms Mar 11 07:30:00 rivoplus volumio[7195]: info: ------------------------------ 48ms Mar 11 07:30:00 rivoplus volumio[7195]: info: ------------------------------ 47ms Mar 11 07:30:00 rivoplus volumio[7195]: info: Signalling Playback active due to playback status change Mar 11 07:30:00 rivoplus volumio[7195]: info: MCU Signalled Playback Inactive Mar 11 07:30:00 rivoplus volumio[7195]: info: MCU Signalled Playback Active Mar 11 07:30:01 rivoplus volumio[7195]: info: explodeUri took 500 milliseconds Mar 11 07:30:01 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushQueue Mar 11 07:30:01 rivoplus volumio[7195]: info: CorePlayQueue::saveQueue Mar 11 07:30:01 rivoplus volumio[7195]: info: CoreStateMachine::updateTrackBlock Mar 11 07:30:01 rivoplus volumio[7195]: info: CorePlayQueue::getTrackBlock Mar 11 07:30:01 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPlay Mar 11 07:30:01 rivoplus volumio[7195]: info: CoreStateMachine::play index 0 Mar 11 07:30:01 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 07:30:01 rivoplus volumio[7195]: info: CoreStateMachine::stop Mar 11 07:30:01 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 07:30:01 rivoplus volumio[7195]: info: CoreStateMachine::play index undefined Mar 11 07:30:01 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 07:30:01 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:01 rivoplus volumio[7195]: info: CoreStateMachine::startPlaybackTimer Mar 11 07:30:01 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:01 rivoplus volumio[7195]: info: [1741645801026] ControllerQobuz::clearAddPlayTrack Mar 11 07:30:01 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand stop Mar 11 07:30:01 rivoplus volumio[7195]: info: sendMpdCommand stop took 4 milliseconds Mar 11 07:30:01 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand clear Mar 11 07:30:01 rivoplus volumio[7195]: info: Mar 11 07:30:01 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:01 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:01 rivoplus volumio[7195]: info: sendMpdCommand clear took 2 milliseconds Mar 11 07:30:01 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/93470622" Mar 11 07:30:01 rivoplus volumio[7195]: info: Mar 11 07:30:01 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:01 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:01 rivoplus volumio[7195]: info: Mar 11 07:30:01 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:01 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:01 rivoplus volumio[7195]: STREAMING PROXY: Handling url /?data=qobuz://song/93470622 Mar 11 07:30:01 rivoplus volumio[7195]: error: updateQueue error: null Mar 11 07:30:01 rivoplus volumio[7195]: info: ------------------------------ 5ms Mar 11 07:30:01 rivoplus volumio[7195]: info: Executing endpoint getStreamUrlqobuz Mar 11 07:30:01 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Mar 11 07:30:01 rivoplus volumio[7195]: info: getStreamUrl took 391 milliseconds Mar 11 07:30:01 rivoplus volumio[7195]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3320215&eid=93470622&fmt=7&profile=raw&range=20-30&app_id=539451548&cid=2382958&etsp=1741649401&hmac=6FCu2DiM4jMpUM0d3Qpv8WOF7Kg Mar 11 07:30:02 rivoplus volumio[7195]: STREAMING PROXY: Response: 200, length: 5571167 Mar 11 07:30:02 rivoplus volumio[7195]: STREAMING PROXY: Client dropped request, destroying Mar 11 07:30:02 rivoplus volumio[7195]: error: updateQueue error: null Mar 11 07:30:02 rivoplus volumio[7195]: error: updateQueue error: null Mar 11 07:30:02 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/93470622" Mar 11 07:30:02 rivoplus volumio[7195]: info: ------------------------------ 1894ms Mar 11 07:30:02 rivoplus volumio[7195]: info: ------------------------------ 1893ms Mar 11 07:30:02 rivoplus volumio[7195]: info: Mar 11 07:30:02 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:02 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:02 rivoplus volumio[7195]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/93470622" took 1 milliseconds Mar 11 07:30:02 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 11 07:30:02 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand play Mar 11 07:30:02 rivoplus volumio[7195]: info: Mar 11 07:30:02 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:02 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:02 rivoplus volumio[7195]: info: Mar 11 07:30:02 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:02 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:02 rivoplus volumio[7195]: STREAMING PROXY: Handling url /?data=qobuz://song/93470622 Mar 11 07:30:02 rivoplus volumio[7195]: info: ------------------------------ 5ms Mar 11 07:30:02 rivoplus volumio[7195]: info: sendMpdCommand play took 4 milliseconds Mar 11 07:30:02 rivoplus volumio[7195]: info: ------------------------------ 4ms Mar 11 07:30:02 rivoplus volumio[7195]: info: ------------------------------ 3ms Mar 11 07:30:02 rivoplus volumio[7195]: info: Executing endpoint getStreamUrlqobuz Mar 11 07:30:02 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Mar 11 07:30:03 rivoplus volumio[7195]: info: getStreamUrl took 387 milliseconds Mar 11 07:30:03 rivoplus volumio[7195]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3320215&eid=93470622&fmt=7&profile=raw&range=20-30&app_id=539451548&cid=2382958&etsp=1741649403&hmac=cKpYMNZGjmPVV6QY0N3STjP-La8 Mar 11 07:30:03 rivoplus volumio[7195]: STREAMING PROXY: Response: 200, length: 5571167 Mar 11 07:30:03 rivoplus volumio[7195]: info: Mar 11 07:30:03 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:03 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:03 rivoplus volumio[7195]: info: Mar 11 07:30:03 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:03 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:03 rivoplus volumio[7195]: info: Mar 11 07:30:03 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:03 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:03 rivoplus volumio[7195]: info: Mar 11 07:30:03 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:03 rivoplus volumio[7195]: info: sendMpdCommand status took 76 milliseconds Mar 11 07:30:03 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:03 rivoplus volumio[7195]: info: sendMpdCommand status took 75 milliseconds Mar 11 07:30:03 rivoplus volumio[7195]: info: sendMpdCommand status took 74 milliseconds Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:03 rivoplus volumio[7195]: info: sendMpdCommand status took 4 milliseconds Mar 11 07:30:03 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 11 07:30:03 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 11 07:30:03 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:03 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:03 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"93470622","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470622","trackType":"qobuz"} Mar 11 07:30:03 rivoplus volumio[7195]: verbose: CURRENT POSITION 0 Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus stop Mar 11 07:30:03 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:03 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"93470622","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470622","trackType":"qobuz"} Mar 11 07:30:03 rivoplus volumio[7195]: verbose: CURRENT POSITION 0 Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:03 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:03 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:03 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"93470622","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470622","trackType":"qobuz"} Mar 11 07:30:03 rivoplus volumio[7195]: verbose: CURRENT POSITION 0 Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:03 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:03 rivoplus volumio[7195]: info: ------------------------------ 99ms Mar 11 07:30:03 rivoplus volumio[7195]: info: ------------------------------ 104ms Mar 11 07:30:03 rivoplus volumio[7195]: info: ------------------------------ 103ms Mar 11 07:30:03 rivoplus volumio[7195]: info: Mar 11 07:30:03 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:03 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:03 rivoplus volumio[7195]: info: Mar 11 07:30:03 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:03 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:03 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 28 milliseconds Mar 11 07:30:03 rivoplus volumio[7195]: info: sendMpdCommand status took 3 milliseconds Mar 11 07:30:03 rivoplus volumio[7195]: info: sendMpdCommand status took 2 milliseconds Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:03 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:03 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"93470622","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470622","trackType":"qobuz"} Mar 11 07:30:03 rivoplus volumio[7195]: verbose: CURRENT POSITION 0 Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:03 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:03 rivoplus volumio[7195]: info: ------------------------------ 47ms Mar 11 07:30:03 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 28 milliseconds Mar 11 07:30:03 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 28 milliseconds Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:03 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:03 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:03 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"93470622","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470622","trackType":"qobuz"} Mar 11 07:30:03 rivoplus volumio[7195]: verbose: CURRENT POSITION 0 Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:03 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:03 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:03 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"93470622","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470622","trackType":"qobuz"} Mar 11 07:30:03 rivoplus volumio[7195]: verbose: CURRENT POSITION 0 Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:03 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:03 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:03 rivoplus volumio[7195]: info: ------------------------------ 49ms Mar 11 07:30:03 rivoplus volumio[7195]: info: ------------------------------ 49ms Mar 11 07:30:04 rivoplus volumio[7195]: STREAMING PROXY: Client dropped request, destroying Mar 11 07:30:11 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 11 07:30:11 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 11 07:30:11 rivoplus volumio[7195]: info: Discovery: Getting this device information Mar 11 07:30:11 rivoplus volumio[7195]: info: CoreCommandRouter::volumioGetState Mar 11 07:30:11 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 11 07:30:33 rivoplus volumio[7195]: info: Mar 11 07:30:33 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:33 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:33 rivoplus volumio[7195]: info: Mar 11 07:30:33 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:33 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:33 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:33 rivoplus volumio[7195]: info: Mar 11 07:30:33 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:33 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:33 rivoplus volumio[7195]: info: Mar 11 07:30:33 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:33 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:33 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:33 rivoplus volumio[7195]: info: Mar 11 07:30:33 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:33 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:33 rivoplus volumio[7195]: info: Mar 11 07:30:33 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:33 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:33 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:33 rivoplus volumio[7195]: error: updateQueue error: null Mar 11 07:30:33 rivoplus volumio[7195]: error: updateQueue error: null Mar 11 07:30:33 rivoplus volumio[7195]: error: updateQueue error: null Mar 11 07:30:33 rivoplus volumio[7195]: info: ------------------------------ 9ms Mar 11 07:30:33 rivoplus volumio[7195]: info: sendMpdCommand status took 7 milliseconds Mar 11 07:30:33 rivoplus volumio[7195]: info: ------------------------------ 8ms Mar 11 07:30:33 rivoplus volumio[7195]: info: sendMpdCommand status took 6 milliseconds Mar 11 07:30:33 rivoplus volumio[7195]: info: ------------------------------ 6ms Mar 11 07:30:33 rivoplus volumio[7195]: info: sendMpdCommand status took 5 milliseconds Mar 11 07:30:33 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:33 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:33 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:33 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:33 rivoplus volumio[7195]: 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} Mar 11 07:30:33 rivoplus volumio[7195]: verbose: CURRENT POSITION 0 Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService stop Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreStateMachine::play index undefined Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:33 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:33 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:33 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:33 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:33 rivoplus volumio[7195]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Mar 11 07:30:33 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:33 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:33 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:33 rivoplus volumio[7195]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Mar 11 07:30:33 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreStateMachine::startPlaybackTimer Mar 11 07:30:33 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:33 rivoplus volumio[7195]: info: [1741645833968] ControllerQobuz::clearAddPlayTrack Mar 11 07:30:33 rivoplus volumio[7195]: info: ------------------------------ 31ms Mar 11 07:30:33 rivoplus volumio[7195]: info: ------------------------------ 30ms Mar 11 07:30:33 rivoplus volumio[7195]: info: ------------------------------ 28ms Mar 11 07:30:33 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand stop Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:33 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:33 rivoplus volumio[7195]: info: sendMpdCommand stop took 6 milliseconds Mar 11 07:30:33 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand clear Mar 11 07:30:33 rivoplus volumio[7195]: info: Mar 11 07:30:33 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:33 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:33 rivoplus volumio[7195]: info: sendMpdCommand clear took 9 milliseconds Mar 11 07:30:33 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/93470623" Mar 11 07:30:33 rivoplus volumio[7195]: info: Mar 11 07:30:33 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:33 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:33 rivoplus volumio[7195]: info: Mar 11 07:30:33 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:33 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:33 rivoplus volumio[7195]: STREAMING PROXY: Handling url /?data=qobuz://song/93470623 Mar 11 07:30:33 rivoplus volumio[7195]: error: updateQueue error: null Mar 11 07:30:33 rivoplus volumio[7195]: info: ------------------------------ 5ms Mar 11 07:30:33 rivoplus volumio[7195]: info: Executing endpoint getStreamUrlqobuz Mar 11 07:30:33 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Mar 11 07:30:34 rivoplus volumio[7195]: info: MCU Signalled Playback Inactive Mar 11 07:30:34 rivoplus volumio[7195]: info: getStreamUrl took 455 milliseconds Mar 11 07:30:34 rivoplus volumio[7195]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3320215&eid=93470623&fmt=7&profile=raw&range=20-30&app_id=539451548&cid=2382958&etsp=1741649434&hmac=Re89OWvawadQ9JHyC8OEIWeeqfU Mar 11 07:30:35 rivoplus volumio[7195]: STREAMING PROXY: Response: 200, length: 4368295 Mar 11 07:30:35 rivoplus volumio[7195]: STREAMING PROXY: Client dropped request, destroying Mar 11 07:30:35 rivoplus volumio[7195]: error: updateQueue error: null Mar 11 07:30:35 rivoplus volumio[7195]: error: updateQueue error: null Mar 11 07:30:35 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/93470623" Mar 11 07:30:35 rivoplus volumio[7195]: info: ------------------------------ 1914ms Mar 11 07:30:35 rivoplus volumio[7195]: info: ------------------------------ 1914ms Mar 11 07:30:35 rivoplus volumio[7195]: info: Mar 11 07:30:35 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:35 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:35 rivoplus volumio[7195]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/93470623" took 2 milliseconds Mar 11 07:30:35 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 11 07:30:35 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand play Mar 11 07:30:35 rivoplus volumio[7195]: info: Mar 11 07:30:35 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:35 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:35 rivoplus volumio[7195]: info: Mar 11 07:30:35 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:35 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:35 rivoplus volumio[7195]: STREAMING PROXY: Handling url /?data=qobuz://song/93470623 Mar 11 07:30:35 rivoplus volumio[7195]: info: ------------------------------ 5ms Mar 11 07:30:35 rivoplus volumio[7195]: info: sendMpdCommand play took 4 milliseconds Mar 11 07:30:35 rivoplus volumio[7195]: info: ------------------------------ 4ms Mar 11 07:30:35 rivoplus volumio[7195]: info: ------------------------------ 3ms Mar 11 07:30:35 rivoplus volumio[7195]: info: Executing endpoint getStreamUrlqobuz Mar 11 07:30:35 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Mar 11 07:30:36 rivoplus volumio[7195]: info: getStreamUrl took 428 milliseconds Mar 11 07:30:36 rivoplus volumio[7195]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3320215&eid=93470623&fmt=7&profile=raw&range=20-30&app_id=539451548&cid=2382958&etsp=1741649436&hmac=4LpzmaMEtssMWbkvypsqQKfWl2Y Mar 11 07:30:36 rivoplus volumio[7195]: STREAMING PROXY: Response: 200, length: 4368295 Mar 11 07:30:36 rivoplus volumio[7195]: info: Mar 11 07:30:36 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:36 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:36 rivoplus volumio[7195]: info: Mar 11 07:30:36 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:36 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:36 rivoplus volumio[7195]: info: Mar 11 07:30:36 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:36 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:36 rivoplus volumio[7195]: info: sendMpdCommand status took 21 milliseconds Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:36 rivoplus volumio[7195]: info: Mar 11 07:30:36 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:36 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:36 rivoplus volumio[7195]: info: sendMpdCommand status took 22 milliseconds Mar 11 07:30:36 rivoplus volumio[7195]: info: sendMpdCommand status took 21 milliseconds Mar 11 07:30:36 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:36 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:36 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"93470623","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470623","trackType":"qobuz"} Mar 11 07:30:36 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus stop Mar 11 07:30:36 rivoplus volumio[7195]: info: ------------------------------ 29ms Mar 11 07:30:36 rivoplus volumio[7195]: info: Mar 11 07:30:36 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:36 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:36 rivoplus volumio[7195]: info: Mar 11 07:30:36 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:36 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:36 rivoplus volumio[7195]: info: sendMpdCommand status took 7 milliseconds Mar 11 07:30:36 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 7 milliseconds Mar 11 07:30:36 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 6 milliseconds Mar 11 07:30:36 rivoplus volumio[7195]: info: sendMpdCommand status took 3 milliseconds Mar 11 07:30:36 rivoplus volumio[7195]: info: sendMpdCommand status took 3 milliseconds Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:36 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:36 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"93470623","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470623","trackType":"qobuz"} Mar 11 07:30:36 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:36 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:36 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:36 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"93470623","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470623","trackType":"qobuz"} Mar 11 07:30:36 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:36 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:36 rivoplus volumio[7195]: info: ------------------------------ 59ms Mar 11 07:30:36 rivoplus volumio[7195]: info: ------------------------------ 58ms Mar 11 07:30:36 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 29 milliseconds Mar 11 07:30:36 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 29 milliseconds Mar 11 07:30:36 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 28 milliseconds Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:36 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:36 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:36 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"93470623","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470623","trackType":"qobuz"} Mar 11 07:30:36 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:36 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:36 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:36 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"93470623","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470623","trackType":"qobuz"} Mar 11 07:30:36 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:36 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:36 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:36 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"93470623","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470623","trackType":"qobuz"} Mar 11 07:30:36 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:36 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:36 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:36 rivoplus volumio[7195]: info: ------------------------------ 68ms Mar 11 07:30:36 rivoplus volumio[7195]: info: ------------------------------ 63ms Mar 11 07:30:36 rivoplus volumio[7195]: info: ------------------------------ 63ms Mar 11 07:30:36 rivoplus volumio[7195]: info: Signalling Playback active due to playback status change Mar 11 07:30:36 rivoplus volumio[7195]: info: MCU Signalled Playback Active Mar 11 07:30:37 rivoplus volumio[7195]: STREAMING PROXY: Client dropped request, destroying Mar 11 07:30:38 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Mar 11 07:30:38 rivoplus volumio[7195]: info: handleBrowseUri took 358 milliseconds Mar 11 07:30:39 rivoplus volumio[7195]: info: Preload queue cleared Mar 11 07:30:39 rivoplus volumio[7195]: info: Preloading song: qobuz://song/93470622 Mar 11 07:30:39 rivoplus volumio[7195]: info: Preloading song: qobuz://song/93470623 Mar 11 07:30:39 rivoplus volumio[7195]: info: Preloading song: qobuz://song/93470624 Mar 11 07:30:39 rivoplus volumio[7195]: info: Preloading song: qobuz://song/93470625 Mar 11 07:30:39 rivoplus volumio[7195]: info: Preloading song: qobuz://song/93470626 Mar 11 07:30:39 rivoplus volumio[7195]: info: Exploding uri qobuz://song/93470622 in service qobuz Mar 11 07:30:39 rivoplus volumio[7195]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 11 07:30:39 rivoplus volumio[7195]: info: Exploding uri qobuz://song/93470623 in service qobuz Mar 11 07:30:39 rivoplus volumio[7195]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 11 07:30:39 rivoplus volumio[7195]: info: No valid Plugin REST Endpoint: getSimilarAlbums Mar 11 07:30:39 rivoplus volumio[7195]: info: No valid Plugin REST Endpoint: getSimilarAlbums Mar 11 07:30:39 rivoplus volumio[7195]: info: Exploding uri qobuz://song/93470624 in service qobuz Mar 11 07:30:39 rivoplus volumio[7195]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 11 07:30:39 rivoplus volumio[7195]: info: Exploding uri qobuz://song/93470625 in service qobuz Mar 11 07:30:39 rivoplus volumio[7195]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 11 07:30:39 rivoplus volumio[7195]: info: Exploding uri qobuz://song/93470626 in service qobuz Mar 11 07:30:39 rivoplus volumio[7195]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 11 07:30:39 rivoplus volumio[7195]: info: explodeUri took 489 milliseconds Mar 11 07:30:39 rivoplus volumio[7195]: info: explodeUri took 456 milliseconds Mar 11 07:30:39 rivoplus volumio[7195]: info: explodeUri took 483 milliseconds Mar 11 07:30:39 rivoplus volumio[7195]: info: explodeUri took 513 milliseconds Mar 11 07:30:39 rivoplus volumio[7195]: info: explodeUri took 457 milliseconds Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 11 07:30:41 rivoplus volumio[7195]: info: Discovery: Getting this device information Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::volumioGetState Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 11 07:30:41 rivoplus volumio[7195]: info: Preload queue cleared Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::ClearQueue Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::stop Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::stPlaybackTimer Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::updateTrackBlock Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::getTrackBlock Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::serviceStop Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::serviceStop Mar 11 07:30:41 rivoplus volumio[7195]: info: [1741645841383] ControllerQobuz::stop Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 11 07:30:41 rivoplus volumio[7195]: info: ControllerMpd::stop Mar 11 07:30:41 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand stop Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::clearPlayQueue Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::saveQueue Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushQueue Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::addQueueItems Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::addQueueItems Mar 11 07:30:41 rivoplus volumio[7195]: info: Preload queue cleared Mar 11 07:30:41 rivoplus volumio[7195]: info: Adding Item to queue: qobuz://song/93470622 Mar 11 07:30:41 rivoplus volumio[7195]: info: Using cached record of: qobuz://song/93470622 Mar 11 07:30:41 rivoplus volumio[7195]: info: Adding Item to queue: qobuz://song/93470623 Mar 11 07:30:41 rivoplus volumio[7195]: info: Using cached record of: qobuz://song/93470623 Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushQueue Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::saveQueue Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::updateTrackBlock Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::getTrackBlock Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPlay Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::play index 1 Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::addQueueItems Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::addQueueItems Mar 11 07:30:41 rivoplus volumio[7195]: info: Preload queue cleared Mar 11 07:30:41 rivoplus volumio[7195]: info: Adding Item to queue: qobuz://song/93470624 Mar 11 07:30:41 rivoplus volumio[7195]: info: Using cached record of: qobuz://song/93470624 Mar 11 07:30:41 rivoplus volumio[7195]: info: Adding Item to queue: qobuz://song/93470625 Mar 11 07:30:41 rivoplus volumio[7195]: info: Using cached record of: qobuz://song/93470625 Mar 11 07:30:41 rivoplus volumio[7195]: info: Adding Item to queue: qobuz://song/93470626 Mar 11 07:30:41 rivoplus volumio[7195]: info: Using cached record of: qobuz://song/93470626 Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::stop Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushQueue Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::saveQueue Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::play index undefined Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::updateTrackBlock Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::getTrackBlock Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::startPlaybackTimer Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:41 rivoplus volumio[7195]: info: [1741645841406] ControllerQobuz::clearAddPlayTrack Mar 11 07:30:41 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand stop Mar 11 07:30:41 rivoplus volumio[7195]: info: Mar 11 07:30:41 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:41 rivoplus volumio[7195]: info: sendMpdCommand stop took 49 milliseconds Mar 11 07:30:41 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:41 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:41 rivoplus volumio[7195]: info: sendMpdCommand stop took 29 milliseconds Mar 11 07:30:41 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand clear Mar 11 07:30:41 rivoplus volumio[7195]: info: Mar 11 07:30:41 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:41 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:41 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:41 rivoplus volumio[7195]: info: Mar 11 07:30:41 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:41 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:41 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:41 rivoplus volumio[7195]: info: Mar 11 07:30:41 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:41 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:41 rivoplus volumio[7195]: info: sendMpdCommand status took 5 milliseconds Mar 11 07:30:41 rivoplus volumio[7195]: info: sendMpdCommand clear took 6 milliseconds Mar 11 07:30:41 rivoplus volumio[7195]: info: sendMpdCommand status took 4 milliseconds Mar 11 07:30:41 rivoplus volumio[7195]: info: sendMpdCommand status took 3 milliseconds Mar 11 07:30:41 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:41 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:41 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/93470623" Mar 11 07:30:41 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:41 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:41 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:41 rivoplus volumio[7195]: STREAMING PROXY: Handling url /?data=qobuz://song/93470623 Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:41 rivoplus volumio[7195]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Mar 11 07:30:41 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:41 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:41 rivoplus volumio[7195]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Mar 11 07:30:41 rivoplus volumio[7195]: info: ------------------------------ 18ms Mar 11 07:30:41 rivoplus volumio[7195]: info: ------------------------------ 18ms Mar 11 07:30:41 rivoplus volumio[7195]: info: Mar 11 07:30:41 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:41 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:41 rivoplus volumio[7195]: info: Mar 11 07:30:41 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:41 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:41 rivoplus volumio[7195]: error: updateQueue error: null Mar 11 07:30:41 rivoplus volumio[7195]: info: ------------------------------ 19ms Mar 11 07:30:41 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 17 milliseconds Mar 11 07:30:41 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:41 rivoplus volumio[7195]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Mar 11 07:30:41 rivoplus volumio[7195]: info: ------------------------------ 27ms Mar 11 07:30:41 rivoplus volumio[7195]: info: Executing endpoint getStreamUrlqobuz Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Mar 11 07:30:41 rivoplus volumio[7195]: info: MCU Signalled Playback Inactive Mar 11 07:30:41 rivoplus volumio[7195]: info: getStreamUrl took 398 milliseconds Mar 11 07:30:41 rivoplus volumio[7195]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3320215&eid=93470623&fmt=7&profile=raw&range=20-30&app_id=539451548&cid=2382958&etsp=1741649441&hmac=S0uAFds6OzyBwxV-8oR786w_tUQ Mar 11 07:30:41 rivoplus volumio[7195]: STREAMING PROXY: Response: 200, length: 4368295 Mar 11 07:30:41 rivoplus volumio[7195]: STREAMING PROXY: Client dropped request, destroying Mar 11 07:30:41 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/93470623" Mar 11 07:30:41 rivoplus volumio[7195]: error: updateQueue error: null Mar 11 07:30:41 rivoplus volumio[7195]: error: updateQueue error: null Mar 11 07:30:41 rivoplus volumio[7195]: info: Mar 11 07:30:41 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:41 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:41 rivoplus volumio[7195]: info: ------------------------------ 450ms Mar 11 07:30:41 rivoplus volumio[7195]: info: ------------------------------ 449ms Mar 11 07:30:41 rivoplus volumio[7195]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/93470623" took 3 milliseconds Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 11 07:30:41 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand play Mar 11 07:30:41 rivoplus volumio[7195]: info: Mar 11 07:30:41 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:41 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:41 rivoplus volumio[7195]: info: Mar 11 07:30:41 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:41 rivoplus volumio[7195]: STREAMING PROXY: Handling url /?data=qobuz://song/93470623 Mar 11 07:30:41 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:41 rivoplus volumio[7195]: info: ------------------------------ 7ms Mar 11 07:30:41 rivoplus volumio[7195]: info: sendMpdCommand play took 5 milliseconds Mar 11 07:30:41 rivoplus volumio[7195]: info: ------------------------------ 5ms Mar 11 07:30:41 rivoplus volumio[7195]: info: ------------------------------ 2ms Mar 11 07:30:41 rivoplus volumio[7195]: info: Executing endpoint getStreamUrlqobuz Mar 11 07:30:41 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Mar 11 07:30:42 rivoplus volumio[7195]: info: getStreamUrl took 399 milliseconds Mar 11 07:30:42 rivoplus volumio[7195]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3320215&eid=93470623&fmt=7&profile=raw&range=20-30&app_id=539451548&cid=2382958&etsp=1741649442&hmac=wPcEg3VkyfOqRqMQ9jUP4SdpkiE Mar 11 07:30:42 rivoplus volumio[7195]: STREAMING PROXY: Response: 200, length: 4368295 Mar 11 07:30:42 rivoplus volumio[7195]: info: Mar 11 07:30:42 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:42 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:42 rivoplus volumio[7195]: info: Mar 11 07:30:42 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:42 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:42 rivoplus volumio[7195]: info: Mar 11 07:30:42 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:42 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:42 rivoplus volumio[7195]: info: Mar 11 07:30:42 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:42 rivoplus volumio[7195]: info: sendMpdCommand status took 36 milliseconds Mar 11 07:30:42 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:42 rivoplus volumio[7195]: info: Mar 11 07:30:42 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:42 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:42 rivoplus volumio[7195]: info: Mar 11 07:30:42 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:42 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:42 rivoplus volumio[7195]: info: sendMpdCommand status took 49 milliseconds Mar 11 07:30:42 rivoplus volumio[7195]: info: sendMpdCommand status took 49 milliseconds Mar 11 07:30:42 rivoplus volumio[7195]: info: sendMpdCommand status took 16 milliseconds Mar 11 07:30:42 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 17 milliseconds Mar 11 07:30:42 rivoplus volumio[7195]: info: sendMpdCommand status took 11 milliseconds Mar 11 07:30:42 rivoplus volumio[7195]: info: sendMpdCommand status took 9 milliseconds Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:42 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:42 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"93470623","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470623","trackType":"qobuz"} Mar 11 07:30:42 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus stop Mar 11 07:30:42 rivoplus volumio[7195]: info: ------------------------------ 69ms Mar 11 07:30:42 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 11 milliseconds Mar 11 07:30:42 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 10 milliseconds Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:42 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:42 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:42 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1216 Kbps","isStreaming":false,"title":"93470623","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470623","trackType":"qobuz"} Mar 11 07:30:42 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:42 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:42 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:42 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":294,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1201 Kbps","isStreaming":false,"title":"93470623","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470623","trackType":"qobuz"} Mar 11 07:30:42 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:42 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:42 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:42 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":315,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1180 Kbps","isStreaming":false,"title":"93470623","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470623","trackType":"qobuz"} Mar 11 07:30:42 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:42 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:42 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:42 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1152 Kbps","isStreaming":false,"title":"93470623","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470623","trackType":"qobuz"} Mar 11 07:30:42 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:42 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:42 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:42 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":30,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1152 Kbps","isStreaming":false,"title":"93470623","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470623","trackType":"qobuz"} Mar 11 07:30:42 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:42 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:42 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:42 rivoplus volumio[7195]: info: ------------------------------ 147ms Mar 11 07:30:42 rivoplus volumio[7195]: info: ------------------------------ 147ms Mar 11 07:30:42 rivoplus volumio[7195]: info: ------------------------------ 115ms Mar 11 07:30:42 rivoplus volumio[7195]: info: ------------------------------ 109ms Mar 11 07:30:42 rivoplus volumio[7195]: info: ------------------------------ 108ms Mar 11 07:30:42 rivoplus volumio[7195]: STREAMING PROXY: Client dropped request, destroying Mar 11 07:30:42 rivoplus volumio[7195]: info: Signalling Playback active due to playback status change Mar 11 07:30:42 rivoplus volumio[7195]: info: MCU Signalled Playback Active Mar 11 07:30:48 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Mar 11 07:30:48 rivoplus volumio[7195]: info: handleBrowseUri took 691 milliseconds Mar 11 07:30:48 rivoplus volumio[7195]: info: Preload queue cleared Mar 11 07:30:48 rivoplus volumio[7195]: info: Preloading song: qobuz://song/16657216 Mar 11 07:30:48 rivoplus volumio[7195]: info: Preloading song: qobuz://song/16657217 Mar 11 07:30:48 rivoplus volumio[7195]: info: Preloading song: qobuz://song/16657218 Mar 11 07:30:48 rivoplus volumio[7195]: info: Preloading song: qobuz://song/16657219 Mar 11 07:30:48 rivoplus volumio[7195]: info: Preloading song: qobuz://song/16657220 Mar 11 07:30:48 rivoplus volumio[7195]: info: Preloading song: qobuz://song/16657221 Mar 11 07:30:48 rivoplus volumio[7195]: info: Preloading song: qobuz://song/16657222 Mar 11 07:30:48 rivoplus volumio[7195]: info: Preloading song: qobuz://song/16657223 Mar 11 07:30:48 rivoplus volumio[7195]: info: Preloading song: qobuz://song/16657224 Mar 11 07:30:49 rivoplus volumio[7195]: info: Exploding uri qobuz://song/16657216 in service qobuz Mar 11 07:30:49 rivoplus volumio[7195]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 11 07:30:49 rivoplus volumio[7195]: info: Exploding uri qobuz://song/16657217 in service qobuz Mar 11 07:30:49 rivoplus volumio[7195]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 11 07:30:49 rivoplus volumio[7195]: info: Exploding uri qobuz://song/16657218 in service qobuz Mar 11 07:30:49 rivoplus volumio[7195]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 11 07:30:49 rivoplus volumio[7195]: info: Exploding uri qobuz://song/16657219 in service qobuz Mar 11 07:30:49 rivoplus volumio[7195]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 11 07:30:49 rivoplus volumio[7195]: info: No valid Plugin REST Endpoint: getSimilarAlbums Mar 11 07:30:49 rivoplus volumio[7195]: info: No valid Plugin REST Endpoint: getSimilarAlbums Mar 11 07:30:49 rivoplus volumio[7195]: info: Exploding uri qobuz://song/16657220 in service qobuz Mar 11 07:30:49 rivoplus volumio[7195]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 11 07:30:49 rivoplus volumio[7195]: info: Exploding uri qobuz://song/16657221 in service qobuz Mar 11 07:30:49 rivoplus volumio[7195]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 11 07:30:49 rivoplus volumio[7195]: info: Exploding uri qobuz://song/16657222 in service qobuz Mar 11 07:30:49 rivoplus volumio[7195]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 11 07:30:49 rivoplus volumio[7195]: info: Exploding uri qobuz://song/16657223 in service qobuz Mar 11 07:30:49 rivoplus volumio[7195]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 11 07:30:49 rivoplus volumio[7195]: info: Exploding uri qobuz://song/16657224 in service qobuz Mar 11 07:30:49 rivoplus volumio[7195]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 11 07:30:49 rivoplus volumio[7195]: info: explodeUri took 440 milliseconds Mar 11 07:30:49 rivoplus volumio[7195]: info: explodeUri took 520 milliseconds Mar 11 07:30:49 rivoplus volumio[7195]: info: explodeUri took 473 milliseconds Mar 11 07:30:49 rivoplus volumio[7195]: info: explodeUri took 473 milliseconds Mar 11 07:30:49 rivoplus volumio[7195]: info: explodeUri took 444 milliseconds Mar 11 07:30:49 rivoplus volumio[7195]: info: explodeUri took 481 milliseconds Mar 11 07:30:49 rivoplus volumio[7195]: info: explodeUri took 460 milliseconds Mar 11 07:30:49 rivoplus volumio[7195]: info: explodeUri took 437 milliseconds Mar 11 07:30:49 rivoplus volumio[7195]: info: explodeUri took 488 milliseconds Mar 11 07:30:50 rivoplus volumio[7195]: info: Preload queue cleared Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::ClearQueue Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::stop Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::stPlaybackTimer Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::updateTrackBlock Mar 11 07:30:50 rivoplus volumio[7195]: info: CorePlayQueue::getTrackBlock Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::serviceStop Mar 11 07:30:50 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::serviceStop Mar 11 07:30:50 rivoplus volumio[7195]: info: [1741645850643] ControllerQobuz::stop Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 11 07:30:50 rivoplus volumio[7195]: info: ControllerMpd::stop Mar 11 07:30:50 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand stop Mar 11 07:30:50 rivoplus volumio[7195]: info: CorePlayQueue::clearPlayQueue Mar 11 07:30:50 rivoplus volumio[7195]: info: CorePlayQueue::saveQueue Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushQueue Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::addQueueItems Mar 11 07:30:50 rivoplus volumio[7195]: info: CorePlayQueue::addQueueItems Mar 11 07:30:50 rivoplus volumio[7195]: info: Preload queue cleared Mar 11 07:30:50 rivoplus volumio[7195]: info: Adding Item to queue: qobuz://album/0060253780526 Mar 11 07:30:50 rivoplus volumio[7195]: info: Exploding uri qobuz://album/0060253780526 in service qobuz Mar 11 07:30:50 rivoplus volumio[7195]: https://prod.vlmapi.io/v2/qobuz/explodeUri Mar 11 07:30:50 rivoplus volumio[7195]: info: Mar 11 07:30:50 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:50 rivoplus volumio[7195]: info: sendMpdCommand stop took 37 milliseconds Mar 11 07:30:50 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:50 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:50 rivoplus volumio[7195]: info: sendMpdCommand status took 1 milliseconds Mar 11 07:30:50 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:50 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:50 rivoplus volumio[7195]: info: Mar 11 07:30:50 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:50 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:50 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:50 rivoplus volumio[7195]: info: Mar 11 07:30:50 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:50 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:50 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:50 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 10 milliseconds Mar 11 07:30:50 rivoplus volumio[7195]: info: sendMpdCommand status took 10 milliseconds Mar 11 07:30:50 rivoplus volumio[7195]: info: sendMpdCommand status took 8 milliseconds Mar 11 07:30:50 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:50 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:50 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:50 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:50 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:50 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:50 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"93470623","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470623","trackType":"qobuz"} Mar 11 07:30:50 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService stop Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus stop Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:50 rivoplus volumio[7195]: info: No code Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:50 rivoplus volumio[7195]: info: ------------------------------ 29ms Mar 11 07:30:50 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 16 milliseconds Mar 11 07:30:50 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 17 milliseconds Mar 11 07:30:50 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:50 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:50 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:50 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"93470623","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470623","trackType":"qobuz"} Mar 11 07:30:50 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService stop Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus stop Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:50 rivoplus volumio[7195]: info: No code Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:50 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 1 Mar 11 07:30:50 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"93470623","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/93470623","trackType":"qobuz"} Mar 11 07:30:50 rivoplus volumio[7195]: verbose: CURRENT POSITION 1 Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService stop Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus stop Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:50 rivoplus volumio[7195]: info: No code Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:50 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:50 rivoplus volumio[7195]: info: ------------------------------ 56ms Mar 11 07:30:50 rivoplus volumio[7195]: info: ------------------------------ 55ms Mar 11 07:30:50 rivoplus volumio[7195]: info: Signalling Playback active due to playback status change Mar 11 07:30:50 rivoplus volumio[7195]: info: MCU Signalled Playback Inactive Mar 11 07:30:50 rivoplus volumio[7195]: info: MCU Signalled Playback Active Mar 11 07:30:51 rivoplus volumio[7195]: info: explodeUri took 362 milliseconds Mar 11 07:30:51 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushQueue Mar 11 07:30:51 rivoplus volumio[7195]: info: CorePlayQueue::saveQueue Mar 11 07:30:51 rivoplus volumio[7195]: info: CoreStateMachine::updateTrackBlock Mar 11 07:30:51 rivoplus volumio[7195]: info: CorePlayQueue::getTrackBlock Mar 11 07:30:51 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPlay Mar 11 07:30:51 rivoplus volumio[7195]: info: CoreStateMachine::play index 0 Mar 11 07:30:51 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 07:30:51 rivoplus volumio[7195]: info: CoreStateMachine::stop Mar 11 07:30:51 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 07:30:51 rivoplus volumio[7195]: info: CoreStateMachine::play index undefined Mar 11 07:30:51 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 11 07:30:51 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:51 rivoplus volumio[7195]: info: CoreStateMachine::startPlaybackTimer Mar 11 07:30:51 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:51 rivoplus volumio[7195]: info: [1741645851018] ControllerQobuz::clearAddPlayTrack Mar 11 07:30:51 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand stop Mar 11 07:30:51 rivoplus volumio[7195]: info: sendMpdCommand stop took 4 milliseconds Mar 11 07:30:51 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand clear Mar 11 07:30:51 rivoplus volumio[7195]: info: Mar 11 07:30:51 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:51 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:51 rivoplus volumio[7195]: info: sendMpdCommand clear took 2 milliseconds Mar 11 07:30:51 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/16657216" Mar 11 07:30:51 rivoplus volumio[7195]: info: Mar 11 07:30:51 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:51 rivoplus volumio[7195]: STREAMING PROXY: Handling url /?data=qobuz://song/16657216 Mar 11 07:30:51 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:51 rivoplus volumio[7195]: info: Mar 11 07:30:51 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:51 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:51 rivoplus volumio[7195]: error: updateQueue error: null Mar 11 07:30:51 rivoplus volumio[7195]: info: ------------------------------ 6ms Mar 11 07:30:51 rivoplus volumio[7195]: info: Executing endpoint getStreamUrlqobuz Mar 11 07:30:51 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Mar 11 07:30:51 rivoplus volumio[7195]: info: getStreamUrl took 398 milliseconds Mar 11 07:30:51 rivoplus volumio[7195]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3320215&eid=16657216&fmt=7&profile=raw&app_id=539451548&cid=2382958&etsp=1741649451&hmac=2AHqCDn2s8tfQJil8n4MicB4VqY Mar 11 07:30:53 rivoplus volumio[7195]: STREAMING PROXY: Response: 200, length: 168239217 Mar 11 07:30:53 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/16657216" Mar 11 07:30:53 rivoplus volumio[7195]: STREAMING PROXY: Client dropped request, destroying Mar 11 07:30:53 rivoplus volumio[7195]: error: updateQueue error: null Mar 11 07:30:53 rivoplus volumio[7195]: info: Mar 11 07:30:53 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:53 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:53 rivoplus volumio[7195]: info: ------------------------------ 2916ms Mar 11 07:30:53 rivoplus volumio[7195]: info: ------------------------------ 2914ms Mar 11 07:30:53 rivoplus volumio[7195]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/16657216" took 2 milliseconds Mar 11 07:30:53 rivoplus volumio[7195]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 11 07:30:53 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand play Mar 11 07:30:53 rivoplus volumio[7195]: info: Mar 11 07:30:53 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:53 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:53 rivoplus volumio[7195]: info: Mar 11 07:30:53 rivoplus volumio[7195]: ---------------------------- MPD announces system playlist update Mar 11 07:30:53 rivoplus volumio[7195]: STREAMING PROXY: Handling url /?data=qobuz://song/16657216 Mar 11 07:30:53 rivoplus volumio[7195]: info: Ignoring MPD Status Update Mar 11 07:30:53 rivoplus volumio[7195]: info: ------------------------------ 7ms Mar 11 07:30:53 rivoplus volumio[7195]: info: sendMpdCommand play took 6 milliseconds Mar 11 07:30:53 rivoplus volumio[7195]: info: ------------------------------ 5ms Mar 11 07:30:53 rivoplus volumio[7195]: info: ------------------------------ 3ms Mar 11 07:30:53 rivoplus volumio[7195]: info: Executing endpoint getStreamUrlqobuz Mar 11 07:30:53 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Mar 11 07:30:54 rivoplus volumio[7195]: info: getStreamUrl took 382 milliseconds Mar 11 07:30:54 rivoplus volumio[7195]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3320215&eid=16657216&fmt=7&profile=raw&app_id=539451548&cid=2382958&etsp=1741649454&hmac=1m3ql74WT7dROohFTN9Min0r1QM Mar 11 07:30:54 rivoplus volumio[7195]: STREAMING PROXY: Response: 200, length: 168239217 Mar 11 07:30:54 rivoplus volumio[7195]: info: Mar 11 07:30:54 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:54 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:54 rivoplus volumio[7195]: info: Mar 11 07:30:54 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:54 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:54 rivoplus volumio[7195]: info: Mar 11 07:30:54 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:54 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:54 rivoplus volumio[7195]: info: Mar 11 07:30:54 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:54 rivoplus volumio[7195]: info: sendMpdCommand status took 86 milliseconds Mar 11 07:30:54 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:54 rivoplus volumio[7195]: info: sendMpdCommand status took 85 milliseconds Mar 11 07:30:54 rivoplus volumio[7195]: info: sendMpdCommand status took 83 milliseconds Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:54 rivoplus volumio[7195]: info: sendMpdCommand status took 6 milliseconds Mar 11 07:30:54 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 11 07:30:54 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 4 milliseconds Mar 11 07:30:54 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:54 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:54 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":619,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16657216","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/16657216","trackType":"qobuz"} Mar 11 07:30:54 rivoplus volumio[7195]: verbose: CURRENT POSITION 0 Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus stop Mar 11 07:30:54 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:54 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":619,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16657216","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/16657216","trackType":"qobuz"} Mar 11 07:30:54 rivoplus volumio[7195]: verbose: CURRENT POSITION 0 Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:54 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:54 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:54 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":619,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16657216","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/16657216","trackType":"qobuz"} Mar 11 07:30:54 rivoplus volumio[7195]: verbose: CURRENT POSITION 0 Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:54 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:54 rivoplus volumio[7195]: info: ------------------------------ 108ms Mar 11 07:30:54 rivoplus volumio[7195]: info: ------------------------------ 112ms Mar 11 07:30:54 rivoplus volumio[7195]: info: ------------------------------ 111ms Mar 11 07:30:54 rivoplus volumio[7195]: info: Mar 11 07:30:54 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:54 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:54 rivoplus volumio[7195]: info: Mar 11 07:30:54 rivoplus volumio[7195]: ---------------------------- MPD announces state update: player Mar 11 07:30:54 rivoplus volumio[7195]: info: ControllerMpd::getState Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand status Mar 11 07:30:54 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 30 milliseconds Mar 11 07:30:54 rivoplus volumio[7195]: info: sendMpdCommand status took 4 milliseconds Mar 11 07:30:54 rivoplus volumio[7195]: info: sendMpdCommand status took 2 milliseconds Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::parseState Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 11 07:30:54 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:54 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":619,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16657216","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/16657216","trackType":"qobuz"} Mar 11 07:30:54 rivoplus volumio[7195]: verbose: CURRENT POSITION 0 Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:54 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:54 rivoplus volumio[7195]: info: ------------------------------ 50ms Mar 11 07:30:54 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 29 milliseconds Mar 11 07:30:54 rivoplus volumio[7195]: info: sendMpdCommand playlistinfo took 30 milliseconds Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:54 rivoplus volumio[7195]: verbose: ControllerMpd::parseTrackInfo Mar 11 07:30:54 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:54 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":619,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16657216","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/16657216","trackType":"qobuz"} Mar 11 07:30:54 rivoplus volumio[7195]: verbose: CURRENT POSITION 0 Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:54 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:54 rivoplus volumio[7195]: info: ControllerMpd::pushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::servicePushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CorePlayQueue::getTrack 0 Mar 11 07:30:54 rivoplus volumio[7195]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":619,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"16657216","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/16657216","trackType":"qobuz"} Mar 11 07:30:54 rivoplus volumio[7195]: verbose: CURRENT POSITION 0 Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::syncState stateService play Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::syncState currentStatus play Mar 11 07:30:54 rivoplus volumio[7195]: info: Received an update from plugin. extracting info from payload Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreStateMachine::pushState Mar 11 07:30:54 rivoplus volumio[7195]: info: CoreCommandRouter::volumioPushState Mar 11 07:30:54 rivoplus volumio[7195]: info: ------------------------------ 57ms Mar 11 07:30:54 rivoplus volumio[7195]: info: ------------------------------ 53ms Mar 11 07:31:11 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 11 07:31:11 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 11 07:31:11 rivoplus volumio[7195]: info: Discovery: Getting this device information Mar 11 07:31:11 rivoplus volumio[7195]: info: CoreCommandRouter::volumioGetState Mar 11 07:31:11 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 11 07:31:37 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Mar 11 07:31:37 rivoplus volumio[7195]: info: handleBrowseUri took 358 milliseconds Mar 11 07:31:38 rivoplus volumio[7195]: info: Preload queue cleared Mar 11 07:31:38 rivoplus volumio[7195]: info: No valid Plugin REST Endpoint: getSimilarAlbums Mar 11 07:31:38 rivoplus volumio[7195]: info: No valid Plugin REST Endpoint: getSimilarAlbums Mar 11 07:31:41 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 11 07:31:41 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 11 07:31:41 rivoplus volumio[7195]: info: Discovery: Getting this device information Mar 11 07:31:41 rivoplus volumio[7195]: info: CoreCommandRouter::volumioGetState Mar 11 07:31:41 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 11 07:31:46 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Mar 11 07:31:46 rivoplus volumio[7195]: info: handleBrowseUri took 133 milliseconds Mar 11 07:31:46 rivoplus volumio[7195]: info: Preload queue cleared Mar 11 07:31:46 rivoplus volumio[7195]: info: Preload queue cleared Mar 11 07:31:52 rivoplus volumio[7195]: info: CoreCommandRouter::executeOnPlugin: metavolumio , superSearch Mar 11 07:31:52 rivoplus volumio[7195]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 11 07:31:52 rivoplus volumio[7195]: TypeError: Cannot read property 'then' of undefined Mar 11 07:31:52 rivoplus volumio[7195]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:498:20) Mar 11 07:31:52 rivoplus volumio[7195]: at Socket.emit (events.js:400:28) Mar 11 07:31:52 rivoplus volumio[7195]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Mar 11 07:31:52 rivoplus volumio[7195]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Mar 11 07:31:52 rivoplus volumio[7195]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 11 07:31:52 rivoplus sudo[18833]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-11 07:30 Mar 11 07:31:52 rivoplus sudo[18833]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 12:29:52 PM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="c26baf739f7d1f3fe648e6cf51b2c348"