-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Tue 2024-10-08 14:27:03 CEST. -- Oct 08 14:26:01 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:26:17 rivo volumio[3109]: info: CoreCommandRouter::volumioGetQueue Oct 08 14:26:17 rivo volumio[3109]: info: CoreStateMachine::getQueue Oct 08 14:26:17 rivo volumio[3109]: info: CorePlayQueue::getQueue Oct 08 14:26:23 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Oct 08 14:26:23 rivo volumio[3109]: info: handleBrowseUri took 137 milliseconds Oct 08 14:26:23 rivo volumio[3109]: info: Preload queue cleared Oct 08 14:26:23 rivo volumio[3109]: info: Preload queue cleared Oct 08 14:26:24 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Oct 08 14:26:25 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 08 14:26:25 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 08 14:26:25 rivo volumio[3109]: info: Discovery: Getting this device information Oct 08 14:26:25 rivo volumio[3109]: info: CoreCommandRouter::volumioGetState Oct 08 14:26:25 rivo volumio[3109]: info: CorePlayQueue::getTrack 11 Oct 08 14:26:25 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 08 14:26:26 rivo volumio[3109]: info: handleBrowseUri took 1402 milliseconds Oct 08 14:26:26 rivo volumio[3109]: info: Preload queue cleared Oct 08 14:26:28 rivo ntpd[3274]: 193.150.22.56 local addr 192.168.2.186 -> Oct 08 14:26:30 rivo volumio[3109]: info: Preload queue cleared Oct 08 14:26:30 rivo volumio[3109]: info: CoreCommandRouter::volumioAddQueueItems Oct 08 14:26:30 rivo volumio[3109]: info: CoreStateMachine::addQueueItems Oct 08 14:26:30 rivo volumio[3109]: info: CorePlayQueue::addQueueItems Oct 08 14:26:30 rivo volumio[3109]: info: Preload queue cleared Oct 08 14:26:30 rivo volumio[3109]: info: Adding Item to queue: qobuz://playlist/24922708 Oct 08 14:26:30 rivo volumio[3109]: info: Exploding uri qobuz://playlist/24922708 in service qobuz Oct 08 14:26:30 rivo volumio[3109]: https://prod.vlmapi.io/v2/qobuz/explodeUri Oct 08 14:26:31 rivo volumio[3109]: info: explodeUri took 779 milliseconds Oct 08 14:26:31 rivo volumio[3109]: info: CoreCommandRouter::volumioPushQueue Oct 08 14:26:31 rivo volumio[3109]: info: CorePlayQueue::saveQueue Oct 08 14:26:31 rivo volumio[3109]: info: CoreStateMachine::updateTrackBlock Oct 08 14:26:31 rivo volumio[3109]: info: CorePlayQueue::getTrackBlock Oct 08 14:26:31 rivo volumio[3109]: info: CoreCommandRouter::volumioPlay Oct 08 14:26:31 rivo volumio[3109]: info: CoreStateMachine::play index 51 Oct 08 14:26:31 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:31 rivo volumio[3109]: info: CoreStateMachine::stop Oct 08 14:26:31 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:31 rivo volumio[3109]: info: CoreStateMachine::stPlaybackTimer Oct 08 14:26:31 rivo volumio[3109]: info: CoreStateMachine::updateTrackBlock Oct 08 14:26:31 rivo volumio[3109]: info: CorePlayQueue::getTrackBlock Oct 08 14:26:31 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:31 rivo volumio[3109]: info: CorePlayQueue::getTrack 11 Oct 08 14:26:31 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:31 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:31 rivo volumio[3109]: info: CoreStateMachine::serviceStop Oct 08 14:26:31 rivo volumio[3109]: info: CorePlayQueue::getTrack 11 Oct 08 14:26:31 rivo volumio[3109]: info: CoreCommandRouter::serviceStop Oct 08 14:26:31 rivo volumio[3109]: info: [1728390391344] ControllerQobuz::stop Oct 08 14:26:31 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 14:26:31 rivo volumio[3109]: info: ControllerMpd::stop Oct 08 14:26:31 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand stop Oct 08 14:26:31 rivo volumio[3109]: info: sendMpdCommand stop took 48 milliseconds Oct 08 14:26:31 rivo volumio[3109]: info: CoreStateMachine::play index undefined Oct 08 14:26:31 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:31 rivo volumio[3109]: info: CorePlayQueue::getTrack 51 Oct 08 14:26:31 rivo volumio[3109]: info: CoreStateMachine::startPlaybackTimer Oct 08 14:26:31 rivo volumio[3109]: info: CorePlayQueue::getTrack 51 Oct 08 14:26:31 rivo volumio[3109]: info: [1728390391395] ControllerQobuz::clearAddPlayTrack Oct 08 14:26:31 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand stop Oct 08 14:26:31 rivo volumio[3109]: info: Oct 08 14:26:31 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:31 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:31 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:31 rivo volumio[3109]: info: sendMpdCommand stop took 1 milliseconds Oct 08 14:26:31 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand clear Oct 08 14:26:31 rivo volumio[3109]: info: Oct 08 14:26:31 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:31 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:31 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:31 rivo volumio[3109]: info: Oct 08 14:26:31 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:31 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:31 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:31 rivo volumio[3109]: info: Oct 08 14:26:31 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:31 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:31 rivo volumio[3109]: info: sendMpdCommand status took 7 milliseconds Oct 08 14:26:31 rivo volumio[3109]: info: sendMpdCommand clear took 6 milliseconds Oct 08 14:26:31 rivo volumio[3109]: info: sendMpdCommand status took 4 milliseconds Oct 08 14:26:31 rivo volumio[3109]: info: sendMpdCommand status took 4 milliseconds Oct 08 14:26:31 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:31 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:31 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/11362184" Oct 08 14:26:31 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:31 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:31 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:31 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:31 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:31 rivo volumio[3109]: info: CorePlayQueue::getTrack 51 Oct 08 14:26:31 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:31 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:31 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/11362184 Oct 08 14:26:31 rivo volumio[3109]: info: CorePlayQueue::getTrack 51 Oct 08 14:26:31 rivo volumio[3109]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 08 14:26:31 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:31 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:31 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:31 rivo volumio[3109]: info: CorePlayQueue::getTrack 51 Oct 08 14:26:31 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:31 rivo volumio[3109]: info: CorePlayQueue::getTrack 51 Oct 08 14:26:31 rivo volumio[3109]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 08 14:26:31 rivo volumio[3109]: info: ------------------------------ 42ms Oct 08 14:26:31 rivo volumio[3109]: info: ------------------------------ 40ms Oct 08 14:26:31 rivo volumio[3109]: info: Oct 08 14:26:31 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:31 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:31 rivo volumio[3109]: info: Oct 08 14:26:31 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:31 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:31 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:31 rivo volumio[3109]: info: ------------------------------ 42ms Oct 08 14:26:31 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 40 milliseconds Oct 08 14:26:31 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:31 rivo volumio[3109]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 08 14:26:31 rivo volumio[3109]: info: ------------------------------ 51ms Oct 08 14:26:31 rivo volumio[3109]: info: MCU Signalled Playback Inactive Oct 08 14:26:31 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:26:31 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:26:32 rivo volumio[3109]: info: getStreamUrl took 677 milliseconds Oct 08 14:26:32 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=11362184&fmt=6&profile=raw&app_id=539451548&cid=1889513&etsp=1728393992&hmac=2V-aOd_6ogtpCScWrcBWt7Zrm6Q Oct 08 14:26:32 rivo volumio[3109]: STREAMING PROXY: Response: 200, length: 28219403 Oct 08 14:26:32 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:26:32 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:32 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/11362184" Oct 08 14:26:32 rivo volumio[3109]: info: ------------------------------ 756ms Oct 08 14:26:32 rivo volumio[3109]: info: ------------------------------ 755ms Oct 08 14:26:32 rivo volumio[3109]: info: Oct 08 14:26:32 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:32 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:32 rivo volumio[3109]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/11362184" took 3 milliseconds Oct 08 14:26:32 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand play Oct 08 14:26:32 rivo volumio[3109]: info: Oct 08 14:26:32 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:32 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:32 rivo volumio[3109]: info: Oct 08 14:26:32 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:32 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:32 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/11362184 Oct 08 14:26:32 rivo volumio[3109]: info: ------------------------------ 6ms Oct 08 14:26:32 rivo volumio[3109]: info: sendMpdCommand play took 5 milliseconds Oct 08 14:26:32 rivo volumio[3109]: info: ------------------------------ 4ms Oct 08 14:26:32 rivo volumio[3109]: info: ------------------------------ 3ms Oct 08 14:26:32 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:26:32 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:26:32 rivo volumio[3109]: info: getStreamUrl took 558 milliseconds Oct 08 14:26:32 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=11362184&fmt=6&profile=raw&app_id=539451548&cid=1889513&etsp=1728393992&hmac=2V-aOd_6ogtpCScWrcBWt7Zrm6Q Oct 08 14:26:32 rivo volumio[3109]: STREAMING PROXY: Response: 200, length: 28219403 Oct 08 14:26:32 rivo volumio[3109]: info: Oct 08 14:26:32 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:32 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:32 rivo volumio[3109]: info: Oct 08 14:26:32 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:32 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:32 rivo volumio[3109]: info: Oct 08 14:26:32 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:32 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:32 rivo volumio[3109]: info: Oct 08 14:26:32 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:32 rivo volumio[3109]: info: sendMpdCommand status took 76 milliseconds Oct 08 14:26:32 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:32 rivo volumio[3109]: info: sendMpdCommand status took 89 milliseconds Oct 08 14:26:32 rivo volumio[3109]: info: sendMpdCommand status took 87 milliseconds Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:32 rivo volumio[3109]: info: Oct 08 14:26:32 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:32 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:32 rivo volumio[3109]: info: Oct 08 14:26:32 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:32 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:32 rivo volumio[3109]: info: sendMpdCommand status took 11 milliseconds Oct 08 14:26:32 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 08 14:26:32 rivo volumio[3109]: info: sendMpdCommand status took 5 milliseconds Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:32 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:32 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:32 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:32 rivo volumio[3109]: info: CorePlayQueue::getTrack 51 Oct 08 14:26:32 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":297,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"11362184","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/11362184","trackType":"qobuz"} Oct 08 14:26:32 rivo volumio[3109]: verbose: CURRENT POSITION 51 Oct 08 14:26:32 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:32 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus stop Oct 08 14:26:32 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:32 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:32 rivo volumio[3109]: info: CorePlayQueue::getTrack 51 Oct 08 14:26:32 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45,"duration":297,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"527 Kbps","isStreaming":false,"title":"11362184","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/11362184","trackType":"qobuz"} Oct 08 14:26:32 rivo volumio[3109]: verbose: CURRENT POSITION 51 Oct 08 14:26:32 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:32 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:32 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:32 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:32 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:32 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:32 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:32 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:32 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:32 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:32 rivo volumio[3109]: info: CorePlayQueue::getTrack 51 Oct 08 14:26:32 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45,"duration":297,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"527 Kbps","isStreaming":false,"title":"11362184","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/11362184","trackType":"qobuz"} Oct 08 14:26:32 rivo volumio[3109]: verbose: CURRENT POSITION 51 Oct 08 14:26:32 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:32 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:32 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:32 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:32 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:32 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:32 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:32 rivo volumio[3109]: info: ------------------------------ 132ms Oct 08 14:26:33 rivo volumio[3109]: info: ------------------------------ 181ms Oct 08 14:26:33 rivo volumio[3109]: info: ------------------------------ 181ms Oct 08 14:26:33 rivo volumio[3109]: info: sendMpdCommand status took 91 milliseconds Oct 08 14:26:33 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 88 milliseconds Oct 08 14:26:33 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 86 milliseconds Oct 08 14:26:33 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:33 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:33 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:33 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:33 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:33 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:33 rivo volumio[3109]: info: CorePlayQueue::getTrack 51 Oct 08 14:26:33 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":983,"duration":297,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"556 Kbps","isStreaming":false,"title":"11362184","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/11362184","trackType":"qobuz"} Oct 08 14:26:33 rivo volumio[3109]: verbose: CURRENT POSITION 51 Oct 08 14:26:33 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:33 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:33 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:33 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:33 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:33 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:33 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:33 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:33 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:33 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:33 rivo volumio[3109]: info: CorePlayQueue::getTrack 51 Oct 08 14:26:33 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":983,"duration":297,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"556 Kbps","isStreaming":false,"title":"11362184","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/11362184","trackType":"qobuz"} Oct 08 14:26:33 rivo volumio[3109]: verbose: CURRENT POSITION 51 Oct 08 14:26:33 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:33 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:33 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:33 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:33 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:33 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:33 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:33 rivo volumio[3109]: info: ------------------------------ 202ms Oct 08 14:26:33 rivo volumio[3109]: info: ------------------------------ 168ms Oct 08 14:26:33 rivo volumio[3109]: info: [LastFM] Current track has sufficient metadata: title (Born, Never Asked) and artist (Laurie Anderson) passed on explicitly Oct 08 14:26:33 rivo volumio[3109]: info: Signalling Playback active due to playback status change Oct 08 14:26:33 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 145 milliseconds Oct 08 14:26:33 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:33 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:33 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:33 rivo volumio[3109]: info: CorePlayQueue::getTrack 51 Oct 08 14:26:33 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":983,"duration":297,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"556 Kbps","isStreaming":false,"title":"11362184","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/11362184","trackType":"qobuz"} Oct 08 14:26:33 rivo volumio[3109]: verbose: CURRENT POSITION 51 Oct 08 14:26:33 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:33 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:33 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:33 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:33 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:33 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:33 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:33 rivo volumio[3109]: info: ------------------------------ 276ms Oct 08 14:26:33 rivo volumio[3109]: info: MCU Signalled Playback Active Oct 08 14:26:33 rivo volumio[3109]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Born, Never Asked","mbid":"4cff8cb1-5b0e-41df-a1aa-1dabd7e1b371","url":"https://www.last.fm/music/Laurie+Anderson/_/Born,+Never+Asked","duration":"271000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"46102","playcount":"149795","artist":{"name":"Laurie Anderson","mbid":"86809b51-cbe2-45f1-804a-e66eed635dea","url":"https://www.last.fm/music/Laurie+Anderson"},"album":{"@":{"position":"5"},"artist":"Laurie Anderson","title":"Big Science","mbid":"b787531c-34e1-315c-ada4-39d4c3c5221a","url":"https://www.last.fm/music/Laurie+Anderson/Big+Science","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/12e36132d24a11357ffc964e8a5a56ca.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/12e36132d24a11357ffc964e8a5a56ca.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/12e36132d24a11357ffc964e8a5a56ca.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/12e36132d24a11357ffc964e8a5a56ca.png","@":{"size":"extralarge"}}]},"userplaycount":"6","userloved":"0","toptags":{"tag":[{"name":"Avant-Garde","url":"https://www.last.fm/tag/Avant-Garde"},{"name":"experimental","url":"https://www.last.fm/tag/experimental"},{"name":"electronic","url":"https://www.last.fm/tag/electronic"},{"name":"female vocalists","url":"https://www.last.fm/tag/female+vocalists"},{"name":"80s","url":"https://www.last.fm/tag/80s"}]}}} Oct 08 14:26:34 rivo volumio[3109]: info: CoreCommandRouter::volumioNext Oct 08 14:26:34 rivo volumio[3109]: info: CoreStateMachine::next Oct 08 14:26:34 rivo volumio[3109]: info: [1728390394324] ControllerQobuz::next Oct 08 14:26:34 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:34 rivo volumio[3109]: info: CoreStateMachine::next Oct 08 14:26:34 rivo volumio[3109]: info: CoreStateMachine::stop Oct 08 14:26:34 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:34 rivo volumio[3109]: info: CoreStateMachine::stPlaybackTimer Oct 08 14:26:34 rivo volumio[3109]: info: CoreStateMachine::updateTrackBlock Oct 08 14:26:34 rivo volumio[3109]: info: CorePlayQueue::getTrackBlock Oct 08 14:26:34 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:34 rivo volumio[3109]: info: CorePlayQueue::getTrack 51 Oct 08 14:26:34 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:34 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:34 rivo volumio[3109]: info: CoreStateMachine::serviceStop Oct 08 14:26:34 rivo volumio[3109]: info: CorePlayQueue::getTrack 51 Oct 08 14:26:34 rivo volumio[3109]: info: CoreCommandRouter::serviceStop Oct 08 14:26:34 rivo volumio[3109]: info: [1728390394342] ControllerQobuz::stop Oct 08 14:26:34 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 14:26:34 rivo volumio[3109]: info: ControllerMpd::stop Oct 08 14:26:34 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand stop Oct 08 14:26:34 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:26:34 rivo volumio[3109]: info: sendMpdCommand stop took 58 milliseconds Oct 08 14:26:34 rivo volumio[3109]: info: CoreStateMachine::play index undefined Oct 08 14:26:34 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:34 rivo volumio[3109]: info: CorePlayQueue::getTrack 52 Oct 08 14:26:34 rivo volumio[3109]: info: CoreStateMachine::startPlaybackTimer Oct 08 14:26:34 rivo volumio[3109]: info: CorePlayQueue::getTrack 52 Oct 08 14:26:34 rivo volumio[3109]: info: [1728390394402] ControllerQobuz::clearAddPlayTrack Oct 08 14:26:34 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand stop Oct 08 14:26:34 rivo volumio[3109]: info: CoreStateMachine::updateTrackBlock Oct 08 14:26:34 rivo volumio[3109]: info: CorePlayQueue::getTrackBlock Oct 08 14:26:34 rivo volumio[3109]: info: Oct 08 14:26:34 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:34 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:34 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:34 rivo volumio[3109]: info: sendMpdCommand stop took 2 milliseconds Oct 08 14:26:34 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand clear Oct 08 14:26:34 rivo volumio[3109]: info: Oct 08 14:26:34 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:34 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:34 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:34 rivo volumio[3109]: info: Oct 08 14:26:34 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:34 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:34 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:34 rivo volumio[3109]: info: Oct 08 14:26:34 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:34 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:34 rivo volumio[3109]: info: sendMpdCommand status took 6 milliseconds Oct 08 14:26:34 rivo volumio[3109]: info: sendMpdCommand clear took 5 milliseconds Oct 08 14:26:34 rivo volumio[3109]: info: sendMpdCommand status took 3 milliseconds Oct 08 14:26:34 rivo volumio[3109]: info: sendMpdCommand status took 3 milliseconds Oct 08 14:26:34 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:34 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:34 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/91285647" Oct 08 14:26:34 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:34 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:34 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:34 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:34 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:34 rivo volumio[3109]: info: CorePlayQueue::getTrack 52 Oct 08 14:26:34 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:34 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:34 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/91285647 Oct 08 14:26:34 rivo volumio[3109]: info: CorePlayQueue::getTrack 52 Oct 08 14:26:34 rivo volumio[3109]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 08 14:26:34 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:34 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:34 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:34 rivo volumio[3109]: info: CorePlayQueue::getTrack 52 Oct 08 14:26:34 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:34 rivo volumio[3109]: info: CorePlayQueue::getTrack 52 Oct 08 14:26:34 rivo volumio[3109]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 08 14:26:34 rivo volumio[3109]: info: ------------------------------ 40ms Oct 08 14:26:34 rivo volumio[3109]: info: ------------------------------ 39ms Oct 08 14:26:34 rivo volumio[3109]: info: Oct 08 14:26:34 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:34 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:34 rivo volumio[3109]: info: Oct 08 14:26:34 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:34 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:34 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:34 rivo volumio[3109]: info: ------------------------------ 42ms Oct 08 14:26:34 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 40 milliseconds Oct 08 14:26:34 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:34 rivo volumio[3109]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 08 14:26:34 rivo volumio[3109]: info: ------------------------------ 49ms Oct 08 14:26:34 rivo volumio[3109]: info: MCU Signalled Playback Inactive Oct 08 14:26:34 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:26:34 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:26:35 rivo volumio[3109]: info: getStreamUrl took 574 milliseconds Oct 08 14:26:35 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=91285647&fmt=6&profile=raw&app_id=539451548&cid=1889513&etsp=1728393994&hmac=293U1zSj6vPj7RQ-fOplP93YcZ8 Oct 08 14:26:35 rivo volumio[3109]: STREAMING PROXY: Response: 200, length: 23512763 Oct 08 14:26:35 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:35 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:26:35 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/91285647" Oct 08 14:26:35 rivo volumio[3109]: info: ------------------------------ 638ms Oct 08 14:26:35 rivo volumio[3109]: info: ------------------------------ 637ms Oct 08 14:26:35 rivo volumio[3109]: info: Oct 08 14:26:35 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:35 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:35 rivo volumio[3109]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/91285647" took 2 milliseconds Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand play Oct 08 14:26:35 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/91285647 Oct 08 14:26:35 rivo volumio[3109]: info: Oct 08 14:26:35 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:35 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:35 rivo volumio[3109]: info: Oct 08 14:26:35 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:35 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:35 rivo volumio[3109]: info: ------------------------------ 8ms Oct 08 14:26:35 rivo volumio[3109]: info: sendMpdCommand play took 7 milliseconds Oct 08 14:26:35 rivo volumio[3109]: info: ------------------------------ 3ms Oct 08 14:26:35 rivo volumio[3109]: info: ------------------------------ 2ms Oct 08 14:26:35 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:26:35 rivo volumio[3109]: info: getStreamUrl took 570 milliseconds Oct 08 14:26:35 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=91285647&fmt=6&profile=raw&app_id=539451548&cid=1889513&etsp=1728393995&hmac=NQtEPonbP0JWcIOgOat4MeV2X5E Oct 08 14:26:35 rivo volumio[3109]: STREAMING PROXY: Response: 200, length: 23512763 Oct 08 14:26:35 rivo volumio[3109]: info: Oct 08 14:26:35 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:35 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:35 rivo volumio[3109]: info: Oct 08 14:26:35 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:35 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:35 rivo volumio[3109]: info: Oct 08 14:26:35 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:35 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:35 rivo volumio[3109]: info: sendMpdCommand status took 56 milliseconds Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:35 rivo volumio[3109]: info: Oct 08 14:26:35 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:35 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:35 rivo volumio[3109]: info: sendMpdCommand status took 58 milliseconds Oct 08 14:26:35 rivo volumio[3109]: info: sendMpdCommand status took 57 milliseconds Oct 08 14:26:35 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:35 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:35 rivo volumio[3109]: info: CorePlayQueue::getTrack 52 Oct 08 14:26:35 rivo volumio[3109]: 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":"91285647","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/91285647","trackType":"qobuz"} Oct 08 14:26:35 rivo volumio[3109]: verbose: CURRENT POSITION 52 Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus stop Oct 08 14:26:35 rivo volumio[3109]: info: ------------------------------ 66ms Oct 08 14:26:35 rivo volumio[3109]: info: Oct 08 14:26:35 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:35 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:35 rivo volumio[3109]: info: Oct 08 14:26:35 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:35 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:35 rivo volumio[3109]: info: sendMpdCommand status took 11 milliseconds Oct 08 14:26:35 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 08 14:26:35 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 9 milliseconds Oct 08 14:26:35 rivo volumio[3109]: info: sendMpdCommand status took 5 milliseconds Oct 08 14:26:35 rivo volumio[3109]: info: sendMpdCommand status took 4 milliseconds Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:35 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:35 rivo volumio[3109]: info: CorePlayQueue::getTrack 52 Oct 08 14:26:35 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":183,"duration":231,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"606 Kbps","isStreaming":false,"title":"91285647","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/91285647","trackType":"qobuz"} Oct 08 14:26:35 rivo volumio[3109]: verbose: CURRENT POSITION 52 Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:35 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:35 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:35 rivo volumio[3109]: info: CorePlayQueue::getTrack 52 Oct 08 14:26:35 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":183,"duration":231,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"548 Kbps","isStreaming":false,"title":"91285647","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/91285647","trackType":"qobuz"} Oct 08 14:26:35 rivo volumio[3109]: verbose: CURRENT POSITION 52 Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:35 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:35 rivo volumio[3109]: info: ------------------------------ 146ms Oct 08 14:26:35 rivo volumio[3109]: info: ------------------------------ 146ms Oct 08 14:26:35 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 78 milliseconds Oct 08 14:26:35 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 77 milliseconds Oct 08 14:26:35 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 77 milliseconds Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:35 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:35 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:35 rivo volumio[3109]: info: CorePlayQueue::getTrack 52 Oct 08 14:26:35 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":983,"duration":231,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"552 Kbps","isStreaming":false,"title":"91285647","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/91285647","trackType":"qobuz"} Oct 08 14:26:35 rivo volumio[3109]: verbose: CURRENT POSITION 52 Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:35 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:35 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:35 rivo volumio[3109]: info: CorePlayQueue::getTrack 52 Oct 08 14:26:35 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":983,"duration":231,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"694 Kbps","isStreaming":false,"title":"91285647","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/91285647","trackType":"qobuz"} Oct 08 14:26:35 rivo volumio[3109]: verbose: CURRENT POSITION 52 Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:35 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:35 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:35 rivo volumio[3109]: info: CorePlayQueue::getTrack 52 Oct 08 14:26:35 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":983,"duration":231,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"694 Kbps","isStreaming":false,"title":"91285647","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/91285647","trackType":"qobuz"} Oct 08 14:26:35 rivo volumio[3109]: verbose: CURRENT POSITION 52 Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:35 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:35 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:35 rivo volumio[3109]: info: ------------------------------ 195ms Oct 08 14:26:35 rivo volumio[3109]: info: ------------------------------ 190ms Oct 08 14:26:35 rivo volumio[3109]: info: ------------------------------ 189ms Oct 08 14:26:36 rivo volumio[3109]: info: [LastFM] Current track has sufficient metadata: title (La Vita) and artist (Beverly Glenn-Copeland) passed on explicitly Oct 08 14:26:36 rivo volumio[3109]: info: Signalling Playback active due to playback status change Oct 08 14:26:36 rivo volumio[3109]: info: MCU Signalled Playback Active Oct 08 14:26:36 rivo volumio[3109]: info: CoreCommandRouter::volumioNext Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::next Oct 08 14:26:36 rivo volumio[3109]: info: [1728390396284] ControllerQobuz::next Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::next Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::stop Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::stPlaybackTimer Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::updateTrackBlock Oct 08 14:26:36 rivo volumio[3109]: info: CorePlayQueue::getTrackBlock Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:36 rivo volumio[3109]: info: CorePlayQueue::getTrack 52 Oct 08 14:26:36 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:36 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::serviceStop Oct 08 14:26:36 rivo volumio[3109]: info: CorePlayQueue::getTrack 52 Oct 08 14:26:36 rivo volumio[3109]: info: CoreCommandRouter::serviceStop Oct 08 14:26:36 rivo volumio[3109]: info: [1728390396302] ControllerQobuz::stop Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 14:26:36 rivo volumio[3109]: info: ControllerMpd::stop Oct 08 14:26:36 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand stop Oct 08 14:26:36 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:26:36 rivo volumio[3109]: info: Oct 08 14:26:36 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:36 rivo volumio[3109]: info: sendMpdCommand stop took 24 milliseconds Oct 08 14:26:36 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:36 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::play index undefined Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:36 rivo volumio[3109]: info: CorePlayQueue::getTrack 53 Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::startPlaybackTimer Oct 08 14:26:36 rivo volumio[3109]: info: CorePlayQueue::getTrack 53 Oct 08 14:26:36 rivo volumio[3109]: info: [1728390396328] ControllerQobuz::clearAddPlayTrack Oct 08 14:26:36 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand stop Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::updateTrackBlock Oct 08 14:26:36 rivo volumio[3109]: info: CorePlayQueue::getTrackBlock Oct 08 14:26:36 rivo volumio[3109]: info: sendMpdCommand status took 4 milliseconds Oct 08 14:26:36 rivo volumio[3109]: info: sendMpdCommand stop took 2 milliseconds Oct 08 14:26:36 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:36 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:36 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand clear Oct 08 14:26:36 rivo volumio[3109]: info: Oct 08 14:26:36 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:36 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:36 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:36 rivo volumio[3109]: info: Oct 08 14:26:36 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:36 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:36 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:36 rivo volumio[3109]: info: Oct 08 14:26:36 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:36 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:36 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 08 14:26:36 rivo volumio[3109]: info: sendMpdCommand clear took 6 milliseconds Oct 08 14:26:36 rivo volumio[3109]: info: sendMpdCommand status took 4 milliseconds Oct 08 14:26:36 rivo volumio[3109]: info: sendMpdCommand status took 4 milliseconds Oct 08 14:26:36 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:36 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/78300158" Oct 08 14:26:36 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:36 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:36 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:36 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:36 rivo volumio[3109]: info: CorePlayQueue::getTrack 53 Oct 08 14:26:36 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:36 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:36 rivo volumio[3109]: info: CorePlayQueue::getTrack 53 Oct 08 14:26:36 rivo volumio[3109]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 08 14:26:36 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:36 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:36 rivo volumio[3109]: info: CorePlayQueue::getTrack 53 Oct 08 14:26:36 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:36 rivo volumio[3109]: info: CorePlayQueue::getTrack 53 Oct 08 14:26:36 rivo volumio[3109]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 08 14:26:36 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/78300158 Oct 08 14:26:36 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:36 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:36 rivo volumio[3109]: info: CorePlayQueue::getTrack 53 Oct 08 14:26:36 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:36 rivo volumio[3109]: info: CorePlayQueue::getTrack 53 Oct 08 14:26:36 rivo volumio[3109]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 08 14:26:36 rivo volumio[3109]: info: ------------------------------ 58ms Oct 08 14:26:36 rivo volumio[3109]: info: ------------------------------ 51ms Oct 08 14:26:36 rivo volumio[3109]: info: ------------------------------ 50ms Oct 08 14:26:36 rivo volumio[3109]: info: Oct 08 14:26:36 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:36 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:36 rivo volumio[3109]: info: Oct 08 14:26:36 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:36 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:36 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:36 rivo volumio[3109]: info: ------------------------------ 51ms Oct 08 14:26:36 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:26:36 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:26:36 rivo volumio[3109]: info: MCU Signalled Playback Inactive Oct 08 14:26:36 rivo volumio[3109]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"La Vita","url":"https://www.last.fm/music/Beverly+Glenn-Copeland/_/La+Vita","duration":"231000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"18123","playcount":"63887","artist":{"name":"Beverly Glenn-Copeland","url":"https://www.last.fm/music/Beverly+Glenn-Copeland"},"album":{"artist":"Beverly Glenn-Copeland","title":"Transmissions: The Music of Beverly Glenn-Copeland","url":"https://www.last.fm/music/Beverly+Glenn-Copeland/Transmissions:+The+Music+of+Beverly+Glenn-Copeland","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/b8e5034b27cf7441247eb0ea8774b52d.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/b8e5034b27cf7441247eb0ea8774b52d.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/b8e5034b27cf7441247eb0ea8774b52d.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/b8e5034b27cf7441247eb0ea8774b52d.png","@":{"size":"extralarge"}}]},"userplaycount":"11","userloved":"0","toptags":{"tag":[{"name":"electronic","url":"https://www.last.fm/tag/electronic"},{"name":"ambient","url":"https://www.last.fm/tag/ambient"},{"name":"new age","url":"https://www.last.fm/tag/new+age"},{"name":"queer","url":"https://www.last.fm/tag/queer"}]}}} Oct 08 14:26:36 rivo volumio[3109]: info: getStreamUrl took 473 milliseconds Oct 08 14:26:36 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=78300158&fmt=7&profile=raw&app_id=539451548&cid=1889513&etsp=1728393996&hmac=eABKmZCynQEoTskwzkeqx18OHK0 Oct 08 14:26:36 rivo volumio[3109]: STREAMING PROXY: Response: 200, length: 22945671 Oct 08 14:26:36 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:36 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:26:36 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:36 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/78300158" Oct 08 14:26:36 rivo volumio[3109]: info: ------------------------------ 538ms Oct 08 14:26:36 rivo volumio[3109]: info: ------------------------------ 537ms Oct 08 14:26:36 rivo volumio[3109]: info: Oct 08 14:26:36 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:36 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:36 rivo volumio[3109]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/78300158" took 2 milliseconds Oct 08 14:26:36 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 14:26:36 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand play Oct 08 14:26:36 rivo volumio[3109]: info: Oct 08 14:26:36 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:36 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:36 rivo volumio[3109]: info: Oct 08 14:26:36 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:36 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:36 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/78300158 Oct 08 14:26:36 rivo volumio[3109]: info: ------------------------------ 5ms Oct 08 14:26:36 rivo volumio[3109]: info: sendMpdCommand play took 4 milliseconds Oct 08 14:26:36 rivo volumio[3109]: info: ------------------------------ 4ms Oct 08 14:26:36 rivo volumio[3109]: info: ------------------------------ 3ms Oct 08 14:26:36 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:26:36 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:26:37 rivo volumio[3109]: info: getStreamUrl took 588 milliseconds Oct 08 14:26:37 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=78300158&fmt=7&profile=raw&app_id=539451548&cid=1889513&etsp=1728393997&hmac=QZrOnsvOr8l4htpcWTNTcgd2cRo Oct 08 14:26:37 rivo volumio[3109]: STREAMING PROXY: Response: 200, length: 22945671 Oct 08 14:26:37 rivo volumio[3109]: info: Oct 08 14:26:37 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:37 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:37 rivo volumio[3109]: info: Oct 08 14:26:37 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:37 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:37 rivo volumio[3109]: info: Oct 08 14:26:37 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:37 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:37 rivo volumio[3109]: info: Oct 08 14:26:37 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:37 rivo volumio[3109]: info: sendMpdCommand status took 16 milliseconds Oct 08 14:26:37 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:37 rivo volumio[3109]: info: sendMpdCommand status took 16 milliseconds Oct 08 14:26:37 rivo volumio[3109]: info: sendMpdCommand status took 15 milliseconds Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:37 rivo volumio[3109]: info: Oct 08 14:26:37 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:37 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:37 rivo volumio[3109]: info: Oct 08 14:26:37 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:37 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:37 rivo volumio[3109]: info: sendMpdCommand status took 28 milliseconds Oct 08 14:26:37 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 31 milliseconds Oct 08 14:26:37 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 31 milliseconds Oct 08 14:26:37 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 30 milliseconds Oct 08 14:26:37 rivo volumio[3109]: info: sendMpdCommand status took 27 milliseconds Oct 08 14:26:37 rivo volumio[3109]: info: sendMpdCommand status took 9 milliseconds Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:37 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:37 rivo volumio[3109]: info: CorePlayQueue::getTrack 53 Oct 08 14:26:37 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":145,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"78300158","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/78300158","trackType":"qobuz"} Oct 08 14:26:37 rivo volumio[3109]: verbose: CURRENT POSITION 53 Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus stop Oct 08 14:26:37 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:37 rivo volumio[3109]: info: CorePlayQueue::getTrack 53 Oct 08 14:26:37 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":145,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"78300158","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/78300158","trackType":"qobuz"} Oct 08 14:26:37 rivo volumio[3109]: verbose: CURRENT POSITION 53 Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:37 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:37 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:37 rivo volumio[3109]: info: CorePlayQueue::getTrack 53 Oct 08 14:26:37 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":145,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"78300158","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/78300158","trackType":"qobuz"} Oct 08 14:26:37 rivo volumio[3109]: verbose: CURRENT POSITION 53 Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:37 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:37 rivo volumio[3109]: info: ------------------------------ 150ms Oct 08 14:26:37 rivo volumio[3109]: info: ------------------------------ 205ms Oct 08 14:26:37 rivo volumio[3109]: info: ------------------------------ 205ms Oct 08 14:26:37 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 156 milliseconds Oct 08 14:26:37 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 155 milliseconds Oct 08 14:26:37 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 154 milliseconds Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:37 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:37 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:37 rivo volumio[3109]: info: CorePlayQueue::getTrack 53 Oct 08 14:26:37 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":145,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"78300158","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/78300158","trackType":"qobuz"} Oct 08 14:26:37 rivo volumio[3109]: verbose: CURRENT POSITION 53 Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:37 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:37 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:37 rivo volumio[3109]: info: CorePlayQueue::getTrack 53 Oct 08 14:26:37 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":145,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"78300158","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/78300158","trackType":"qobuz"} Oct 08 14:26:37 rivo volumio[3109]: verbose: CURRENT POSITION 53 Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:37 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:37 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:37 rivo volumio[3109]: info: CorePlayQueue::getTrack 53 Oct 08 14:26:37 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":240,"duration":145,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1158 Kbps","isStreaming":false,"title":"78300158","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/78300158","trackType":"qobuz"} Oct 08 14:26:37 rivo volumio[3109]: verbose: CURRENT POSITION 53 Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:37 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:37 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:37 rivo volumio[3109]: info: ------------------------------ 327ms Oct 08 14:26:37 rivo volumio[3109]: info: ------------------------------ 322ms Oct 08 14:26:37 rivo volumio[3109]: info: ------------------------------ 321ms Oct 08 14:26:37 rivo volumio[3109]: info: [LastFM] Current track has sufficient metadata: title (Love Will Remain) and artist (Bill Fay) passed on explicitly Oct 08 14:26:38 rivo volumio[3109]: info: Signalling Playback active due to playback status change Oct 08 14:26:38 rivo volumio[3109]: info: MCU Signalled Playback Active Oct 08 14:26:38 rivo volumio[3109]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Love Will Remain","url":"https://www.last.fm/music/Bill+Fay/_/Love+Will+Remain","duration":"144000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"5038","playcount":"13182","artist":{"name":"Bill Fay","mbid":"c139d092-9457-40ec-8130-e11d4cbcfb56","url":"https://www.last.fm/music/Bill+Fay"},"album":{"artist":"Bill Fay","title":"Countless Branches","url":"https://www.last.fm/music/Bill+Fay/Countless+Branches","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/ed966dd5ae0410cd024ca0a725b7c2f5.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/ed966dd5ae0410cd024ca0a725b7c2f5.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/ed966dd5ae0410cd024ca0a725b7c2f5.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/ed966dd5ae0410cd024ca0a725b7c2f5.png","@":{"size":"extralarge"}}]},"userplaycount":"2","userloved":"0","toptags":""}} Oct 08 14:26:38 rivo volumio[3109]: info: CoreCommandRouter::volumioNext Oct 08 14:26:38 rivo volumio[3109]: info: CoreStateMachine::next Oct 08 14:26:38 rivo volumio[3109]: info: [1728390398868] ControllerQobuz::next Oct 08 14:26:38 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:38 rivo volumio[3109]: info: CoreStateMachine::next Oct 08 14:26:38 rivo volumio[3109]: info: CoreStateMachine::stop Oct 08 14:26:38 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:38 rivo volumio[3109]: info: CoreStateMachine::stPlaybackTimer Oct 08 14:26:38 rivo volumio[3109]: info: CoreStateMachine::updateTrackBlock Oct 08 14:26:38 rivo volumio[3109]: info: CorePlayQueue::getTrackBlock Oct 08 14:26:38 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:38 rivo volumio[3109]: info: CorePlayQueue::getTrack 53 Oct 08 14:26:38 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:38 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:38 rivo volumio[3109]: info: CoreStateMachine::serviceStop Oct 08 14:26:38 rivo volumio[3109]: info: CorePlayQueue::getTrack 53 Oct 08 14:26:38 rivo volumio[3109]: info: CoreCommandRouter::serviceStop Oct 08 14:26:38 rivo volumio[3109]: info: [1728390398884] ControllerQobuz::stop Oct 08 14:26:38 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 14:26:38 rivo volumio[3109]: info: ControllerMpd::stop Oct 08 14:26:38 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand stop Oct 08 14:26:38 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:26:38 rivo volumio[3109]: info: Oct 08 14:26:38 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:38 rivo volumio[3109]: info: sendMpdCommand stop took 61 milliseconds Oct 08 14:26:38 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:38 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:38 rivo volumio[3109]: info: CoreStateMachine::play index undefined Oct 08 14:26:38 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:38 rivo volumio[3109]: info: CorePlayQueue::getTrack 54 Oct 08 14:26:38 rivo volumio[3109]: info: CoreStateMachine::startPlaybackTimer Oct 08 14:26:38 rivo volumio[3109]: info: CorePlayQueue::getTrack 54 Oct 08 14:26:38 rivo volumio[3109]: info: [1728390398948] ControllerQobuz::clearAddPlayTrack Oct 08 14:26:38 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand stop Oct 08 14:26:38 rivo volumio[3109]: info: CoreStateMachine::updateTrackBlock Oct 08 14:26:38 rivo volumio[3109]: info: CorePlayQueue::getTrackBlock Oct 08 14:26:38 rivo volumio[3109]: info: Oct 08 14:26:38 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:38 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:38 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:38 rivo volumio[3109]: info: Oct 08 14:26:38 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:38 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:38 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:38 rivo volumio[3109]: info: sendMpdCommand status took 6 milliseconds Oct 08 14:26:38 rivo volumio[3109]: info: sendMpdCommand stop took 5 milliseconds Oct 08 14:26:38 rivo volumio[3109]: info: sendMpdCommand status took 3 milliseconds Oct 08 14:26:38 rivo volumio[3109]: info: sendMpdCommand status took 2 milliseconds Oct 08 14:26:38 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:38 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:38 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand clear Oct 08 14:26:38 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:38 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:38 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:38 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:38 rivo volumio[3109]: info: Oct 08 14:26:38 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:38 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:38 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 08 14:26:38 rivo volumio[3109]: info: sendMpdCommand clear took 3 milliseconds Oct 08 14:26:38 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 08 14:26:38 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 08 14:26:38 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:38 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/243035218" Oct 08 14:26:38 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:38 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:38 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:38 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:38 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:38 rivo volumio[3109]: info: CorePlayQueue::getTrack 54 Oct 08 14:26:38 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:38 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:38 rivo volumio[3109]: info: CorePlayQueue::getTrack 54 Oct 08 14:26:38 rivo volumio[3109]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 08 14:26:38 rivo volumio[3109]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 08 14:26:38 rivo volumio[3109]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 08 14:26:38 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/243035218 Oct 08 14:26:38 rivo volumio[3109]: info: ------------------------------ 32ms Oct 08 14:26:38 rivo volumio[3109]: info: ------------------------------ 28ms Oct 08 14:26:38 rivo volumio[3109]: info: ------------------------------ 26ms Oct 08 14:26:38 rivo volumio[3109]: info: Oct 08 14:26:38 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:38 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:38 rivo volumio[3109]: info: Oct 08 14:26:38 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:38 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:38 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:38 rivo volumio[3109]: info: ------------------------------ 24ms Oct 08 14:26:38 rivo volumio[3109]: info: MCU Signalled Playback Inactive Oct 08 14:26:38 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:26:38 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:26:39 rivo volumio[3109]: info: getStreamUrl took 550 milliseconds Oct 08 14:26:39 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=243035218&fmt=6&profile=raw&app_id=539451548&cid=1889513&etsp=1728393999&hmac=1QOc4tB6ZOqyfRmP5KTYq_DtwSw Oct 08 14:26:39 rivo volumio[3109]: STREAMING PROXY: Response: 200, length: 18858530 Oct 08 14:26:39 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:26:39 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/243035218" Oct 08 14:26:39 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:39 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:39 rivo volumio[3109]: info: Oct 08 14:26:39 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:39 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:39 rivo volumio[3109]: info: ------------------------------ 609ms Oct 08 14:26:39 rivo volumio[3109]: info: ------------------------------ 608ms Oct 08 14:26:39 rivo volumio[3109]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/243035218" took 2 milliseconds Oct 08 14:26:39 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 14:26:39 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand play Oct 08 14:26:39 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/243035218 Oct 08 14:26:39 rivo volumio[3109]: info: Oct 08 14:26:39 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:39 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:39 rivo volumio[3109]: info: ------------------------------ 6ms Oct 08 14:26:39 rivo volumio[3109]: info: sendMpdCommand play took 5 milliseconds Oct 08 14:26:39 rivo volumio[3109]: info: Oct 08 14:26:39 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:39 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:39 rivo volumio[3109]: info: ------------------------------ 4ms Oct 08 14:26:39 rivo volumio[3109]: info: ------------------------------ 2ms Oct 08 14:26:39 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:26:39 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:26:40 rivo volumio[3109]: info: getStreamUrl took 680 milliseconds Oct 08 14:26:40 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=243035218&fmt=6&profile=raw&app_id=539451548&cid=1889513&etsp=1728394000&hmac=YZsvp6Y1QUpfl_3jhnu1hPPMYso Oct 08 14:26:40 rivo volumio[3109]: STREAMING PROXY: Response: 200, length: 18858530 Oct 08 14:26:40 rivo volumio[3109]: info: Oct 08 14:26:40 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:40 rivo volumio[3109]: info: Oct 08 14:26:40 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:40 rivo volumio[3109]: info: Oct 08 14:26:40 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:40 rivo volumio[3109]: info: Oct 08 14:26:40 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand status took 30 milliseconds Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand status took 28 milliseconds Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand status took 28 milliseconds Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:40 rivo volumio[3109]: info: Oct 08 14:26:40 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:40 rivo volumio[3109]: info: Oct 08 14:26:40 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand status took 12 milliseconds Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 11 milliseconds Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand status took 4 milliseconds Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrack 54 Oct 08 14:26:40 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":219,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"243035218","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/243035218","trackType":"qobuz"} Oct 08 14:26:40 rivo volumio[3109]: verbose: CURRENT POSITION 54 Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus stop Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrack 54 Oct 08 14:26:40 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":219,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"243035218","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/243035218","trackType":"qobuz"} Oct 08 14:26:40 rivo volumio[3109]: verbose: CURRENT POSITION 54 Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:40 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrack 54 Oct 08 14:26:40 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":22,"duration":219,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"243035218","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/243035218","trackType":"qobuz"} Oct 08 14:26:40 rivo volumio[3109]: verbose: CURRENT POSITION 54 Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:40 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:40 rivo volumio[3109]: info: ------------------------------ 83ms Oct 08 14:26:40 rivo volumio[3109]: info: ------------------------------ 151ms Oct 08 14:26:40 rivo volumio[3109]: info: ------------------------------ 151ms Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand status took 116 milliseconds Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 113 milliseconds Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 111 milliseconds Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrack 54 Oct 08 14:26:40 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":228,"duration":219,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"632 Kbps","isStreaming":false,"title":"243035218","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/243035218","trackType":"qobuz"} Oct 08 14:26:40 rivo volumio[3109]: verbose: CURRENT POSITION 54 Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:40 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrack 54 Oct 08 14:26:40 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":251,"duration":219,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"637 Kbps","isStreaming":false,"title":"243035218","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/243035218","trackType":"qobuz"} Oct 08 14:26:40 rivo volumio[3109]: verbose: CURRENT POSITION 54 Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:40 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:40 rivo volumio[3109]: info: ------------------------------ 231ms Oct 08 14:26:40 rivo volumio[3109]: info: ------------------------------ 224ms Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::volumioNext Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::next Oct 08 14:26:40 rivo volumio[3109]: info: [1728390400616] ControllerQobuz::next Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::next Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::stop Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::stPlaybackTimer Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::updateTrackBlock Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrackBlock Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrack 54 Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::serviceStop Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrack 54 Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::serviceStop Oct 08 14:26:40 rivo volumio[3109]: info: [1728390400634] ControllerQobuz::stop Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::stop Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand stop Oct 08 14:26:40 rivo volumio[3109]: info: [LastFM] Current track has sufficient metadata: title (Stars at Noon) and artist (Tindersticks) passed on explicitly Oct 08 14:26:40 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:26:40 rivo volumio[3109]: info: Signalling Playback active due to playback status change Oct 08 14:26:40 rivo volumio[3109]: info: Oct 08 14:26:40 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 225 milliseconds Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand stop took 85 milliseconds Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:40 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":251,"duration":219,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"637 Kbps","isStreaming":false,"title":"243035218","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/243035218","trackType":"qobuz"} Oct 08 14:26:40 rivo volumio[3109]: verbose: CURRENT POSITION 55 Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus stop Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::play index undefined Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:40 rivo volumio[3109]: info: ------------------------------ 347ms Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::updateTrackBlock Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrackBlock Oct 08 14:26:40 rivo volumio[3109]: info: Oct 08 14:26:40 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:40 rivo volumio[3109]: info: Oct 08 14:26:40 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand status took 13 milliseconds Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand status took 6 milliseconds Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand status took 5 milliseconds Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 10 milliseconds Oct 08 14:26:40 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 9 milliseconds Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:40 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:40 rivo volumio[3109]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:40 rivo volumio[3109]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 08 14:26:40 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:40 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:40 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:40 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:40 rivo volumio[3109]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 08 14:26:40 rivo volumio[3109]: info: ------------------------------ 95ms Oct 08 14:26:40 rivo volumio[3109]: info: ------------------------------ 88ms Oct 08 14:26:40 rivo volumio[3109]: info: ------------------------------ 88ms Oct 08 14:26:40 rivo volumio[3109]: info: [LastFM] Current track has sufficient metadata: title (You And Your Sister) and artist (This Mortal Coil) passed on explicitly Oct 08 14:26:40 rivo volumio[3109]: info: Signalling Playback active due to playback status change Oct 08 14:26:40 rivo volumio[3109]: info: MCU Signalled Playback Active Oct 08 14:26:40 rivo volumio[3109]: info: MCU Signalled Playback Inactive Oct 08 14:26:40 rivo volumio[3109]: info: MCU Signalled Playback Active Oct 08 14:26:41 rivo volumio[3109]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Stars at Noon","url":"https://www.last.fm/music/Tindersticks/_/Stars+at+Noon","duration":"0","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"7868","playcount":"25763","artist":{"name":"Tindersticks","mbid":"4306a798-e2f8-4192-9a45-2fd41cdae60c","url":"https://www.last.fm/music/Tindersticks"},"userplaycount":"3","userloved":"0","toptags":{"tag":{"name":"rain","url":"https://www.last.fm/tag/rain"}}}} Oct 08 14:26:41 rivo volumio[3109]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"You And Your Sister","mbid":"8241ed25-6abc-4bec-834d-1c2de0e1b2f7","url":"https://www.last.fm/music/This+Mortal+Coil/_/You+And+Your+Sister","duration":"197000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"34419","playcount":"139832","artist":{"name":"This Mortal Coil","mbid":"60ef8ddb-7676-4056-a357-9a8c228d03a6","url":"https://www.last.fm/music/This+Mortal+Coil"},"album":{"@":{"position":"6"},"artist":"This Mortal Coil","title":"Blood","mbid":"c7cea06b-a537-44ad-bd56-e27d41dcf83a","url":"https://www.last.fm/music/This+Mortal+Coil/Blood","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/7d10a0a72ea6487c84b2a918884a4111.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/7d10a0a72ea6487c84b2a918884a4111.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/7d10a0a72ea6487c84b2a918884a4111.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/7d10a0a72ea6487c84b2a918884a4111.png","@":{"size":"extralarge"}}]},"userplaycount":"6","userloved":"0","toptags":{"tag":[{"name":"alternative","url":"https://www.last.fm/tag/alternative"},{"name":"ambient","url":"https://www.last.fm/tag/ambient"},{"name":"female vocalists","url":"https://www.last.fm/tag/female+vocalists"},{"name":"4ad","url":"https://www.last.fm/tag/4ad"},{"name":"beautiful","url":"https://www.last.fm/tag/beautiful"}]}}} Oct 08 14:26:47 rivo volumio[3109]: info: CoreCommandRouter::volumioSeek Oct 08 14:26:47 rivo volumio[3109]: info: CoreStateMachine::seek Oct 08 14:26:47 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:47 rivo volumio[3109]: info: TRACKBLOCK {"uri":"qobuz://song/6019085","service":"qobuz","name":"You And Your Sister","title":"You And Your Sister","album":"Blood","type":"track","tracknumber":6,"volumeNumber":1,"albumart":"https://static.qobuz.com/images/covers/59/06/0652637300659_600.jpg","duration":194,"trackType":"qobuz","samplerate":"44.1 KHz","bitdepth":"16 bit","explicit":false,"artist":"This Mortal Coil","artistUri":"qobuz://artist/385962","albumUri":"qobuz://album/0652637300659","audioQuality":"","tagImage":""} Oct 08 14:26:47 rivo volumio[3109]: info: CoreStateMachine::startPlaybackTimer Oct 08 14:26:47 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:47 rivo volumio[3109]: info: [1728390407658] ControllerQobuz::seek Oct 08 14:26:47 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 14:26:47 rivo volumio[3109]: info: ControllerMpd::seek Oct 08 14:26:47 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:47 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:47 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:47 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/243035218 Oct 08 14:26:47 rivo volumio[3109]: info: [LastFM] Current track has sufficient metadata: title (Stars at Noon) and artist (Tindersticks) passed on explicitly Oct 08 14:26:47 rivo volumio[3109]: error: null Oct 08 14:26:47 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:26:47 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:26:47 rivo volumio[3109]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Stars at Noon","url":"https://www.last.fm/music/Tindersticks/_/Stars+at+Noon","duration":"0","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"7868","playcount":"25763","artist":{"name":"Tindersticks","mbid":"4306a798-e2f8-4192-9a45-2fd41cdae60c","url":"https://www.last.fm/music/Tindersticks"},"userplaycount":"3","userloved":"0","toptags":{"tag":{"name":"rain","url":"https://www.last.fm/tag/rain"}}}} Oct 08 14:26:48 rivo volumio[3109]: info: getStreamUrl took 616 milliseconds Oct 08 14:26:48 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=243035218&fmt=6&profile=raw&app_id=539451548&cid=1889513&etsp=1728394008&hmac=U5EZ_-JDy4JTOu5f0ruo72A4U-U Oct 08 14:26:48 rivo volumio[3109]: STREAMING PROXY: Response: 200, length: 18858530 Oct 08 14:26:48 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:26:48 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/243035218 Oct 08 14:26:48 rivo volumio[3109]: info: Oct 08 14:26:48 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:48 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:48 rivo volumio[3109]: info: Oct 08 14:26:48 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:48 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:48 rivo volumio[3109]: info: Oct 08 14:26:48 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:48 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:48 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:26:48 rivo volumio[3109]: info: Oct 08 14:26:48 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:48 rivo volumio[3109]: info: sendMpdCommand status took 27 milliseconds Oct 08 14:26:48 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:48 rivo volumio[3109]: info: sendMpdCommand status took 28 milliseconds Oct 08 14:26:48 rivo volumio[3109]: info: sendMpdCommand status took 27 milliseconds Oct 08 14:26:48 rivo volumio[3109]: info: sendMpdCommand status took 3 milliseconds Oct 08 14:26:48 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:48 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:48 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:48 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":53000,"duration":219,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"243035218","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/243035218","trackType":"qobuz"} Oct 08 14:26:48 rivo volumio[3109]: verbose: CURRENT POSITION 55 Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:48 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:48 rivo volumio[3109]: info: ------------------------------ 66ms Oct 08 14:26:48 rivo volumio[3109]: info: Oct 08 14:26:48 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:48 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:48 rivo volumio[3109]: info: Oct 08 14:26:48 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:48 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:48 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 40 milliseconds Oct 08 14:26:48 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 39 milliseconds Oct 08 14:26:48 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 40 milliseconds Oct 08 14:26:48 rivo volumio[3109]: info: sendMpdCommand status took 5 milliseconds Oct 08 14:26:48 rivo volumio[3109]: info: sendMpdCommand status took 3 milliseconds Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:48 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:48 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:48 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":53000,"duration":219,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"243035218","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/243035218","trackType":"qobuz"} Oct 08 14:26:48 rivo volumio[3109]: verbose: CURRENT POSITION 55 Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:48 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:48 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:48 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:48 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":53000,"duration":219,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"243035218","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/243035218","trackType":"qobuz"} Oct 08 14:26:48 rivo volumio[3109]: verbose: CURRENT POSITION 55 Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:48 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:48 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:48 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:48 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":53000,"duration":219,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"243035218","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/243035218","trackType":"qobuz"} Oct 08 14:26:48 rivo volumio[3109]: verbose: CURRENT POSITION 55 Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:48 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:48 rivo volumio[3109]: info: ------------------------------ 155ms Oct 08 14:26:48 rivo volumio[3109]: info: ------------------------------ 155ms Oct 08 14:26:48 rivo volumio[3109]: info: ------------------------------ 132ms Oct 08 14:26:48 rivo volumio[3109]: info: [LastFM] Current track has sufficient metadata: title (You And Your Sister) and artist (This Mortal Coil) passed on explicitly Oct 08 14:26:48 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 146 milliseconds Oct 08 14:26:48 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 146 milliseconds Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:48 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:48 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:48 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:48 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":53000,"duration":219,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"243035218","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/243035218","trackType":"qobuz"} Oct 08 14:26:48 rivo volumio[3109]: verbose: CURRENT POSITION 55 Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:48 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:48 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:48 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:48 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":53000,"duration":219,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"243035218","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/243035218","trackType":"qobuz"} Oct 08 14:26:48 rivo volumio[3109]: verbose: CURRENT POSITION 55 Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:48 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:48 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:48 rivo volumio[3109]: info: ------------------------------ 216ms Oct 08 14:26:48 rivo volumio[3109]: info: ------------------------------ 215ms Oct 08 14:26:49 rivo volumio[3109]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"You And Your Sister","mbid":"8241ed25-6abc-4bec-834d-1c2de0e1b2f7","url":"https://www.last.fm/music/This+Mortal+Coil/_/You+And+Your+Sister","duration":"197000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"34419","playcount":"139832","artist":{"name":"This Mortal Coil","mbid":"60ef8ddb-7676-4056-a357-9a8c228d03a6","url":"https://www.last.fm/music/This+Mortal+Coil"},"album":{"@":{"position":"6"},"artist":"This Mortal Coil","title":"Blood","mbid":"c7cea06b-a537-44ad-bd56-e27d41dcf83a","url":"https://www.last.fm/music/This+Mortal+Coil/Blood","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/7d10a0a72ea6487c84b2a918884a4111.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/7d10a0a72ea6487c84b2a918884a4111.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/7d10a0a72ea6487c84b2a918884a4111.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/7d10a0a72ea6487c84b2a918884a4111.png","@":{"size":"extralarge"}}]},"userplaycount":"6","userloved":"0","toptags":{"tag":[{"name":"alternative","url":"https://www.last.fm/tag/alternative"},{"name":"ambient","url":"https://www.last.fm/tag/ambient"},{"name":"female vocalists","url":"https://www.last.fm/tag/female+vocalists"},{"name":"4ad","url":"https://www.last.fm/tag/4ad"},{"name":"beautiful","url":"https://www.last.fm/tag/beautiful"}]}}} Oct 08 14:26:49 rivo volumio[3109]: info: getStreamUrl took 878 milliseconds Oct 08 14:26:49 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=243035218&fmt=6&profile=raw&app_id=539451548&cid=1889513&etsp=1728394009&hmac=KPsHZyt3Fl1DQQqiaW5u9gtJitE Oct 08 14:26:49 rivo volumio[3109]: STREAMING PROXY: Got range request: bytes=4618609- Oct 08 14:26:49 rivo volumio[3109]: STREAMING PROXY: Response: 206, length: 14239921 Oct 08 14:26:50 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:26:50 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/243035218 Oct 08 14:26:50 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:26:50 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:26:51 rivo volumio[3109]: info: getStreamUrl took 471 milliseconds Oct 08 14:26:51 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=243035218&fmt=6&profile=raw&app_id=539451548&cid=1889513&etsp=1728394010&hmac=LYBjuascMsaAwGt9ssMbIJURoEs Oct 08 14:26:51 rivo volumio[3109]: STREAMING PROXY: Got range request: bytes=22542- Oct 08 14:26:51 rivo volumio[3109]: STREAMING PROXY: Response: 206, length: 18835988 Oct 08 14:26:51 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:26:52 rivo volumio[3109]: info: CoreCommandRouter::volumioNext Oct 08 14:26:52 rivo volumio[3109]: info: CoreStateMachine::next Oct 08 14:26:52 rivo volumio[3109]: info: [1728390412518] ControllerQobuz::next Oct 08 14:26:52 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:52 rivo volumio[3109]: info: CoreStateMachine::next Oct 08 14:26:52 rivo volumio[3109]: info: CoreStateMachine::stop Oct 08 14:26:52 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:52 rivo volumio[3109]: info: CoreStateMachine::stPlaybackTimer Oct 08 14:26:52 rivo volumio[3109]: info: CoreStateMachine::updateTrackBlock Oct 08 14:26:52 rivo volumio[3109]: info: CorePlayQueue::getTrackBlock Oct 08 14:26:52 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:52 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:52 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:52 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:52 rivo volumio[3109]: info: CoreStateMachine::serviceStop Oct 08 14:26:52 rivo volumio[3109]: info: CorePlayQueue::getTrack 55 Oct 08 14:26:52 rivo volumio[3109]: info: CoreCommandRouter::serviceStop Oct 08 14:26:52 rivo volumio[3109]: info: [1728390412535] ControllerQobuz::stop Oct 08 14:26:52 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 14:26:52 rivo volumio[3109]: info: ControllerMpd::stop Oct 08 14:26:52 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand stop Oct 08 14:26:52 rivo volumio[3109]: info: sendMpdCommand stop took 41 milliseconds Oct 08 14:26:52 rivo volumio[3109]: info: CoreStateMachine::play index undefined Oct 08 14:26:52 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:52 rivo volumio[3109]: info: CorePlayQueue::getTrack 56 Oct 08 14:26:52 rivo volumio[3109]: info: CoreStateMachine::startPlaybackTimer Oct 08 14:26:52 rivo volumio[3109]: info: CorePlayQueue::getTrack 56 Oct 08 14:26:52 rivo volumio[3109]: info: [1728390412578] ControllerQobuz::clearAddPlayTrack Oct 08 14:26:52 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand stop Oct 08 14:26:52 rivo volumio[3109]: info: CoreStateMachine::updateTrackBlock Oct 08 14:26:52 rivo volumio[3109]: info: CorePlayQueue::getTrackBlock Oct 08 14:26:52 rivo volumio[3109]: info: Oct 08 14:26:52 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:52 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:52 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:52 rivo volumio[3109]: info: sendMpdCommand stop took 2 milliseconds Oct 08 14:26:52 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand clear Oct 08 14:26:52 rivo volumio[3109]: info: Oct 08 14:26:52 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:52 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:52 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:52 rivo volumio[3109]: info: Oct 08 14:26:52 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:52 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:52 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:52 rivo volumio[3109]: info: Oct 08 14:26:52 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:52 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:52 rivo volumio[3109]: info: sendMpdCommand status took 6 milliseconds Oct 08 14:26:52 rivo volumio[3109]: info: sendMpdCommand clear took 5 milliseconds Oct 08 14:26:52 rivo volumio[3109]: info: sendMpdCommand status took 4 milliseconds Oct 08 14:26:52 rivo volumio[3109]: info: sendMpdCommand status took 3 milliseconds Oct 08 14:26:52 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:52 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:52 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/7290579" Oct 08 14:26:52 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:52 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:52 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:52 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:52 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:52 rivo volumio[3109]: info: CorePlayQueue::getTrack 56 Oct 08 14:26:52 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:52 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/7290579 Oct 08 14:26:52 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:52 rivo volumio[3109]: info: CorePlayQueue::getTrack 56 Oct 08 14:26:52 rivo volumio[3109]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 08 14:26:52 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:52 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:52 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:52 rivo volumio[3109]: info: CorePlayQueue::getTrack 56 Oct 08 14:26:52 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:52 rivo volumio[3109]: info: CorePlayQueue::getTrack 56 Oct 08 14:26:52 rivo volumio[3109]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 08 14:26:52 rivo volumio[3109]: info: ------------------------------ 37ms Oct 08 14:26:52 rivo volumio[3109]: info: ------------------------------ 35ms Oct 08 14:26:52 rivo volumio[3109]: info: Oct 08 14:26:52 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:52 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:52 rivo volumio[3109]: info: Oct 08 14:26:52 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:52 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:52 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:52 rivo volumio[3109]: info: ------------------------------ 38ms Oct 08 14:26:52 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 36 milliseconds Oct 08 14:26:52 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:52 rivo volumio[3109]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 08 14:26:52 rivo volumio[3109]: info: ------------------------------ 46ms Oct 08 14:26:52 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:26:52 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:26:52 rivo volumio[3109]: info: MCU Signalled Playback Inactive Oct 08 14:26:53 rivo volumio[3109]: info: getStreamUrl took 569 milliseconds Oct 08 14:26:53 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=7290579&fmt=6&profile=raw&app_id=539451548&cid=1889513&etsp=1728394013&hmac=ylKK0UnVOKeMHxnNgdlcMsyopD8 Oct 08 14:26:53 rivo volumio[3109]: STREAMING PROXY: Response: 200, length: 17566913 Oct 08 14:26:53 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/7290579" Oct 08 14:26:53 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:53 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:53 rivo volumio[3109]: info: Oct 08 14:26:53 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:53 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:53 rivo volumio[3109]: info: ------------------------------ 667ms Oct 08 14:26:53 rivo volumio[3109]: info: ------------------------------ 666ms Oct 08 14:26:53 rivo volumio[3109]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/7290579" took 2 milliseconds Oct 08 14:26:53 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand play Oct 08 14:26:53 rivo volumio[3109]: info: Oct 08 14:26:53 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:53 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:53 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/7290579 Oct 08 14:26:53 rivo volumio[3109]: info: Oct 08 14:26:53 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:53 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:53 rivo volumio[3109]: info: ------------------------------ 9ms Oct 08 14:26:53 rivo volumio[3109]: info: sendMpdCommand play took 7 milliseconds Oct 08 14:26:53 rivo volumio[3109]: info: ------------------------------ 4ms Oct 08 14:26:53 rivo volumio[3109]: info: ------------------------------ 3ms Oct 08 14:26:53 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:26:53 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:26:53 rivo volumio[3109]: info: getStreamUrl took 483 milliseconds Oct 08 14:26:53 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=7290579&fmt=6&profile=raw&app_id=539451548&cid=1889513&etsp=1728394013&hmac=ylKK0UnVOKeMHxnNgdlcMsyopD8 Oct 08 14:26:53 rivo volumio[3109]: STREAMING PROXY: Response: 200, length: 17566913 Oct 08 14:26:53 rivo volumio[3109]: info: Oct 08 14:26:53 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:53 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:53 rivo volumio[3109]: info: Oct 08 14:26:53 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:53 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:53 rivo volumio[3109]: info: Oct 08 14:26:53 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:53 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:53 rivo volumio[3109]: info: Oct 08 14:26:53 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:53 rivo volumio[3109]: info: sendMpdCommand status took 39 milliseconds Oct 08 14:26:53 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:53 rivo volumio[3109]: info: sendMpdCommand status took 40 milliseconds Oct 08 14:26:53 rivo volumio[3109]: info: sendMpdCommand status took 41 milliseconds Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:53 rivo volumio[3109]: info: Oct 08 14:26:53 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:53 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:53 rivo volumio[3109]: info: Oct 08 14:26:53 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:53 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:53 rivo volumio[3109]: info: sendMpdCommand status took 25 milliseconds Oct 08 14:26:53 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 20 milliseconds Oct 08 14:26:53 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 19 milliseconds Oct 08 14:26:53 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 18 milliseconds Oct 08 14:26:53 rivo volumio[3109]: info: sendMpdCommand status took 16 milliseconds Oct 08 14:26:53 rivo volumio[3109]: info: sendMpdCommand status took 13 milliseconds Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:53 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:53 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:53 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:53 rivo volumio[3109]: info: CorePlayQueue::getTrack 56 Oct 08 14:26:53 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":192,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"7290579","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/7290579","trackType":"qobuz"} Oct 08 14:26:53 rivo volumio[3109]: verbose: CURRENT POSITION 56 Oct 08 14:26:53 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:53 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus stop Oct 08 14:26:53 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:53 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:53 rivo volumio[3109]: info: CorePlayQueue::getTrack 56 Oct 08 14:26:53 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":192,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"647 Kbps","isStreaming":false,"title":"7290579","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/7290579","trackType":"qobuz"} Oct 08 14:26:53 rivo volumio[3109]: verbose: CURRENT POSITION 56 Oct 08 14:26:53 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:53 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:53 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:53 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:53 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:53 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:53 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:53 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:53 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:53 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:53 rivo volumio[3109]: info: CorePlayQueue::getTrack 56 Oct 08 14:26:53 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":192,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"647 Kbps","isStreaming":false,"title":"7290579","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/7290579","trackType":"qobuz"} Oct 08 14:26:53 rivo volumio[3109]: verbose: CURRENT POSITION 56 Oct 08 14:26:53 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:53 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:53 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:53 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:53 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:53 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:53 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:53 rivo volumio[3109]: info: ------------------------------ 118ms Oct 08 14:26:54 rivo volumio[3109]: info: ------------------------------ 180ms Oct 08 14:26:54 rivo volumio[3109]: info: ------------------------------ 180ms Oct 08 14:26:54 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 114 milliseconds Oct 08 14:26:54 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 110 milliseconds Oct 08 14:26:54 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 109 milliseconds Oct 08 14:26:54 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:54 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:54 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:54 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:54 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:54 rivo volumio[3109]: info: CorePlayQueue::getTrack 56 Oct 08 14:26:54 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":297,"duration":192,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"680 Kbps","isStreaming":false,"title":"7290579","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/7290579","trackType":"qobuz"} Oct 08 14:26:54 rivo volumio[3109]: verbose: CURRENT POSITION 56 Oct 08 14:26:54 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:54 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:54 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:54 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:54 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:54 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:54 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:54 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:54 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:54 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:54 rivo volumio[3109]: info: CorePlayQueue::getTrack 56 Oct 08 14:26:54 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":297,"duration":192,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"680 Kbps","isStreaming":false,"title":"7290579","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/7290579","trackType":"qobuz"} Oct 08 14:26:54 rivo volumio[3109]: verbose: CURRENT POSITION 56 Oct 08 14:26:54 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:54 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:54 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:54 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:54 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:54 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:54 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:54 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:54 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:54 rivo volumio[3109]: info: CorePlayQueue::getTrack 56 Oct 08 14:26:54 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":297,"duration":192,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"680 Kbps","isStreaming":false,"title":"7290579","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/7290579","trackType":"qobuz"} Oct 08 14:26:54 rivo volumio[3109]: verbose: CURRENT POSITION 56 Oct 08 14:26:54 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:54 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:54 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:54 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:54 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:54 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:54 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:54 rivo volumio[3109]: info: ------------------------------ 295ms Oct 08 14:26:54 rivo volumio[3109]: info: ------------------------------ 283ms Oct 08 14:26:54 rivo volumio[3109]: info: ------------------------------ 282ms Oct 08 14:26:54 rivo volumio[3109]: info: [LastFM] Current track has sufficient metadata: title (Tcheren Deya) and artist (Mathias Duplessy) passed on explicitly Oct 08 14:26:54 rivo volumio[3109]: info: Signalling Playback active due to playback status change Oct 08 14:26:54 rivo volumio[3109]: info: MCU Signalled Playback Active Oct 08 14:26:54 rivo volumio[3109]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Tcheren Deya","url":"https://www.last.fm/music/Mathias+Duplessy/_/Tcheren+Deya","duration":"192000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"6147","playcount":"25047","artist":{"name":"Mathias Duplessy","url":"https://www.last.fm/music/Mathias+Duplessy"},"album":{"artist":"Mathias Duplessy","title":"My Mongolia","url":"https://www.last.fm/music/Mathias+Duplessy/My+Mongolia","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/55ab46fb0d4c4560a39b35a188fe69c5.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/55ab46fb0d4c4560a39b35a188fe69c5.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/55ab46fb0d4c4560a39b35a188fe69c5.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/55ab46fb0d4c4560a39b35a188fe69c5.png","@":{"size":"extralarge"}}]},"userplaycount":"6","userloved":"0","toptags":{"tag":[{"name":"fip","url":"https://www.last.fm/tag/fip"},{"name":"faworytne","url":"https://www.last.fm/tag/faworytne"},{"name":"plons","url":"https://www.last.fm/tag/plons"},{"name":"bajki z marsa","url":"https://www.last.fm/tag/bajki+z+marsa"}]}}} Oct 08 14:26:55 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 08 14:26:55 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 08 14:26:55 rivo volumio[3109]: info: Discovery: Getting this device information Oct 08 14:26:55 rivo volumio[3109]: info: CoreCommandRouter::volumioGetState Oct 08 14:26:55 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 08 14:26:55 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:26:57 rivo volumio[3109]: info: CoreCommandRouter::volumioNext Oct 08 14:26:57 rivo volumio[3109]: info: CoreStateMachine::next Oct 08 14:26:57 rivo volumio[3109]: info: [1728390417164] ControllerQobuz::next Oct 08 14:26:57 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:57 rivo volumio[3109]: info: CoreStateMachine::next Oct 08 14:26:57 rivo volumio[3109]: info: CoreStateMachine::stop Oct 08 14:26:57 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:57 rivo volumio[3109]: info: CoreStateMachine::stPlaybackTimer Oct 08 14:26:57 rivo volumio[3109]: info: CoreStateMachine::updateTrackBlock Oct 08 14:26:57 rivo volumio[3109]: info: CorePlayQueue::getTrackBlock Oct 08 14:26:57 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:57 rivo volumio[3109]: info: CorePlayQueue::getTrack 56 Oct 08 14:26:57 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:57 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:57 rivo volumio[3109]: info: CoreStateMachine::serviceStop Oct 08 14:26:57 rivo volumio[3109]: info: CorePlayQueue::getTrack 56 Oct 08 14:26:57 rivo volumio[3109]: info: CoreCommandRouter::serviceStop Oct 08 14:26:57 rivo volumio[3109]: info: [1728390417170] ControllerQobuz::stop Oct 08 14:26:57 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 14:26:57 rivo volumio[3109]: info: ControllerMpd::stop Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand stop Oct 08 14:26:57 rivo volumio[3109]: info: Oct 08 14:26:57 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:57 rivo volumio[3109]: info: sendMpdCommand stop took 48 milliseconds Oct 08 14:26:57 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:57 rivo volumio[3109]: info: CoreStateMachine::play index undefined Oct 08 14:26:57 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:26:57 rivo volumio[3109]: info: CorePlayQueue::getTrack 57 Oct 08 14:26:57 rivo volumio[3109]: info: CoreStateMachine::startPlaybackTimer Oct 08 14:26:57 rivo volumio[3109]: info: CorePlayQueue::getTrack 57 Oct 08 14:26:57 rivo volumio[3109]: info: [1728390417221] ControllerQobuz::clearAddPlayTrack Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand stop Oct 08 14:26:57 rivo volumio[3109]: info: CoreStateMachine::updateTrackBlock Oct 08 14:26:57 rivo volumio[3109]: info: CorePlayQueue::getTrackBlock Oct 08 14:26:57 rivo volumio[3109]: info: Oct 08 14:26:57 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:57 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:57 rivo volumio[3109]: info: Oct 08 14:26:57 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:57 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:57 rivo volumio[3109]: info: sendMpdCommand status took 8 milliseconds Oct 08 14:26:57 rivo volumio[3109]: info: sendMpdCommand stop took 7 milliseconds Oct 08 14:26:57 rivo volumio[3109]: info: sendMpdCommand status took 4 milliseconds Oct 08 14:26:57 rivo volumio[3109]: info: sendMpdCommand status took 2 milliseconds Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand clear Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:57 rivo volumio[3109]: info: Oct 08 14:26:57 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:57 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:57 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 08 14:26:57 rivo volumio[3109]: info: sendMpdCommand clear took 5 milliseconds Oct 08 14:26:57 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 08 14:26:57 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 5 milliseconds Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/2328986" Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:57 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:57 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:57 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:57 rivo volumio[3109]: info: CorePlayQueue::getTrack 57 Oct 08 14:26:57 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:57 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:57 rivo volumio[3109]: info: CorePlayQueue::getTrack 57 Oct 08 14:26:57 rivo volumio[3109]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 08 14:26:57 rivo volumio[3109]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 08 14:26:57 rivo volumio[3109]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 08 14:26:57 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/2328986 Oct 08 14:26:57 rivo volumio[3109]: info: ------------------------------ 29ms Oct 08 14:26:57 rivo volumio[3109]: info: ------------------------------ 23ms Oct 08 14:26:57 rivo volumio[3109]: info: ------------------------------ 21ms Oct 08 14:26:57 rivo volumio[3109]: info: Oct 08 14:26:57 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:57 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:57 rivo volumio[3109]: info: Oct 08 14:26:57 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:57 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:57 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:57 rivo volumio[3109]: info: ------------------------------ 18ms Oct 08 14:26:57 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:26:57 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:26:57 rivo volumio[3109]: info: MCU Signalled Playback Inactive Oct 08 14:26:57 rivo volumio[3109]: info: getStreamUrl took 562 milliseconds Oct 08 14:26:57 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=2328986&fmt=6&profile=raw&app_id=539451548&cid=1889513&etsp=1728394017&hmac=VT5660WuyL1bgkCCC51ouecGTQo Oct 08 14:26:57 rivo volumio[3109]: STREAMING PROXY: Response: 200, length: 12113545 Oct 08 14:26:57 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:26:57 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:57 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/2328986" Oct 08 14:26:57 rivo volumio[3109]: info: ------------------------------ 632ms Oct 08 14:26:57 rivo volumio[3109]: info: ------------------------------ 631ms Oct 08 14:26:57 rivo volumio[3109]: info: Oct 08 14:26:57 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:57 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:57 rivo volumio[3109]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/2328986" took 2 milliseconds Oct 08 14:26:57 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 14:26:57 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand play Oct 08 14:26:57 rivo volumio[3109]: info: Oct 08 14:26:57 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:57 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:57 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/2328986 Oct 08 14:26:57 rivo volumio[3109]: info: Oct 08 14:26:57 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:26:57 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:26:57 rivo volumio[3109]: info: ------------------------------ 6ms Oct 08 14:26:57 rivo volumio[3109]: info: sendMpdCommand play took 6 milliseconds Oct 08 14:26:57 rivo volumio[3109]: info: ------------------------------ 4ms Oct 08 14:26:57 rivo volumio[3109]: info: ------------------------------ 3ms Oct 08 14:26:57 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:26:57 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:26:58 rivo volumio[3109]: info: getStreamUrl took 459 milliseconds Oct 08 14:26:58 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=2328986&fmt=6&profile=raw&app_id=539451548&cid=1889513&etsp=1728394018&hmac=yrTaCCdiB5etLrSrZgJ4wX6xC50 Oct 08 14:26:58 rivo volumio[3109]: STREAMING PROXY: Response: 200, length: 12113545 Oct 08 14:26:58 rivo volumio[3109]: info: Oct 08 14:26:58 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:58 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:58 rivo volumio[3109]: info: Oct 08 14:26:58 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:58 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:58 rivo volumio[3109]: info: Oct 08 14:26:58 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:58 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:58 rivo volumio[3109]: info: Oct 08 14:26:58 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:58 rivo volumio[3109]: info: sendMpdCommand status took 15 milliseconds Oct 08 14:26:58 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:58 rivo volumio[3109]: info: sendMpdCommand status took 14 milliseconds Oct 08 14:26:58 rivo volumio[3109]: info: sendMpdCommand status took 13 milliseconds Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:58 rivo volumio[3109]: info: sendMpdCommand status took 4 milliseconds Oct 08 14:26:58 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:58 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:58 rivo volumio[3109]: info: CorePlayQueue::getTrack 57 Oct 08 14:26:58 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":124,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2328986","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/2328986","trackType":"qobuz"} Oct 08 14:26:58 rivo volumio[3109]: verbose: CURRENT POSITION 57 Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus stop Oct 08 14:26:58 rivo volumio[3109]: info: ------------------------------ 24ms Oct 08 14:26:58 rivo volumio[3109]: info: Oct 08 14:26:58 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:58 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:58 rivo volumio[3109]: info: Oct 08 14:26:58 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:26:58 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:26:58 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 69 milliseconds Oct 08 14:26:58 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 70 milliseconds Oct 08 14:26:58 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 67 milliseconds Oct 08 14:26:58 rivo volumio[3109]: info: sendMpdCommand status took 65 milliseconds Oct 08 14:26:58 rivo volumio[3109]: info: sendMpdCommand status took 63 milliseconds Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:26:58 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:58 rivo volumio[3109]: info: CorePlayQueue::getTrack 57 Oct 08 14:26:58 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":124,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2328986","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/2328986","trackType":"qobuz"} Oct 08 14:26:58 rivo volumio[3109]: verbose: CURRENT POSITION 57 Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:58 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:58 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:58 rivo volumio[3109]: info: CorePlayQueue::getTrack 57 Oct 08 14:26:58 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":124,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2328986","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/2328986","trackType":"qobuz"} Oct 08 14:26:58 rivo volumio[3109]: verbose: CURRENT POSITION 57 Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:58 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:58 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:58 rivo volumio[3109]: info: CorePlayQueue::getTrack 57 Oct 08 14:26:58 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":124,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"2328986","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/2328986","trackType":"qobuz"} Oct 08 14:26:58 rivo volumio[3109]: verbose: CURRENT POSITION 57 Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:58 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:58 rivo volumio[3109]: info: ------------------------------ 129ms Oct 08 14:26:58 rivo volumio[3109]: info: ------------------------------ 128ms Oct 08 14:26:58 rivo volumio[3109]: info: ------------------------------ 118ms Oct 08 14:26:58 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 46 milliseconds Oct 08 14:26:58 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 47 milliseconds Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:58 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:26:58 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:58 rivo volumio[3109]: info: CorePlayQueue::getTrack 57 Oct 08 14:26:58 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":983,"duration":124,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"596 Kbps","isStreaming":false,"title":"2328986","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/2328986","trackType":"qobuz"} Oct 08 14:26:58 rivo volumio[3109]: verbose: CURRENT POSITION 57 Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:58 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:58 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:26:58 rivo volumio[3109]: info: CorePlayQueue::getTrack 57 Oct 08 14:26:58 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":983,"duration":124,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"564 Kbps","isStreaming":false,"title":"2328986","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/2328986","trackType":"qobuz"} Oct 08 14:26:58 rivo volumio[3109]: verbose: CURRENT POSITION 57 Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:26:58 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:26:58 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:26:58 rivo volumio[3109]: info: ------------------------------ 146ms Oct 08 14:26:58 rivo volumio[3109]: info: ------------------------------ 146ms Oct 08 14:26:58 rivo volumio[3109]: info: [LastFM] Current track has sufficient metadata: title (Hold Heart) and artist (Emiliana Torrini) passed on explicitly Oct 08 14:26:58 rivo volumio[3109]: info: Signalling Playback active due to playback status change Oct 08 14:26:58 rivo volumio[3109]: info: MCU Signalled Playback Active Oct 08 14:26:58 rivo volumio[3109]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Hold Heart","url":"https://www.last.fm/music/Emil%C3%ADana+Torrini/_/Hold+Heart","duration":"124000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"99097","playcount":"516356","artist":{"name":"Emilíana Torrini","mbid":"b2a9731b-9e13-4ff9-af21-5e694a5663e8","url":"https://www.last.fm/music/Emil%C3%ADana+Torrini"},"album":{"artist":"Various Artists","title":"Liebe ist... Best Of","url":"https://www.last.fm/music/Various+Artists/Liebe+ist...+Best+Of","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/213b305528ae4e9ab23d8b4648fddab5.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/213b305528ae4e9ab23d8b4648fddab5.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/213b305528ae4e9ab23d8b4648fddab5.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/213b305528ae4e9ab23d8b4648fddab5.png","@":{"size":"extralarge"}}]},"userplaycount":"3","userloved":"0","toptags":{"tag":[{"name":"female vocalists","url":"https://www.last.fm/tag/female+vocalists"},{"name":"chillout","url":"https://www.last.fm/tag/chillout"},{"name":"alternative","url":"https://www.last.fm/tag/alternative"},{"name":"icelandic","url":"https://www.last.fm/tag/icelandic"},{"name":"pop","url":"https://www.last.fm/tag/pop"}]},"wiki":{"published":"01 May 2010, 12:18","summary":"eighth track off the album Me And Armini (2008) release through Roughtrade label Read more on Last.fm.","content":"eighth track off the album Me And Armini (2008) release through Roughtrade label Read more on Last.fm. User-contributed text is available under the Creative Commons By-SA License; additional terms may apply."}}} Oct 08 14:26:59 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:27:00 rivo volumio[3109]: info: CoreCommandRouter::volumioNext Oct 08 14:27:00 rivo volumio[3109]: info: CoreStateMachine::next Oct 08 14:27:00 rivo volumio[3109]: info: [1728390420448] ControllerQobuz::next Oct 08 14:27:00 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:27:00 rivo volumio[3109]: info: CoreStateMachine::next Oct 08 14:27:00 rivo volumio[3109]: info: CoreStateMachine::stop Oct 08 14:27:00 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:27:00 rivo volumio[3109]: info: CoreStateMachine::stPlaybackTimer Oct 08 14:27:00 rivo volumio[3109]: info: CoreStateMachine::updateTrackBlock Oct 08 14:27:00 rivo volumio[3109]: info: CorePlayQueue::getTrackBlock Oct 08 14:27:00 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:27:00 rivo volumio[3109]: info: CorePlayQueue::getTrack 57 Oct 08 14:27:00 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:27:00 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:27:00 rivo volumio[3109]: info: CoreStateMachine::serviceStop Oct 08 14:27:00 rivo volumio[3109]: info: CorePlayQueue::getTrack 57 Oct 08 14:27:00 rivo volumio[3109]: info: CoreCommandRouter::serviceStop Oct 08 14:27:00 rivo volumio[3109]: info: [1728390420468] ControllerQobuz::stop Oct 08 14:27:00 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 14:27:00 rivo volumio[3109]: info: ControllerMpd::stop Oct 08 14:27:00 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand stop Oct 08 14:27:00 rivo volumio[3109]: info: sendMpdCommand stop took 46 milliseconds Oct 08 14:27:00 rivo volumio[3109]: info: CoreStateMachine::play index undefined Oct 08 14:27:00 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 14:27:00 rivo volumio[3109]: info: CorePlayQueue::getTrack 58 Oct 08 14:27:00 rivo volumio[3109]: info: CoreStateMachine::startPlaybackTimer Oct 08 14:27:00 rivo volumio[3109]: info: CorePlayQueue::getTrack 58 Oct 08 14:27:00 rivo volumio[3109]: info: [1728390420521] ControllerQobuz::clearAddPlayTrack Oct 08 14:27:00 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand stop Oct 08 14:27:00 rivo volumio[3109]: info: CoreStateMachine::updateTrackBlock Oct 08 14:27:00 rivo volumio[3109]: info: CorePlayQueue::getTrackBlock Oct 08 14:27:00 rivo volumio[3109]: info: Oct 08 14:27:00 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:27:00 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:27:00 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:27:00 rivo volumio[3109]: info: sendMpdCommand stop took 3 milliseconds Oct 08 14:27:00 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand clear Oct 08 14:27:00 rivo volumio[3109]: info: Oct 08 14:27:00 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:27:00 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:27:00 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:27:00 rivo volumio[3109]: info: Oct 08 14:27:00 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:27:00 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:27:00 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:27:00 rivo volumio[3109]: info: Oct 08 14:27:00 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:27:00 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:27:00 rivo volumio[3109]: info: sendMpdCommand status took 9 milliseconds Oct 08 14:27:00 rivo volumio[3109]: info: sendMpdCommand clear took 10 milliseconds Oct 08 14:27:00 rivo volumio[3109]: info: sendMpdCommand status took 5 milliseconds Oct 08 14:27:00 rivo volumio[3109]: info: sendMpdCommand status took 4 milliseconds Oct 08 14:27:00 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:27:00 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:27:00 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/58344690" Oct 08 14:27:00 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:27:00 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:27:00 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:27:00 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:27:00 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:27:00 rivo volumio[3109]: info: CorePlayQueue::getTrack 58 Oct 08 14:27:00 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:27:00 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/58344690 Oct 08 14:27:00 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:27:00 rivo volumio[3109]: info: CorePlayQueue::getTrack 58 Oct 08 14:27:00 rivo volumio[3109]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 08 14:27:00 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:27:00 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:27:00 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:27:00 rivo volumio[3109]: info: CorePlayQueue::getTrack 58 Oct 08 14:27:00 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:27:00 rivo volumio[3109]: info: CorePlayQueue::getTrack 58 Oct 08 14:27:00 rivo volumio[3109]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Oct 08 14:27:00 rivo volumio[3109]: info: ------------------------------ 33ms Oct 08 14:27:00 rivo volumio[3109]: info: ------------------------------ 29ms Oct 08 14:27:00 rivo volumio[3109]: info: Oct 08 14:27:00 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:27:00 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:27:00 rivo volumio[3109]: info: Oct 08 14:27:00 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:27:00 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:27:00 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:27:00 rivo volumio[3109]: info: ------------------------------ 32ms Oct 08 14:27:00 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 30 milliseconds Oct 08 14:27:00 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:27:00 rivo volumio[3109]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Oct 08 14:27:00 rivo volumio[3109]: info: ------------------------------ 44ms Oct 08 14:27:00 rivo volumio[3109]: info: MCU Signalled Playback Inactive Oct 08 14:27:00 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:27:00 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:27:01 rivo volumio[3109]: info: getStreamUrl took 629 milliseconds Oct 08 14:27:01 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=58344690&fmt=6&profile=raw&app_id=539451548&cid=1889513&etsp=1728394021&hmac=aTasYeXWubapovqU5-hYVSLFXvI Oct 08 14:27:01 rivo volumio[3109]: STREAMING PROXY: Response: 200, length: 25389567 Oct 08 14:27:01 rivo volumio[3109]: STREAMING PROXY: Client dropped request, destroying Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/58344690" Oct 08 14:27:01 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:27:01 rivo volumio[3109]: error: updateQueue error: null Oct 08 14:27:01 rivo volumio[3109]: info: Oct 08 14:27:01 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:27:01 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:27:01 rivo volumio[3109]: info: ------------------------------ 710ms Oct 08 14:27:01 rivo volumio[3109]: info: ------------------------------ 708ms Oct 08 14:27:01 rivo volumio[3109]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/58344690" took 3 milliseconds Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand play Oct 08 14:27:01 rivo volumio[3109]: info: Oct 08 14:27:01 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:27:01 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:27:01 rivo volumio[3109]: info: Oct 08 14:27:01 rivo volumio[3109]: ---------------------------- MPD announces system playlist update Oct 08 14:27:01 rivo volumio[3109]: info: Ignoring MPD Status Update Oct 08 14:27:01 rivo volumio[3109]: STREAMING PROXY: Handling url /?data=qobuz://song/58344690 Oct 08 14:27:01 rivo volumio[3109]: info: ------------------------------ 9ms Oct 08 14:27:01 rivo volumio[3109]: info: sendMpdCommand play took 8 milliseconds Oct 08 14:27:01 rivo volumio[3109]: info: ------------------------------ 8ms Oct 08 14:27:01 rivo volumio[3109]: info: ------------------------------ 7ms Oct 08 14:27:01 rivo volumio[3109]: info: Executing endpoint getStreamUrlqobuz Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 08 14:27:01 rivo volumio[3109]: info: getStreamUrl took 513 milliseconds Oct 08 14:27:01 rivo volumio[3109]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=280707&eid=58344690&fmt=6&profile=raw&app_id=539451548&cid=1889513&etsp=1728394021&hmac=aTasYeXWubapovqU5-hYVSLFXvI Oct 08 14:27:01 rivo volumio[3109]: STREAMING PROXY: Response: 200, length: 25389567 Oct 08 14:27:01 rivo volumio[3109]: info: Oct 08 14:27:01 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:27:01 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:27:01 rivo volumio[3109]: info: Oct 08 14:27:01 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:27:01 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:27:01 rivo volumio[3109]: info: Oct 08 14:27:01 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:27:01 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:27:01 rivo volumio[3109]: info: Oct 08 14:27:01 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:27:01 rivo volumio[3109]: info: sendMpdCommand status took 35 milliseconds Oct 08 14:27:01 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:27:01 rivo volumio[3109]: info: sendMpdCommand status took 34 milliseconds Oct 08 14:27:01 rivo volumio[3109]: info: sendMpdCommand status took 33 milliseconds Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:27:01 rivo volumio[3109]: info: Oct 08 14:27:01 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:27:01 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:27:01 rivo volumio[3109]: info: Oct 08 14:27:01 rivo volumio[3109]: ---------------------------- MPD announces state update: player Oct 08 14:27:01 rivo volumio[3109]: info: ControllerMpd::getState Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand status Oct 08 14:27:01 rivo volumio[3109]: info: sendMpdCommand status took 15 milliseconds Oct 08 14:27:01 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 9 milliseconds Oct 08 14:27:01 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 8 milliseconds Oct 08 14:27:01 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 7 milliseconds Oct 08 14:27:01 rivo volumio[3109]: info: sendMpdCommand status took 5 milliseconds Oct 08 14:27:01 rivo volumio[3109]: info: sendMpdCommand status took 4 milliseconds Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::parseState Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 14:27:01 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:27:01 rivo volumio[3109]: info: CorePlayQueue::getTrack 58 Oct 08 14:27:01 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":314,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"58344690","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/58344690","trackType":"qobuz"} Oct 08 14:27:01 rivo volumio[3109]: verbose: CURRENT POSITION 58 Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus stop Oct 08 14:27:01 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:27:01 rivo volumio[3109]: info: CorePlayQueue::getTrack 58 Oct 08 14:27:01 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":91,"duration":314,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"456 Kbps","isStreaming":false,"title":"58344690","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/58344690","trackType":"qobuz"} Oct 08 14:27:01 rivo volumio[3109]: verbose: CURRENT POSITION 58 Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:27:01 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:27:01 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:27:01 rivo volumio[3109]: info: CorePlayQueue::getTrack 58 Oct 08 14:27:01 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":91,"duration":314,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"456 Kbps","isStreaming":false,"title":"58344690","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/58344690","trackType":"qobuz"} Oct 08 14:27:01 rivo volumio[3109]: verbose: CURRENT POSITION 58 Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:27:01 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:27:01 rivo volumio[3109]: info: ------------------------------ 86ms Oct 08 14:27:01 rivo volumio[3109]: info: ------------------------------ 102ms Oct 08 14:27:01 rivo volumio[3109]: info: ------------------------------ 102ms Oct 08 14:27:01 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 53 milliseconds Oct 08 14:27:01 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 46 milliseconds Oct 08 14:27:01 rivo volumio[3109]: info: sendMpdCommand playlistinfo took 45 milliseconds Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:27:01 rivo volumio[3109]: verbose: ControllerMpd::parseTrackInfo Oct 08 14:27:01 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:27:01 rivo volumio[3109]: info: CorePlayQueue::getTrack 58 Oct 08 14:27:01 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":549,"duration":314,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"464 Kbps","isStreaming":false,"title":"58344690","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/58344690","trackType":"qobuz"} Oct 08 14:27:01 rivo volumio[3109]: verbose: CURRENT POSITION 58 Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:27:01 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:27:01 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:27:01 rivo volumio[3109]: info: CorePlayQueue::getTrack 58 Oct 08 14:27:01 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":571,"duration":314,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"464 Kbps","isStreaming":false,"title":"58344690","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/58344690","trackType":"qobuz"} Oct 08 14:27:01 rivo volumio[3109]: verbose: CURRENT POSITION 58 Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:27:01 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:27:01 rivo volumio[3109]: info: ControllerMpd::pushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::servicePushState Oct 08 14:27:01 rivo volumio[3109]: info: CorePlayQueue::getTrack 58 Oct 08 14:27:01 rivo volumio[3109]: verbose: STATE SERVICE {"status":"play","position":0,"seek":571,"duration":314,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"464 Kbps","isStreaming":false,"title":"58344690","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/58344690","trackType":"qobuz"} Oct 08 14:27:01 rivo volumio[3109]: verbose: CURRENT POSITION 58 Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::syncState stateService play Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::syncState currentStatus play Oct 08 14:27:01 rivo volumio[3109]: info: Received an update from plugin. extracting info from payload Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreStateMachine::pushState Oct 08 14:27:01 rivo volumio[3109]: info: CoreCommandRouter::volumioPushState Oct 08 14:27:01 rivo volumio[3109]: info: ------------------------------ 105ms Oct 08 14:27:01 rivo volumio[3109]: info: ------------------------------ 95ms Oct 08 14:27:01 rivo volumio[3109]: info: ------------------------------ 94ms Oct 08 14:27:02 rivo volumio[3109]: info: [LastFM] Current track has sufficient metadata: title (Between these Hands) and artist (Various Artists) passed on explicitly Oct 08 14:27:02 rivo volumio[3109]: info: Signalling Playback active due to playback status change Oct 08 14:27:02 rivo volumio[3109]: info: MCU Signalled Playback Active Oct 08 14:27:02 rivo volumio[3109]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 08 14:27:02 rivo volumio[3109]: TypeError: Cannot read property '@' of undefined Oct 08 14:27:02 rivo volumio[3109]: at Object.callback (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:342:14) Oct 08 14:27:02 rivo volumio[3109]: at /data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:60:13 Oct 08 14:27:02 rivo volumio[3109]: at Parser. (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:308:18) Oct 08 14:27:02 rivo volumio[3109]: at Parser.emit (events.js:400:28) Oct 08 14:27:02 rivo volumio[3109]: at SAXParser.onerror (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:123:26) Oct 08 14:27:02 rivo volumio[3109]: at emit (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:624:35) Oct 08 14:27:02 rivo volumio[3109]: at error (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:653:5) Oct 08 14:27:02 rivo volumio[3109]: at strictFail (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:677:7) Oct 08 14:27:02 rivo volumio[3109]: at closeTag (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:871:9) Oct 08 14:27:02 rivo volumio[3109]: at SAXParser.write (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:1436:13) Oct 08 14:27:02 rivo volumio[3109]: at Parser.exports.Parser.Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:323:31) Oct 08 14:27:02 rivo volumio[3109]: at Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:5:59) Oct 08 14:27:02 rivo volumio[3109]: at IncomingMessage. (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:58:14) Oct 08 14:27:02 rivo volumio[3109]: at IncomingMessage.emit (events.js:412:35) Oct 08 14:27:02 rivo volumio[3109]: at endReadableNT (internal/streams/readable.js:1333:12) Oct 08 14:27:02 rivo volumio[3109]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Oct 08 14:27:02 rivo volumio[3109]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 08 14:27:03 rivo sudo[6554]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-08 14:26 Oct 08 14:27:03 rivo sudo[6554]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:47:06 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="b3e08c3e210a64867536255c2503fb09"