-- Logs begin at Sun 2025-06-22 08:09:07 JST, end at Sun 2025-06-22 11:26:46 JST. -- Jun 22 11:25:04 rivo volumio[3093]: STREAMING PROXY: Client dropped request, destroying Jun 22 11:25:12 rivo volumio[3093]: info: CoreCommandRouter::volumioNext Jun 22 11:25:12 rivo volumio[3093]: info: CoreStateMachine::next Jun 22 11:25:12 rivo volumio[3093]: info: [1750559112987] ControllerQobuz::next Jun 22 11:25:12 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 22 11:25:12 rivo volumio[3093]: info: CoreStateMachine::next Jun 22 11:25:12 rivo volumio[3093]: info: CoreStateMachine::stop Jun 22 11:25:12 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 22 11:25:12 rivo volumio[3093]: info: CoreStateMachine::stPlaybackTimer Jun 22 11:25:12 rivo volumio[3093]: info: CoreStateMachine::updateTrackBlock Jun 22 11:25:12 rivo volumio[3093]: info: CorePlayQueue::getTrackBlock Jun 22 11:25:12 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:12 rivo volumio[3093]: info: CorePlayQueue::getTrack 5 Jun 22 11:25:12 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 22 11:25:12 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:12 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:12 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:12 rivo volumio[3093]: info: CoreStateMachine::serviceStop Jun 22 11:25:12 rivo volumio[3093]: info: CorePlayQueue::getTrack 5 Jun 22 11:25:12 rivo volumio[3093]: info: CoreCommandRouter::serviceStop Jun 22 11:25:12 rivo volumio[3093]: info: [1750559112997] ControllerQobuz::stop Jun 22 11:25:12 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 22 11:25:12 rivo volumio[3093]: info: ControllerMpd::stop Jun 22 11:25:12 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand stop Jun 22 11:25:13 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:13 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback disable Jun 22 11:25:13 rivo kernel: spdif_a keep clk continuous Jun 22 11:25:13 rivo kernel: aml_spdif_close Jun 22 11:25:13 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 22 11:25:13 rivo volumio[3093]: info: Jun 22 11:25:13 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:13 rivo volumio[3093]: info: sendMpdCommand stop took 50 milliseconds Jun 22 11:25:13 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:13 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:13 rivo volumio[3093]: info: CoreStateMachine::play index undefined Jun 22 11:25:13 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 22 11:25:13 rivo volumio[3093]: info: CorePlayQueue::getTrack 56 Jun 22 11:25:13 rivo volumio[3093]: info: CoreStateMachine::startPlaybackTimer Jun 22 11:25:13 rivo volumio[3093]: info: CorePlayQueue::getTrack 56 Jun 22 11:25:13 rivo volumio[3093]: info: [1750559113048] ControllerQobuz::clearAddPlayTrack Jun 22 11:25:13 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand stop Jun 22 11:25:13 rivo volumio[3093]: info: CoreStateMachine::updateTrackBlock Jun 22 11:25:13 rivo volumio[3093]: info: CorePlayQueue::getTrackBlock Jun 22 11:25:13 rivo volumio[3093]: info: Jun 22 11:25:13 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:13 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:13 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:13 rivo volumio[3093]: info: Jun 22 11:25:13 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:13 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:13 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:13 rivo volumio[3093]: info: sendMpdCommand status took 12 milliseconds Jun 22 11:25:13 rivo volumio[3093]: info: sendMpdCommand stop took 11 milliseconds Jun 22 11:25:13 rivo volumio[3093]: info: sendMpdCommand status took 9 milliseconds Jun 22 11:25:13 rivo volumio[3093]: info: sendMpdCommand status took 2 milliseconds Jun 22 11:25:13 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:13 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:25:13 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand clear Jun 22 11:25:13 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:13 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:25:13 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:13 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:25:13 rivo volumio[3093]: info: Jun 22 11:25:13 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:25:13 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:25:13 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 4 milliseconds Jun 22 11:25:13 rivo volumio[3093]: info: sendMpdCommand clear took 4 milliseconds Jun 22 11:25:13 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 4 milliseconds Jun 22 11:25:13 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 3 milliseconds Jun 22 11:25:13 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:25:13 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/33912398" Jun 22 11:25:13 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:25:13 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:25:13 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:25:13 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:25:13 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:13 rivo volumio[3093]: info: CorePlayQueue::getTrack 56 Jun 22 11:25:13 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 22 11:25:13 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:13 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:13 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:13 rivo volumio[3093]: info: CorePlayQueue::getTrack 56 Jun 22 11:25:13 rivo volumio[3093]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jun 22 11:25:13 rivo volumio[3093]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jun 22 11:25:13 rivo volumio[3093]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jun 22 11:25:13 rivo volumio[3093]: STREAMING PROXY: Handling url /?data=qobuz://song/33912398 Jun 22 11:25:13 rivo volumio[3093]: info: ------------------------------ 37ms Jun 22 11:25:13 rivo volumio[3093]: info: ------------------------------ 33ms Jun 22 11:25:13 rivo volumio[3093]: info: ------------------------------ 32ms Jun 22 11:25:13 rivo volumio[3093]: info: Jun 22 11:25:13 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:25:13 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:25:13 rivo volumio[3093]: info: Jun 22 11:25:13 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:25:13 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:25:13 rivo volumio[3093]: error: updateQueue error: null Jun 22 11:25:13 rivo volumio[3093]: info: ------------------------------ 27ms Jun 22 11:25:13 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:13 rivo volumio[3093]: info: MCU Signalled Playback Inactive Jun 22 11:25:13 rivo volumio[3093]: info: Executing endpoint getStreamUrlqobuz Jun 22 11:25:13 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jun 22 11:25:13 rivo volumio[3093]: info: getStreamUrl took 413 milliseconds Jun 22 11:25:13 rivo volumio[3093]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3516194&eid=33912398&fmt=6&profile=raw&app_id=539451548&cid=2515659&etsp=1750562713&hmac=ylh6S3TWLSR08DQM3QWtNNi-dTc Jun 22 11:25:15 rivo volumio[3093]: STREAMING PROXY: Response: 200, length: 26337529 Jun 22 11:25:15 rivo volumio[3093]: STREAMING PROXY: Client dropped request, destroying Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/33912398" Jun 22 11:25:15 rivo volumio[3093]: error: updateQueue error: null Jun 22 11:25:15 rivo volumio[3093]: error: updateQueue error: null Jun 22 11:25:15 rivo volumio[3093]: info: Jun 22 11:25:15 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:25:15 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:25:15 rivo volumio[3093]: info: ------------------------------ 2020ms Jun 22 11:25:15 rivo volumio[3093]: info: ------------------------------ 2019ms Jun 22 11:25:15 rivo volumio[3093]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/33912398" took 2 milliseconds Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand play Jun 22 11:25:15 rivo volumio[3093]: info: Jun 22 11:25:15 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:25:15 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:25:15 rivo volumio[3093]: info: Jun 22 11:25:15 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:25:15 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:25:15 rivo volumio[3093]: STREAMING PROXY: Handling url /?data=qobuz://song/33912398 Jun 22 11:25:15 rivo volumio[3093]: info: ------------------------------ 5ms Jun 22 11:25:15 rivo volumio[3093]: info: sendMpdCommand play took 4 milliseconds Jun 22 11:25:15 rivo volumio[3093]: info: ------------------------------ 4ms Jun 22 11:25:15 rivo volumio[3093]: Upnp client error: Error: read ECONNRESET Jun 22 11:25:15 rivo volumio[3093]: info: ------------------------------ 7ms Jun 22 11:25:15 rivo volumio[3093]: info: Executing endpoint getStreamUrlqobuz Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jun 22 11:25:15 rivo volumio[3093]: info: getStreamUrl took 401 milliseconds Jun 22 11:25:15 rivo volumio[3093]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3516194&eid=33912398&fmt=6&profile=raw&app_id=539451548&cid=2515659&etsp=1750562715&hmac=5PWKObNuVIztBT9lwEx7fzPtESk Jun 22 11:25:15 rivo volumio[3093]: STREAMING PROXY: Response: 200, length: 26337529 Jun 22 11:25:15 rivo kernel: aml_spdif_open Jun 22 11:25:15 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 22 11:25:15 rivo kernel: set normal 512 fs /4 fs Jun 22 11:25:15 rivo kernel: set spdifout clk:5644800, mpll:22579200 Jun 22 11:25:15 rivo kernel: get spdifout clk:5644797, mpll:22579186 Jun 22 11:25:15 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Jun 22 11:25:15 rivo kernel: set normal 512 fs /4 fs Jun 22 11:25:15 rivo kernel: set spdifout clk:5644800, mpll:22579200 Jun 22 11:25:15 rivo kernel: get spdifout clk:5644797, mpll:22579186 Jun 22 11:25:15 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Jun 22 11:25:15 rivo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Jun 22 11:25:15 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Jun 22 11:25:15 rivo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Jun 22 11:25:15 rivo volumio[3093]: info: Jun 22 11:25:15 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:15 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:15 rivo volumio[3093]: info: Jun 22 11:25:15 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:15 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:15 rivo volumio[3093]: info: Jun 22 11:25:15 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:15 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:15 rivo volumio[3093]: info: Jun 22 11:25:15 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:15 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:15 rivo volumio[3093]: info: sendMpdCommand status took 6 milliseconds Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:25:15 rivo volumio[3093]: info: Jun 22 11:25:15 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:15 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:15 rivo volumio[3093]: info: Jun 22 11:25:15 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:15 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:15 rivo volumio[3093]: info: sendMpdCommand status took 16 milliseconds Jun 22 11:25:15 rivo volumio[3093]: info: sendMpdCommand status took 14 milliseconds Jun 22 11:25:15 rivo volumio[3093]: info: sendMpdCommand status took 13 milliseconds Jun 22 11:25:15 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 12 milliseconds Jun 22 11:25:15 rivo volumio[3093]: info: sendMpdCommand status took 8 milliseconds Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:25:15 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:25:15 rivo volumio[3093]: info: CorePlayQueue::getTrack 56 Jun 22 11:25:15 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":231,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"33912398","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/33912398","trackType":"qobuz"} Jun 22 11:25:15 rivo volumio[3093]: verbose: CURRENT POSITION 56 Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus stop Jun 22 11:25:15 rivo volumio[3093]: info: ------------------------------ 25ms Jun 22 11:25:15 rivo volumio[3093]: info: sendMpdCommand status took 13 milliseconds Jun 22 11:25:15 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 22 11:25:15 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 6 milliseconds Jun 22 11:25:15 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:25:15 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:25:15 rivo volumio[3093]: info: CorePlayQueue::getTrack 56 Jun 22 11:25:15 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":231,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"33912398","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/33912398","trackType":"qobuz"} Jun 22 11:25:15 rivo volumio[3093]: verbose: CURRENT POSITION 56 Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus play Jun 22 11:25:15 rivo volumio[3093]: info: Received an update from plugin. extracting info from payload Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:15 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:25:15 rivo volumio[3093]: info: CorePlayQueue::getTrack 56 Jun 22 11:25:15 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1121,"duration":231,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"629 Kbps","isStreaming":false,"title":"33912398","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/33912398","trackType":"qobuz"} Jun 22 11:25:15 rivo volumio[3093]: verbose: CURRENT POSITION 56 Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus play Jun 22 11:25:15 rivo volumio[3093]: info: Received an update from plugin. extracting info from payload Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:15 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:25:15 rivo volumio[3093]: info: CorePlayQueue::getTrack 56 Jun 22 11:25:15 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1121,"duration":231,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"629 Kbps","isStreaming":false,"title":"33912398","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/33912398","trackType":"qobuz"} Jun 22 11:25:15 rivo volumio[3093]: verbose: CURRENT POSITION 56 Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus play Jun 22 11:25:15 rivo volumio[3093]: info: Received an update from plugin. extracting info from payload Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:15 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:25:15 rivo volumio[3093]: info: CorePlayQueue::getTrack 56 Jun 22 11:25:15 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1121,"duration":231,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"629 Kbps","isStreaming":false,"title":"33912398","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/33912398","trackType":"qobuz"} Jun 22 11:25:15 rivo volumio[3093]: verbose: CURRENT POSITION 56 Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus play Jun 22 11:25:15 rivo volumio[3093]: info: Received an update from plugin. extracting info from payload Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:15 rivo volumio[3093]: info: ------------------------------ 83ms Jun 22 11:25:15 rivo volumio[3093]: info: ------------------------------ 82ms Jun 22 11:25:15 rivo volumio[3093]: info: ------------------------------ 81ms Jun 22 11:25:15 rivo volumio[3093]: info: ------------------------------ 77ms Jun 22 11:25:15 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 63 milliseconds Jun 22 11:25:15 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:25:15 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:25:15 rivo volumio[3093]: info: CorePlayQueue::getTrack 56 Jun 22 11:25:15 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1121,"duration":231,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"629 Kbps","isStreaming":false,"title":"33912398","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/33912398","trackType":"qobuz"} Jun 22 11:25:15 rivo volumio[3093]: verbose: CURRENT POSITION 56 Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus play Jun 22 11:25:15 rivo volumio[3093]: info: Received an update from plugin. extracting info from payload Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:15 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:15 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:15 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:15 rivo volumio[3093]: info: ------------------------------ 93ms Jun 22 11:25:15 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:15 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:15 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:15 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:15 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:15 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:15 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:15 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:15 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:15 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:15 rivo volumio[3093]: info: Signalling Playback active due to playback status change Jun 22 11:25:15 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Jun 22 11:25:15 rivo volumio[3093]: info: MCU Signalled Playback Active Jun 22 11:25:18 rivo volumio[3093]: info: CoreCommandRouter::volumioNext Jun 22 11:25:18 rivo volumio[3093]: info: CoreStateMachine::next Jun 22 11:25:18 rivo volumio[3093]: info: [1750559118405] ControllerQobuz::next Jun 22 11:25:18 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 22 11:25:18 rivo volumio[3093]: info: CoreStateMachine::next Jun 22 11:25:18 rivo volumio[3093]: info: CoreStateMachine::stop Jun 22 11:25:18 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 22 11:25:18 rivo volumio[3093]: info: CoreStateMachine::stPlaybackTimer Jun 22 11:25:18 rivo volumio[3093]: info: CoreStateMachine::updateTrackBlock Jun 22 11:25:18 rivo volumio[3093]: info: CorePlayQueue::getTrackBlock Jun 22 11:25:18 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:18 rivo volumio[3093]: info: CorePlayQueue::getTrack 56 Jun 22 11:25:18 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 22 11:25:18 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:18 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:18 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:18 rivo volumio[3093]: info: CoreStateMachine::serviceStop Jun 22 11:25:18 rivo volumio[3093]: info: CorePlayQueue::getTrack 56 Jun 22 11:25:18 rivo volumio[3093]: info: CoreCommandRouter::serviceStop Jun 22 11:25:18 rivo volumio[3093]: info: [1750559118419] ControllerQobuz::stop Jun 22 11:25:18 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 22 11:25:18 rivo volumio[3093]: info: ControllerMpd::stop Jun 22 11:25:18 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand stop Jun 22 11:25:18 rivo volumio[3093]: STREAMING PROXY: Client dropped request, destroying Jun 22 11:25:18 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:18 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback disable Jun 22 11:25:18 rivo kernel: spdif_a keep clk continuous Jun 22 11:25:18 rivo kernel: aml_spdif_close Jun 22 11:25:18 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 22 11:25:18 rivo volumio[3093]: info: sendMpdCommand stop took 25 milliseconds Jun 22 11:25:18 rivo volumio[3093]: info: CoreStateMachine::play index undefined Jun 22 11:25:18 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 22 11:25:18 rivo volumio[3093]: info: CorePlayQueue::getTrack 20 Jun 22 11:25:18 rivo volumio[3093]: info: CoreStateMachine::startPlaybackTimer Jun 22 11:25:18 rivo volumio[3093]: info: CorePlayQueue::getTrack 20 Jun 22 11:25:18 rivo volumio[3093]: info: [1750559118446] ControllerQobuz::clearAddPlayTrack Jun 22 11:25:18 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand stop Jun 22 11:25:18 rivo volumio[3093]: info: CoreStateMachine::updateTrackBlock Jun 22 11:25:18 rivo volumio[3093]: info: CorePlayQueue::getTrackBlock Jun 22 11:25:18 rivo volumio[3093]: info: Jun 22 11:25:18 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:18 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:18 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:18 rivo volumio[3093]: info: sendMpdCommand stop took 2 milliseconds Jun 22 11:25:18 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand clear Jun 22 11:25:18 rivo volumio[3093]: info: Jun 22 11:25:18 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:18 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:18 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:18 rivo volumio[3093]: info: Jun 22 11:25:18 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:18 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:18 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:18 rivo volumio[3093]: info: Jun 22 11:25:18 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:25:18 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:25:18 rivo volumio[3093]: info: sendMpdCommand status took 5 milliseconds Jun 22 11:25:18 rivo volumio[3093]: info: sendMpdCommand clear took 5 milliseconds Jun 22 11:25:18 rivo volumio[3093]: info: sendMpdCommand status took 4 milliseconds Jun 22 11:25:18 rivo volumio[3093]: info: sendMpdCommand status took 2 milliseconds Jun 22 11:25:18 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:18 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:25:18 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/4539656" Jun 22 11:25:18 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:18 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:25:18 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:25:18 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:18 rivo volumio[3093]: info: CorePlayQueue::getTrack 20 Jun 22 11:25:18 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 22 11:25:18 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:18 rivo volumio[3093]: STREAMING PROXY: Handling url /?data=qobuz://song/4539656 Jun 22 11:25:18 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:18 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:18 rivo volumio[3093]: info: CorePlayQueue::getTrack 20 Jun 22 11:25:18 rivo volumio[3093]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jun 22 11:25:18 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:25:18 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:25:18 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:18 rivo volumio[3093]: info: CorePlayQueue::getTrack 20 Jun 22 11:25:18 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:18 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:18 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:18 rivo volumio[3093]: info: CorePlayQueue::getTrack 20 Jun 22 11:25:18 rivo volumio[3093]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jun 22 11:25:18 rivo volumio[3093]: info: ------------------------------ 25ms Jun 22 11:25:18 rivo volumio[3093]: info: ------------------------------ 25ms Jun 22 11:25:18 rivo volumio[3093]: info: Jun 22 11:25:18 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:25:18 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:25:18 rivo volumio[3093]: info: Jun 22 11:25:18 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:25:18 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:25:18 rivo volumio[3093]: error: updateQueue error: null Jun 22 11:25:18 rivo volumio[3093]: info: ------------------------------ 30ms Jun 22 11:25:18 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 29 milliseconds Jun 22 11:25:18 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:25:18 rivo volumio[3093]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jun 22 11:25:18 rivo volumio[3093]: info: ------------------------------ 38ms Jun 22 11:25:18 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:18 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:18 rivo volumio[3093]: info: Executing endpoint getStreamUrlqobuz Jun 22 11:25:18 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jun 22 11:25:18 rivo volumio[3093]: info: MCU Signalled Playback Inactive Jun 22 11:25:18 rivo volumio[3093]: info: getStreamUrl took 416 milliseconds Jun 22 11:25:18 rivo volumio[3093]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3516194&eid=4539656&fmt=6&profile=raw&app_id=539451548&cid=2515659&etsp=1750562718&hmac=zKTPi3cHDS5BxbSqC8ek4kwGtiQ Jun 22 11:25:20 rivo volumio[3093]: STREAMING PROXY: Response: 200, length: 29860905 Jun 22 11:25:20 rivo volumio[3093]: STREAMING PROXY: Client dropped request, destroying Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/4539656" Jun 22 11:25:20 rivo volumio[3093]: error: updateQueue error: null Jun 22 11:25:20 rivo volumio[3093]: error: updateQueue error: null Jun 22 11:25:20 rivo volumio[3093]: info: Jun 22 11:25:20 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:25:20 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:25:20 rivo volumio[3093]: info: ------------------------------ 2031ms Jun 22 11:25:20 rivo volumio[3093]: info: ------------------------------ 2029ms Jun 22 11:25:20 rivo volumio[3093]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/4539656" took 3 milliseconds Jun 22 11:25:20 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand play Jun 22 11:25:20 rivo volumio[3093]: Upnp client error: Error: This socket has been ended by the other party Jun 22 11:25:20 rivo volumio[3093]: info: Jun 22 11:25:20 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:25:20 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:25:20 rivo volumio[3093]: STREAMING PROXY: Handling url /?data=qobuz://song/4539656 Jun 22 11:25:20 rivo volumio[3093]: info: Jun 22 11:25:20 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:25:20 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:25:20 rivo volumio[3093]: info: ------------------------------ 6ms Jun 22 11:25:20 rivo volumio[3093]: info: sendMpdCommand play took 6 milliseconds Jun 22 11:25:20 rivo volumio[3093]: info: ------------------------------ 4ms Jun 22 11:25:20 rivo volumio[3093]: info: ------------------------------ 2ms Jun 22 11:25:20 rivo volumio[3093]: info: Executing endpoint getStreamUrlqobuz Jun 22 11:25:20 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jun 22 11:25:20 rivo volumio[3093]: info: getStreamUrl took 389 milliseconds Jun 22 11:25:20 rivo volumio[3093]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3516194&eid=4539656&fmt=6&profile=raw&app_id=539451548&cid=2515659&etsp=1750562720&hmac=uFIuubsNkb4SMAnRPkm_txIJa6E Jun 22 11:25:20 rivo volumio[3093]: STREAMING PROXY: Response: 200, length: 29860905 Jun 22 11:25:20 rivo kernel: aml_spdif_open Jun 22 11:25:20 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 22 11:25:20 rivo volumio[3093]: info: Jun 22 11:25:20 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:20 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:20 rivo volumio[3093]: info: Jun 22 11:25:20 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:20 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:20 rivo kernel: set normal 512 fs /4 fs Jun 22 11:25:20 rivo kernel: set spdifout clk:5644800, mpll:22579200 Jun 22 11:25:20 rivo kernel: get spdifout clk:5644797, mpll:22579186 Jun 22 11:25:20 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Jun 22 11:25:20 rivo kernel: set normal 512 fs /4 fs Jun 22 11:25:20 rivo kernel: set spdifout clk:5644800, mpll:22579200 Jun 22 11:25:20 rivo kernel: get spdifout clk:5644797, mpll:22579186 Jun 22 11:25:20 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Jun 22 11:25:20 rivo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Jun 22 11:25:20 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Jun 22 11:25:20 rivo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Jun 22 11:25:20 rivo volumio[3093]: info: Jun 22 11:25:20 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:20 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:20 rivo volumio[3093]: info: Jun 22 11:25:20 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:20 rivo volumio[3093]: info: sendMpdCommand status took 4 milliseconds Jun 22 11:25:20 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:20 rivo volumio[3093]: info: sendMpdCommand status took 4 milliseconds Jun 22 11:25:20 rivo volumio[3093]: info: sendMpdCommand status took 2 milliseconds Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:25:20 rivo volumio[3093]: info: Jun 22 11:25:20 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:20 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:20 rivo volumio[3093]: info: Jun 22 11:25:20 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:25:20 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:25:20 rivo volumio[3093]: info: sendMpdCommand status took 15 milliseconds Jun 22 11:25:20 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 14 milliseconds Jun 22 11:25:20 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 13 milliseconds Jun 22 11:25:20 rivo volumio[3093]: info: sendMpdCommand status took 4 milliseconds Jun 22 11:25:20 rivo volumio[3093]: info: sendMpdCommand status took 3 milliseconds Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:20 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:25:21 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:25:21 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:25:21 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:25:21 rivo volumio[3093]: info: CorePlayQueue::getTrack 20 Jun 22 11:25:21 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":252,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"4539656","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/4539656","trackType":"qobuz"} Jun 22 11:25:21 rivo volumio[3093]: verbose: CURRENT POSITION 20 Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus stop Jun 22 11:25:21 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:25:21 rivo volumio[3093]: info: CorePlayQueue::getTrack 20 Jun 22 11:25:21 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":252,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"4539656","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/4539656","trackType":"qobuz"} Jun 22 11:25:21 rivo volumio[3093]: verbose: CURRENT POSITION 20 Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus play Jun 22 11:25:21 rivo volumio[3093]: info: Received an update from plugin. extracting info from payload Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:21 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:25:21 rivo volumio[3093]: info: CorePlayQueue::getTrack 20 Jun 22 11:25:21 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":252,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"4539656","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/4539656","trackType":"qobuz"} Jun 22 11:25:21 rivo volumio[3093]: verbose: CURRENT POSITION 20 Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus play Jun 22 11:25:21 rivo volumio[3093]: info: Received an update from plugin. extracting info from payload Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:21 rivo volumio[3093]: info: ------------------------------ 40ms Jun 22 11:25:21 rivo volumio[3093]: info: ------------------------------ 67ms Jun 22 11:25:21 rivo volumio[3093]: info: ------------------------------ 66ms Jun 22 11:25:21 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 49 milliseconds Jun 22 11:25:21 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 48 milliseconds Jun 22 11:25:21 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 49 milliseconds Jun 22 11:25:21 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:25:21 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:25:21 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:25:21 rivo volumio[3093]: info: CorePlayQueue::getTrack 20 Jun 22 11:25:21 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":252,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"4539656","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/4539656","trackType":"qobuz"} Jun 22 11:25:21 rivo volumio[3093]: verbose: CURRENT POSITION 20 Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus play Jun 22 11:25:21 rivo volumio[3093]: info: Received an update from plugin. extracting info from payload Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:21 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:25:21 rivo volumio[3093]: info: CorePlayQueue::getTrack 20 Jun 22 11:25:21 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1121,"duration":252,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"621 Kbps","isStreaming":false,"title":"4539656","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/4539656","trackType":"qobuz"} Jun 22 11:25:21 rivo volumio[3093]: verbose: CURRENT POSITION 20 Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus play Jun 22 11:25:21 rivo volumio[3093]: info: Received an update from plugin. extracting info from payload Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:21 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:25:21 rivo volumio[3093]: info: CorePlayQueue::getTrack 20 Jun 22 11:25:21 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1121,"duration":252,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"621 Kbps","isStreaming":false,"title":"4539656","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/4539656","trackType":"qobuz"} Jun 22 11:25:21 rivo volumio[3093]: verbose: CURRENT POSITION 20 Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus play Jun 22 11:25:21 rivo volumio[3093]: info: Received an update from plugin. extracting info from payload Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:21 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:25:21 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:25:21 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:25:21 rivo volumio[3093]: info: ------------------------------ 110ms Jun 22 11:25:21 rivo volumio[3093]: info: ------------------------------ 107ms Jun 22 11:25:21 rivo volumio[3093]: info: ------------------------------ 98ms Jun 22 11:25:21 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:21 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:21 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:21 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:21 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:21 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:21 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:21 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:21 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:21 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:25:21 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Jun 22 11:25:21 rivo volumio[3093]: info: Signalling Playback active due to playback status change Jun 22 11:25:21 rivo volumio[3093]: info: MCU Signalled Playback Active Jun 22 11:25:24 rivo volumio[3093]: STREAMING PROXY: Client dropped request, destroying Jun 22 11:25:27 rivo volumio[3093]: info: CoreCommandRouter::volumioGetState Jun 22 11:25:28 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 22 11:25:28 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 22 11:25:28 rivo volumio[3093]: info: Discovery: Getting this device information Jun 22 11:25:28 rivo volumio[3093]: info: CoreCommandRouter::volumioGetState Jun 22 11:25:28 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 22 11:25:29 rivo volumio[3093]: info: Executing endpoint metavolumio Jun 22 11:25:29 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 22 11:25:29 rivo volumio[3093]: info: Executing endpoint metavolumio Jun 22 11:25:29 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 22 11:25:29 rivo volumio[3093]: info: Executing endpoint metavolumio Jun 22 11:25:29 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 22 11:25:58 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 22 11:25:58 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 22 11:25:58 rivo volumio[3093]: info: Discovery: Getting this device information Jun 22 11:25:58 rivo volumio[3093]: info: CoreCommandRouter::volumioGetState Jun 22 11:25:58 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 22 11:26:06 rivo volumio[3093]: info: CorePlayQueue::getTrack 20 Jun 22 11:26:06 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: qobuz , goto Jun 22 11:26:06 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:06 rivo volumio[3093]: info: Executing endpoint metavolumio Jun 22 11:26:06 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 22 11:26:06 rivo volumio[3093]: info: explodeUri took 377 milliseconds Jun 22 11:26:07 rivo volumio[3093]: info: handleBrowseUri took 1281 milliseconds Jun 22 11:26:08 rivo volumio[3093]: info: Executing endpoint getSimilarArtists Jun 22 11:26:08 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Jun 22 11:26:08 rivo volumio[3093]: info: Executing endpoint getSimilarArtists Jun 22 11:26:08 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Jun 22 11:26:08 rivo volumio[3093]: info: Executing endpoint getSimilarArtists Jun 22 11:26:08 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Jun 22 11:26:08 rivo volumio[3093]: info: Executing endpoint getSimilarArtists Jun 22 11:26:08 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Jun 22 11:26:08 rivo volumio[3093]: info: Executing endpoint getSimilarArtists Jun 22 11:26:08 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Jun 22 11:26:09 rivo volumio[3093]: info: Executing endpoint getSimilarArtists Jun 22 11:26:09 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Jun 22 11:26:14 rivo volumio[3093]: info: Executing endpoint getSimilarArtists Jun 22 11:26:14 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Jun 22 11:26:14 rivo volumio[3093]: info: Executing endpoint getSimilarArtists Jun 22 11:26:14 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Jun 22 11:26:14 rivo volumio[3093]: info: Executing endpoint metavolumio Jun 22 11:26:14 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 22 11:26:18 rivo volumio[3093]: error: Failed request for metavolumio API Jun 22 11:26:24 rivo volumio[3093]: info: CoreCommandRouter::volumioGetState Jun 22 11:26:26 rivo volumio[3093]: info: Executing endpoint metavolumio Jun 22 11:26:26 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 22 11:26:26 rivo volumio[3093]: info: Executing endpoint metavolumio Jun 22 11:26:26 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 22 11:26:26 rivo volumio[3093]: info: Executing endpoint metavolumio Jun 22 11:26:26 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 22 11:26:26 rivo volumio[3093]: info: Executing endpoint metavolumio Jun 22 11:26:26 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 22 11:26:27 rivo volumio[3093]: error: Failed request for metavolumio API Jun 22 11:26:27 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Jun 22 11:26:27 rivo volumio[3093]: info: handleBrowseUri took 149 milliseconds Jun 22 11:26:27 rivo volumio[3093]: info: Preload queue cleared Jun 22 11:26:27 rivo volumio[3093]: info: Preload queue cleared Jun 22 11:26:27 rivo volumio[3093]: error: Failed request for metavolumio API Jun 22 11:26:28 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 22 11:26:28 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 22 11:26:28 rivo volumio[3093]: info: Discovery: Getting this device information Jun 22 11:26:28 rivo volumio[3093]: info: CoreCommandRouter::volumioGetState Jun 22 11:26:28 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 22 11:26:29 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Jun 22 11:26:29 rivo volumio[3093]: info: handleBrowseUri took 667 milliseconds Jun 22 11:26:29 rivo volumio[3093]: info: Preload queue cleared Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/314987059 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/53768212 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/168839412 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/199468357 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/178610962 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/188769508 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/47886309 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/163497669 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/329331941 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/28520146 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/13204923 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/121872260 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/194363575 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/98920782 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/44059398 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/211818606 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/296007669 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/313481418 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/81035645 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/196016517 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/196816961 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/314504626 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/260275740 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/3957120 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/127323775 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/641947 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/127404148 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/66798141 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/314007447 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/60339561 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/91451723 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/38992373 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/104605104 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/128906807 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/2133088 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/281596467 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/175971951 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/251430307 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/1020021 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/84982386 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/4621816 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/52594147 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/22136764 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/45715266 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/635536 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/196016523 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/196016633 Jun 22 11:26:29 rivo volumio[3093]: info: Preloading song: qobuz://song/126443492 Jun 22 11:26:29 rivo volumio[3093]: info: Exploding uri qobuz://song/314987059 in service qobuz Jun 22 11:26:29 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/53768212 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/168839412 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/199468357 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/178610962 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/188769508 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/47886309 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/163497669 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/329331941 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/28520146 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: explodeUri took 465 milliseconds Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/13204923 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: explodeUri took 456 milliseconds Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/121872260 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: explodeUri took 473 milliseconds Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/194363575 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: explodeUri took 468 milliseconds Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/98920782 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: explodeUri took 468 milliseconds Jun 22 11:26:30 rivo volumio[3093]: info: explodeUri took 447 milliseconds Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/44059398 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: explodeUri took 418 milliseconds Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/211818606 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: explodeUri took 450 milliseconds Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/296007669 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: explodeUri took 448 milliseconds Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/313481418 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/81035645 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: explodeUri took 454 milliseconds Jun 22 11:26:30 rivo volumio[3093]: info: explodeUri took 440 milliseconds Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/196016517 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:30 rivo volumio[3093]: info: Exploding uri qobuz://song/196816961 in service qobuz Jun 22 11:26:30 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/314504626 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 463 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 545 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/260275740 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 490 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 451 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/3957120 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/127323775 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 468 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/641947 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 479 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/127404148 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 491 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 446 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/66798141 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 436 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/314007447 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/60339561 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 456 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/91451723 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 468 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 429 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/38992373 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/104605104 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 491 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/128906807 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 454 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/2133088 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 469 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/281596467 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 457 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 446 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/175971951 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/251430307 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 464 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 441 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/1020021 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 449 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/84982386 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:31 rivo volumio[3093]: info: explodeUri took 432 milliseconds Jun 22 11:26:31 rivo volumio[3093]: info: Exploding uri qobuz://song/4621816 in service qobuz Jun 22 11:26:31 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:32 rivo volumio[3093]: info: Exploding uri qobuz://song/52594147 in service qobuz Jun 22 11:26:32 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:32 rivo volumio[3093]: info: explodeUri took 475 milliseconds Jun 22 11:26:32 rivo volumio[3093]: info: explodeUri took 429 milliseconds Jun 22 11:26:32 rivo volumio[3093]: info: Exploding uri qobuz://song/22136764 in service qobuz Jun 22 11:26:32 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:32 rivo volumio[3093]: info: explodeUri took 430 milliseconds Jun 22 11:26:32 rivo volumio[3093]: info: Exploding uri qobuz://song/45715266 in service qobuz Jun 22 11:26:32 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:32 rivo volumio[3093]: info: Exploding uri qobuz://song/635536 in service qobuz Jun 22 11:26:32 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:32 rivo volumio[3093]: info: explodeUri took 454 milliseconds Jun 22 11:26:32 rivo volumio[3093]: info: explodeUri took 427 milliseconds Jun 22 11:26:32 rivo volumio[3093]: info: Exploding uri qobuz://song/196016523 in service qobuz Jun 22 11:26:32 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:32 rivo volumio[3093]: info: explodeUri took 443 milliseconds Jun 22 11:26:32 rivo volumio[3093]: info: Exploding uri qobuz://song/196016633 in service qobuz Jun 22 11:26:32 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:32 rivo volumio[3093]: info: explodeUri took 450 milliseconds Jun 22 11:26:32 rivo volumio[3093]: info: Exploding uri qobuz://song/126443492 in service qobuz Jun 22 11:26:32 rivo volumio[3093]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jun 22 11:26:32 rivo volumio[3093]: info: explodeUri took 447 milliseconds Jun 22 11:26:32 rivo volumio[3093]: info: explodeUri took 456 milliseconds Jun 22 11:26:32 rivo volumio[3093]: info: explodeUri took 426 milliseconds Jun 22 11:26:32 rivo volumio[3093]: info: explodeUri took 453 milliseconds Jun 22 11:26:32 rivo volumio[3093]: info: explodeUri took 425 milliseconds Jun 22 11:26:32 rivo volumio[3093]: info: explodeUri took 424 milliseconds Jun 22 11:26:32 rivo volumio[3093]: info: explodeUri took 433 milliseconds Jun 22 11:26:32 rivo volumio[3093]: info: explodeUri took 442 milliseconds Jun 22 11:26:32 rivo volumio[3093]: info: explodeUri took 446 milliseconds Jun 22 11:26:36 rivo volumio[3093]: info: Preload queue cleared Jun 22 11:26:36 rivo volumio[3093]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::ClearQueue Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::stop Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::stPlaybackTimer Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::updateTrackBlock Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::getTrackBlock Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::getTrack 20 Jun 22 11:26:36 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 22 11:26:36 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:26:36 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:26:36 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::serviceStop Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::getTrack 20 Jun 22 11:26:36 rivo volumio[3093]: info: CoreCommandRouter::serviceStop Jun 22 11:26:36 rivo volumio[3093]: info: [1750559196290] ControllerQobuz::stop Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 22 11:26:36 rivo volumio[3093]: info: ControllerMpd::stop Jun 22 11:26:36 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand stop Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::clearPlayQueue Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::saveQueue Jun 22 11:26:36 rivo volumio[3093]: info: CoreCommandRouter::volumioPushQueue Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::addQueueItems Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::addQueueItems Jun 22 11:26:36 rivo volumio[3093]: info: Preload queue cleared Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/314987059 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/314987059 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/53768212 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/53768212 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/168839412 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/168839412 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/199468357 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/199468357 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/178610962 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/178610962 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/188769508 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/188769508 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/47886309 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/47886309 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/163497669 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/163497669 Jun 22 11:26:36 rivo volumio[3093]: info: CoreCommandRouter::volumioPushQueue Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::saveQueue Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::updateTrackBlock Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::getTrackBlock Jun 22 11:26:36 rivo volumio[3093]: info: CoreCommandRouter::volumioPlay Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::play index 7 Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::addQueueItems Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::addQueueItems Jun 22 11:26:36 rivo volumio[3093]: info: Preload queue cleared Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/329331941 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/329331941 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/28520146 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/28520146 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/13204923 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/13204923 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/121872260 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/121872260 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/194363575 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/194363575 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/98920782 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/98920782 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/44059398 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/44059398 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/211818606 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/211818606 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/296007669 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/296007669 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/313481418 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/313481418 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/81035645 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/81035645 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/196016517 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/196016517 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/196816961 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/196816961 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/314504626 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/314504626 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/260275740 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/260275740 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/3957120 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/3957120 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/127323775 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/127323775 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/641947 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/641947 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/127404148 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/127404148 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/66798141 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/66798141 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/314007447 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/314007447 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/60339561 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/60339561 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/91451723 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/91451723 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/38992373 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/38992373 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/104605104 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/104605104 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/128906807 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/128906807 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/2133088 Jun 22 11:26:36 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback disable Jun 22 11:26:36 rivo kernel: spdif_a keep clk continuous Jun 22 11:26:36 rivo kernel: aml_spdif_close Jun 22 11:26:36 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/2133088 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/281596467 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/281596467 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/175971951 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/175971951 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/251430307 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/251430307 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/1020021 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/1020021 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/84982386 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/84982386 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/4621816 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/4621816 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/52594147 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/52594147 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/22136764 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/22136764 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/45715266 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/45715266 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/635536 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/635536 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/196016523 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/196016523 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/196016633 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/196016633 Jun 22 11:26:36 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/126443492 Jun 22 11:26:36 rivo volumio[3093]: info: Using cached record of: qobuz://song/126443492 Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::stop Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 22 11:26:36 rivo volumio[3093]: info: CoreCommandRouter::volumioPushQueue Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::saveQueue Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::play index undefined Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::updateTrackBlock Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::getTrackBlock Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::getTrack 7 Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::startPlaybackTimer Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::getTrack 7 Jun 22 11:26:36 rivo volumio[3093]: info: [1750559196341] ControllerQobuz::clearAddPlayTrack Jun 22 11:26:36 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand stop Jun 22 11:26:36 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:26:36 rivo volumio[3093]: info: Jun 22 11:26:36 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:26:36 rivo volumio[3093]: info: sendMpdCommand stop took 76 milliseconds Jun 22 11:26:36 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:26:36 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:26:36 rivo volumio[3093]: info: sendMpdCommand stop took 25 milliseconds Jun 22 11:26:36 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand clear Jun 22 11:26:36 rivo volumio[3093]: info: Jun 22 11:26:36 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:26:36 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:26:36 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:26:36 rivo volumio[3093]: info: Jun 22 11:26:36 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:26:36 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:26:36 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:26:36 rivo volumio[3093]: info: Jun 22 11:26:36 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:26:36 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:26:36 rivo volumio[3093]: info: sendMpdCommand status took 10 milliseconds Jun 22 11:26:36 rivo volumio[3093]: info: sendMpdCommand clear took 9 milliseconds Jun 22 11:26:36 rivo volumio[3093]: info: sendMpdCommand status took 8 milliseconds Jun 22 11:26:36 rivo volumio[3093]: info: sendMpdCommand status took 7 milliseconds Jun 22 11:26:36 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:26:36 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:26:36 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/163497669" Jun 22 11:26:36 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:26:36 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:26:36 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:26:36 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::getTrack 7 Jun 22 11:26:36 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 22 11:26:36 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:26:36 rivo volumio[3093]: STREAMING PROXY: Handling url /?data=qobuz://song/163497669 Jun 22 11:26:36 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:26:36 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::getTrack 7 Jun 22 11:26:36 rivo volumio[3093]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jun 22 11:26:36 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:26:36 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:26:36 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::getTrack 7 Jun 22 11:26:36 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:26:36 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:26:36 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:26:36 rivo volumio[3093]: info: CorePlayQueue::getTrack 7 Jun 22 11:26:36 rivo volumio[3093]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jun 22 11:26:36 rivo volumio[3093]: info: ------------------------------ 31ms Jun 22 11:26:36 rivo volumio[3093]: info: ------------------------------ 30ms Jun 22 11:26:36 rivo volumio[3093]: info: Jun 22 11:26:36 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:26:36 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:26:36 rivo volumio[3093]: info: Jun 22 11:26:36 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:26:36 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:26:36 rivo volumio[3093]: error: updateQueue error: null Jun 22 11:26:36 rivo volumio[3093]: info: ------------------------------ 34ms Jun 22 11:26:36 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 32 milliseconds Jun 22 11:26:36 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:26:36 rivo volumio[3093]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jun 22 11:26:36 rivo volumio[3093]: info: ------------------------------ 46ms Jun 22 11:26:36 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:26:36 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:26:36 rivo volumio[3093]: info: Executing endpoint getStreamUrlqobuz Jun 22 11:26:36 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jun 22 11:26:36 rivo volumio[3093]: info: MCU Signalled Playback Inactive Jun 22 11:26:36 rivo volumio[3093]: info: getStreamUrl took 385 milliseconds Jun 22 11:26:36 rivo volumio[3093]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3516194&eid=163497669&fmt=6&profile=raw&app_id=539451548&cid=2515659&etsp=1750562796&hmac=0Uq9clK2Grj6pTg77OraTS7hqA8 Jun 22 11:26:38 rivo volumio[3093]: STREAMING PROXY: Response: 200, length: 25918075 Jun 22 11:26:38 rivo volumio[3093]: STREAMING PROXY: Client dropped request, destroying Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/163497669" Jun 22 11:26:38 rivo volumio[3093]: error: updateQueue error: null Jun 22 11:26:38 rivo volumio[3093]: error: updateQueue error: null Jun 22 11:26:38 rivo volumio[3093]: info: Jun 22 11:26:38 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:26:38 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:26:38 rivo volumio[3093]: info: ------------------------------ 1890ms Jun 22 11:26:38 rivo volumio[3093]: info: ------------------------------ 1890ms Jun 22 11:26:38 rivo volumio[3093]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/163497669" took 3 milliseconds Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand play Jun 22 11:26:38 rivo volumio[3093]: STREAMING PROXY: Handling url /?data=qobuz://song/163497669 Jun 22 11:26:38 rivo volumio[3093]: info: Jun 22 11:26:38 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:26:38 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:26:38 rivo volumio[3093]: info: Jun 22 11:26:38 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:26:38 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:26:38 rivo volumio[3093]: info: ------------------------------ 8ms Jun 22 11:26:38 rivo volumio[3093]: info: sendMpdCommand play took 7 milliseconds Jun 22 11:26:38 rivo volumio[3093]: info: ------------------------------ 3ms Jun 22 11:26:38 rivo volumio[3093]: info: ------------------------------ 2ms Jun 22 11:26:38 rivo volumio[3093]: info: Executing endpoint getStreamUrlqobuz Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jun 22 11:26:38 rivo volumio[3093]: info: getStreamUrl took 377 milliseconds Jun 22 11:26:38 rivo volumio[3093]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3516194&eid=163497669&fmt=6&profile=raw&app_id=539451548&cid=2515659&etsp=1750562798&hmac=eDgin080EQV5iZU9fwLNVOjy5tA Jun 22 11:26:38 rivo volumio[3093]: STREAMING PROXY: Response: 200, length: 25918075 Jun 22 11:26:38 rivo kernel: aml_spdif_open Jun 22 11:26:38 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jun 22 11:26:38 rivo kernel: set normal 512 fs /4 fs Jun 22 11:26:38 rivo kernel: set spdifout clk:5644800, mpll:22579200 Jun 22 11:26:38 rivo kernel: get spdifout clk:5644797, mpll:22579186 Jun 22 11:26:38 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Jun 22 11:26:38 rivo kernel: set normal 512 fs /4 fs Jun 22 11:26:38 rivo kernel: set spdifout clk:5644800, mpll:22579200 Jun 22 11:26:38 rivo kernel: get spdifout clk:5644797, mpll:22579186 Jun 22 11:26:38 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Jun 22 11:26:38 rivo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Jun 22 11:26:38 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Jun 22 11:26:38 rivo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Jun 22 11:26:38 rivo volumio[3093]: info: Jun 22 11:26:38 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:26:38 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:26:38 rivo volumio[3093]: info: Jun 22 11:26:38 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:26:38 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:26:38 rivo volumio[3093]: info: Jun 22 11:26:38 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:26:38 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:26:38 rivo volumio[3093]: info: Jun 22 11:26:38 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:26:38 rivo volumio[3093]: info: sendMpdCommand status took 6 milliseconds Jun 22 11:26:38 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:26:38 rivo volumio[3093]: info: sendMpdCommand status took 4 milliseconds Jun 22 11:26:38 rivo volumio[3093]: info: sendMpdCommand status took 3 milliseconds Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:26:38 rivo volumio[3093]: info: Jun 22 11:26:38 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:26:38 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:26:38 rivo volumio[3093]: info: Jun 22 11:26:38 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:26:38 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:26:38 rivo volumio[3093]: info: sendMpdCommand status took 7 milliseconds Jun 22 11:26:38 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 7 milliseconds Jun 22 11:26:38 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 6 milliseconds Jun 22 11:26:38 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 22 11:26:38 rivo volumio[3093]: info: sendMpdCommand status took 4 milliseconds Jun 22 11:26:38 rivo volumio[3093]: info: sendMpdCommand status took 3 milliseconds Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:26:38 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:26:38 rivo volumio[3093]: info: CorePlayQueue::getTrack 7 Jun 22 11:26:38 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":202,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"163497669","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/163497669","trackType":"qobuz"} Jun 22 11:26:38 rivo volumio[3093]: verbose: CURRENT POSITION 7 Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus stop Jun 22 11:26:38 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:26:38 rivo volumio[3093]: info: CorePlayQueue::getTrack 7 Jun 22 11:26:38 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":202,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"163497669","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/163497669","trackType":"qobuz"} Jun 22 11:26:38 rivo volumio[3093]: verbose: CURRENT POSITION 7 Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus play Jun 22 11:26:38 rivo volumio[3093]: info: Received an update from plugin. extracting info from payload Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:26:38 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:26:38 rivo volumio[3093]: info: CorePlayQueue::getTrack 7 Jun 22 11:26:38 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":202,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"163497669","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/163497669","trackType":"qobuz"} Jun 22 11:26:38 rivo volumio[3093]: verbose: CURRENT POSITION 7 Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus play Jun 22 11:26:38 rivo volumio[3093]: info: Received an update from plugin. extracting info from payload Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:26:38 rivo volumio[3093]: info: ------------------------------ 39ms Jun 22 11:26:38 rivo volumio[3093]: info: ------------------------------ 50ms Jun 22 11:26:38 rivo volumio[3093]: info: ------------------------------ 47ms Jun 22 11:26:38 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 37 milliseconds Jun 22 11:26:38 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 35 milliseconds Jun 22 11:26:38 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 35 milliseconds Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:26:38 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:26:38 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:26:38 rivo volumio[3093]: info: CorePlayQueue::getTrack 7 Jun 22 11:26:38 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":202,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"163497669","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/163497669","trackType":"qobuz"} Jun 22 11:26:38 rivo volumio[3093]: verbose: CURRENT POSITION 7 Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus play Jun 22 11:26:38 rivo volumio[3093]: info: Received an update from plugin. extracting info from payload Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:26:38 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:26:38 rivo volumio[3093]: info: CorePlayQueue::getTrack 7 Jun 22 11:26:38 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":202,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"163497669","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/163497669","trackType":"qobuz"} Jun 22 11:26:38 rivo volumio[3093]: verbose: CURRENT POSITION 7 Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus play Jun 22 11:26:38 rivo volumio[3093]: info: Received an update from plugin. extracting info from payload Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:26:38 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:26:38 rivo volumio[3093]: info: CorePlayQueue::getTrack 7 Jun 22 11:26:38 rivo volumio[3093]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":202,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"163497669","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/163497669","trackType":"qobuz"} Jun 22 11:26:38 rivo volumio[3093]: verbose: CURRENT POSITION 7 Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::syncState stateService play Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::syncState currentStatus play Jun 22 11:26:38 rivo volumio[3093]: info: Received an update from plugin. extracting info from payload Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:26:38 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:26:38 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:26:38 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:26:38 rivo volumio[3093]: info: ------------------------------ 87ms Jun 22 11:26:38 rivo volumio[3093]: info: ------------------------------ 82ms Jun 22 11:26:38 rivo volumio[3093]: info: ------------------------------ 82ms Jun 22 11:26:38 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:26:38 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:26:38 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:26:38 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:26:38 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:26:38 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:26:38 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:26:38 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:26:38 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:26:38 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:26:38 rivo volumio[3093]: info: Signalling Playback active due to playback status change Jun 22 11:26:38 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Jun 22 11:26:38 rivo volumio[3093]: info: MCU Signalled Playback Active Jun 22 11:26:41 rivo volumio[3093]: STREAMING PROXY: Client dropped request, destroying Jun 22 11:26:44 rivo volumio[3093]: info: Preload queue cleared Jun 22 11:26:44 rivo volumio[3093]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::ClearQueue Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::stop Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::stPlaybackTimer Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::updateTrackBlock Jun 22 11:26:44 rivo volumio[3093]: info: CorePlayQueue::getTrackBlock Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:26:44 rivo volumio[3093]: info: CorePlayQueue::getTrack 7 Jun 22 11:26:44 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 22 11:26:44 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:26:44 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:26:44 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::serviceStop Jun 22 11:26:44 rivo volumio[3093]: info: CorePlayQueue::getTrack 7 Jun 22 11:26:44 rivo volumio[3093]: info: CoreCommandRouter::serviceStop Jun 22 11:26:44 rivo volumio[3093]: info: [1750559204933] ControllerQobuz::stop Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService mpd Jun 22 11:26:44 rivo volumio[3093]: info: ControllerMpd::stop Jun 22 11:26:44 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand stop Jun 22 11:26:44 rivo volumio[3093]: info: CorePlayQueue::clearPlayQueue Jun 22 11:26:44 rivo volumio[3093]: info: CorePlayQueue::saveQueue Jun 22 11:26:44 rivo volumio[3093]: info: CoreCommandRouter::volumioPushQueue Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::addQueueItems Jun 22 11:26:44 rivo volumio[3093]: info: CorePlayQueue::addQueueItems Jun 22 11:26:44 rivo volumio[3093]: info: Preload queue cleared Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/314987059 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/314987059 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/53768212 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/53768212 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/168839412 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/168839412 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/199468357 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/199468357 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/178610962 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/178610962 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/188769508 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/188769508 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/47886309 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/47886309 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/163497669 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/163497669 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/329331941 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/329331941 Jun 22 11:26:44 rivo volumio[3093]: info: CoreCommandRouter::volumioPushQueue Jun 22 11:26:44 rivo volumio[3093]: info: CorePlayQueue::saveQueue Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::updateTrackBlock Jun 22 11:26:44 rivo volumio[3093]: info: CorePlayQueue::getTrackBlock Jun 22 11:26:44 rivo volumio[3093]: info: CoreCommandRouter::volumioPlay Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::play index 8 Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::addQueueItems Jun 22 11:26:44 rivo volumio[3093]: info: CorePlayQueue::addQueueItems Jun 22 11:26:44 rivo volumio[3093]: info: Preload queue cleared Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/28520146 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/28520146 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/13204923 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/13204923 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/121872260 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/121872260 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/194363575 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/194363575 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/98920782 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/98920782 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/44059398 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/44059398 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/211818606 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/211818606 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/296007669 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/296007669 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/313481418 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/313481418 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/81035645 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/81035645 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/196016517 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/196016517 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/196816961 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/196816961 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/314504626 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/314504626 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/260275740 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/260275740 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/3957120 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/3957120 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/127323775 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/127323775 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/641947 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/641947 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/127404148 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/127404148 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/66798141 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/66798141 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/314007447 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/314007447 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/60339561 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/60339561 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/91451723 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/91451723 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/38992373 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/38992373 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/104605104 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/104605104 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/128906807 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/128906807 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/2133088 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/2133088 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/281596467 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/281596467 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/175971951 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/175971951 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/251430307 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/251430307 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/1020021 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/1020021 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/84982386 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/84982386 Jun 22 11:26:44 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback disable Jun 22 11:26:44 rivo kernel: spdif_a keep clk continuous Jun 22 11:26:44 rivo kernel: aml_spdif_close Jun 22 11:26:44 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/4621816 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/4621816 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/52594147 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/52594147 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/22136764 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/22136764 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/45715266 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/45715266 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/635536 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/635536 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/196016523 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/196016523 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/196016633 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/196016633 Jun 22 11:26:44 rivo volumio[3093]: info: Adding Item to queue: qobuz://song/126443492 Jun 22 11:26:44 rivo volumio[3093]: info: Using cached record of: qobuz://song/126443492 Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::stop Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 22 11:26:44 rivo volumio[3093]: info: CoreCommandRouter::volumioPushQueue Jun 22 11:26:44 rivo volumio[3093]: info: CorePlayQueue::saveQueue Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::play index undefined Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::updateTrackBlock Jun 22 11:26:44 rivo volumio[3093]: info: CorePlayQueue::getTrackBlock Jun 22 11:26:44 rivo volumio[3093]: info: CorePlayQueue::getTrack 8 Jun 22 11:26:44 rivo volumio[3093]: info: CoreStateMachine::startPlaybackTimer Jun 22 11:26:44 rivo volumio[3093]: info: CorePlayQueue::getTrack 8 Jun 22 11:26:44 rivo volumio[3093]: info: [1750559204984] ControllerQobuz::clearAddPlayTrack Jun 22 11:26:44 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand stop Jun 22 11:26:44 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:26:45 rivo volumio[3093]: info: Jun 22 11:26:45 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:26:45 rivo volumio[3093]: info: sendMpdCommand stop took 72 milliseconds Jun 22 11:26:45 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:26:45 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:26:45 rivo volumio[3093]: info: sendMpdCommand stop took 21 milliseconds Jun 22 11:26:45 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand clear Jun 22 11:26:45 rivo volumio[3093]: info: Jun 22 11:26:45 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:26:45 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:26:45 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:26:45 rivo volumio[3093]: info: Jun 22 11:26:45 rivo volumio[3093]: ---------------------------- MPD announces state update: player Jun 22 11:26:45 rivo volumio[3093]: info: ControllerMpd::getState Jun 22 11:26:45 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand status Jun 22 11:26:45 rivo volumio[3093]: info: Jun 22 11:26:45 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:26:45 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:26:45 rivo volumio[3093]: info: sendMpdCommand status took 10 milliseconds Jun 22 11:26:45 rivo volumio[3093]: info: sendMpdCommand clear took 9 milliseconds Jun 22 11:26:45 rivo volumio[3093]: info: sendMpdCommand status took 8 milliseconds Jun 22 11:26:45 rivo volumio[3093]: info: sendMpdCommand status took 7 milliseconds Jun 22 11:26:45 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:26:45 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 22 11:26:45 rivo volumio[3093]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/329331941" Jun 22 11:26:45 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:26:45 rivo volumio[3093]: verbose: ControllerMpd::parseState Jun 22 11:26:45 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:26:45 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:26:45 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:26:45 rivo volumio[3093]: info: CorePlayQueue::getTrack 8 Jun 22 11:26:45 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 22 11:26:45 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:26:45 rivo volumio[3093]: STREAMING PROXY: Handling url /?data=qobuz://song/329331941 Jun 22 11:26:45 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:26:45 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:26:45 rivo volumio[3093]: info: CorePlayQueue::getTrack 8 Jun 22 11:26:45 rivo volumio[3093]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jun 22 11:26:45 rivo volumio[3093]: info: ControllerMpd::pushState Jun 22 11:26:45 rivo volumio[3093]: info: CoreCommandRouter::servicePushState Jun 22 11:26:45 rivo volumio[3093]: info: CoreStateMachine::pushState Jun 22 11:26:45 rivo volumio[3093]: info: CorePlayQueue::getTrack 8 Jun 22 11:26:45 rivo volumio[3093]: info: CoreCommandRouter::volumioPushState Jun 22 11:26:45 rivo volumio[3093]: info: MRS: Pushing multiroomSync output update for this device Jun 22 11:26:45 rivo volumio[3093]: info: MRS: Pushing multiroomSync output Jun 22 11:26:45 rivo volumio[3093]: info: CorePlayQueue::getTrack 8 Jun 22 11:26:45 rivo volumio[3093]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Jun 22 11:26:45 rivo volumio[3093]: info: ------------------------------ 26ms Jun 22 11:26:45 rivo volumio[3093]: info: ------------------------------ 25ms Jun 22 11:26:45 rivo volumio[3093]: info: Jun 22 11:26:45 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:26:45 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:26:45 rivo volumio[3093]: info: Jun 22 11:26:45 rivo volumio[3093]: ---------------------------- MPD announces system playlist update Jun 22 11:26:45 rivo volumio[3093]: info: Ignoring MPD Status Update Jun 22 11:26:45 rivo volumio[3093]: error: updateQueue error: null Jun 22 11:26:45 rivo volumio[3093]: info: ------------------------------ 28ms Jun 22 11:26:45 rivo volumio[3093]: info: sendMpdCommand playlistinfo took 27 milliseconds Jun 22 11:26:45 rivo volumio[3093]: verbose: ControllerMpd::parseTrackInfo Jun 22 11:26:45 rivo volumio[3093]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jun 22 11:26:45 rivo volumio[3093]: info: ------------------------------ 39ms Jun 22 11:26:45 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:26:45 rivo volumio[3093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 22 11:26:45 rivo volumio[3093]: info: Executing endpoint getStreamUrlqobuz Jun 22 11:26:45 rivo volumio[3093]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jun 22 11:26:45 rivo volumio[3093]: info: MCU Signalled Playback Inactive Jun 22 11:26:45 rivo volumio[3093]: info: getStreamUrl took 415 milliseconds Jun 22 11:26:45 rivo volumio[3093]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=3516194&eid=329331941&fmt=7&profile=raw&range=20-30&app_id=539451548&cid=2515659&etsp=1750562805&hmac=VP6cEfob_CqBMAqDQMPLC2NAoIE Jun 22 11:26:46 rivo volumio[3093]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 22 11:26:46 rivo volumio[3093]: Error: connect ETIMEDOUT 151.101.66.79:80 Jun 22 11:26:46 rivo volumio[3093]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Jun 22 11:26:46 rivo volumio[3093]: errno: -110, Jun 22 11:26:46 rivo volumio[3093]: code: 'ETIMEDOUT', Jun 22 11:26:46 rivo volumio[3093]: syscall: 'connect', Jun 22 11:26:46 rivo volumio[3093]: address: '151.101.66.79', Jun 22 11:26:46 rivo volumio[3093]: port: 80 Jun 22 11:26:46 rivo volumio[3093]: } Jun 22 11:26:46 rivo volumio[3093]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 22 11:26:46 rivo sudo[21657]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-22 11:25 Jun 22 11:26:46 rivo sudo[21657]: 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="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 10:40:21 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="257abb5a10f96d014c189cf43ed95c4d"