-- Logs begin at Mon 2024-04-08 19:41:09 CEST, end at Mon 2024-04-08 21:26:40 CEST. -- Apr 08 21:25:04 rivo volumio[5374]: info: CoreCommandRouter::volumioNext Apr 08 21:25:04 rivo volumio[5374]: info: CoreStateMachine::next Apr 08 21:25:04 rivo volumio[5374]: info: [1712604304521] ControllerQobuz::next Apr 08 21:25:04 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:25:04 rivo volumio[5374]: info: CoreStateMachine::next Apr 08 21:25:04 rivo volumio[5374]: info: CoreStateMachine::stop Apr 08 21:25:04 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:25:04 rivo volumio[5374]: info: CoreStateMachine::stPlaybackTimer Apr 08 21:25:04 rivo volumio[5374]: info: CoreStateMachine::updateTrackBlock Apr 08 21:25:04 rivo volumio[5374]: info: CorePlayQueue::getTrackBlock Apr 08 21:25:04 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:04 rivo volumio[5374]: info: CorePlayQueue::getTrack 14 Apr 08 21:25:04 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:04 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:04 rivo volumio[5374]: info: CoreStateMachine::serviceStop Apr 08 21:25:04 rivo volumio[5374]: info: CorePlayQueue::getTrack 14 Apr 08 21:25:04 rivo volumio[5374]: info: CoreCommandRouter::serviceStop Apr 08 21:25:04 rivo volumio[5374]: info: [1712604304529] ControllerQobuz::stop Apr 08 21:25:04 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 08 21:25:04 rivo volumio[5374]: info: ControllerMpd::stop Apr 08 21:25:04 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand stop Apr 08 21:25:04 rivo volumio[5374]: info: Apr 08 21:25:04 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:04 rivo volumio[5374]: info: sendMpdCommand stop took 73 milliseconds Apr 08 21:25:04 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:04 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:04 rivo volumio[5374]: info: CoreStateMachine::play index undefined Apr 08 21:25:04 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:25:04 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:04 rivo volumio[5374]: info: CoreStateMachine::startPlaybackTimer Apr 08 21:25:04 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:04 rivo volumio[5374]: info: [1712604304604] ControllerQobuz::clearAddPlayTrack Apr 08 21:25:04 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand stop Apr 08 21:25:04 rivo volumio[5374]: info: CoreStateMachine::updateTrackBlock Apr 08 21:25:04 rivo volumio[5374]: info: CorePlayQueue::getTrackBlock Apr 08 21:25:04 rivo volumio[5374]: info: Apr 08 21:25:04 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:04 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:04 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:04 rivo volumio[5374]: info: Apr 08 21:25:04 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:04 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:04 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:04 rivo volumio[5374]: info: sendMpdCommand status took 8 milliseconds Apr 08 21:25:04 rivo volumio[5374]: info: sendMpdCommand stop took 6 milliseconds Apr 08 21:25:04 rivo volumio[5374]: info: sendMpdCommand status took 3 milliseconds Apr 08 21:25:04 rivo volumio[5374]: info: sendMpdCommand status took 2 milliseconds Apr 08 21:25:04 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:04 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:04 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand clear Apr 08 21:25:04 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:04 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:04 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:04 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:04 rivo volumio[5374]: info: Apr 08 21:25:04 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:04 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:04 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 08 21:25:04 rivo volumio[5374]: info: sendMpdCommand clear took 3 milliseconds Apr 08 21:25:04 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 08 21:25:04 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 08 21:25:04 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:04 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/22396323" Apr 08 21:25:04 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:04 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:04 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:04 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:04 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:04 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:04 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:04 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:04 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:04 rivo volumio[5374]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Apr 08 21:25:04 rivo volumio[5374]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 08 21:25:04 rivo volumio[5374]: STREAMING PROXY: Handling url /?data=qobuz://song/22396323 Apr 08 21:25:04 rivo volumio[5374]: info: ------------------------------ 29ms Apr 08 21:25:04 rivo volumio[5374]: info: ------------------------------ 24ms Apr 08 21:25:04 rivo volumio[5374]: info: ------------------------------ 23ms Apr 08 21:25:04 rivo volumio[5374]: info: Apr 08 21:25:04 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:04 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:04 rivo volumio[5374]: info: Apr 08 21:25:04 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:04 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:04 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:25:04 rivo volumio[5374]: info: ------------------------------ 21ms Apr 08 21:25:04 rivo volumio[5374]: info: Executing endpoint getStreamUrlqobuz Apr 08 21:25:04 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 08 21:25:04 rivo volumio[5374]: info: getStreamUrl took 343 milliseconds Apr 08 21:25:04 rivo volumio[5374]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2676332&eid=22396323&fmt=7&profile=raw&app_id=539451548&cid=1859196&etsp=1712607904&hmac=zetw0HPgEEyavJvB8LmYdzHcUEA Apr 08 21:25:05 rivo volumio[5374]: STREAMING PROXY: Response: 200, length: 47460425 Apr 08 21:25:05 rivo volumio[5374]: STREAMING PROXY: Client dropped request, destroying Apr 08 21:25:05 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/22396323" Apr 08 21:25:05 rivo volumio[5374]: info: ------------------------------ 661ms Apr 08 21:25:05 rivo volumio[5374]: info: ------------------------------ 659ms Apr 08 21:25:05 rivo volumio[5374]: info: Apr 08 21:25:05 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:05 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:05 rivo volumio[5374]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/22396323" took 1 milliseconds Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand play Apr 08 21:25:05 rivo volumio[5374]: STREAMING PROXY: Handling url /?data=qobuz://song/22396323 Apr 08 21:25:05 rivo volumio[5374]: info: Apr 08 21:25:05 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:05 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:05 rivo volumio[5374]: info: Apr 08 21:25:05 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:05 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:05 rivo volumio[5374]: info: ------------------------------ 9ms Apr 08 21:25:05 rivo volumio[5374]: info: sendMpdCommand play took 8 milliseconds Apr 08 21:25:05 rivo volumio[5374]: info: ------------------------------ 3ms Apr 08 21:25:05 rivo volumio[5374]: info: Executing endpoint getStreamUrlqobuz Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 08 21:25:05 rivo volumio[5374]: info: getStreamUrl took 281 milliseconds Apr 08 21:25:05 rivo volumio[5374]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2676332&eid=22396323&fmt=7&profile=raw&app_id=539451548&cid=1859196&etsp=1712607905&hmac=VG7jfMNPKoJRIw8Ro9M-ewXwFns Apr 08 21:25:05 rivo volumio[5374]: STREAMING PROXY: Response: 200, length: 47460425 Apr 08 21:25:05 rivo volumio[5374]: info: Apr 08 21:25:05 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:05 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:05 rivo volumio[5374]: info: Apr 08 21:25:05 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:05 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:05 rivo volumio[5374]: info: Apr 08 21:25:05 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:05 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:05 rivo volumio[5374]: info: Apr 08 21:25:05 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:05 rivo volumio[5374]: info: sendMpdCommand status took 10 milliseconds Apr 08 21:25:05 rivo volumio[5374]: info: sendMpdCommand status took 10 milliseconds Apr 08 21:25:05 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:05 rivo volumio[5374]: info: sendMpdCommand status took 11 milliseconds Apr 08 21:25:05 rivo volumio[5374]: info: sendMpdCommand status took 4 milliseconds Apr 08 21:25:05 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 08 21:25:05 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:05 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:05 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:05 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":210,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396323","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396323","trackType":"qobuz"} Apr 08 21:25:05 rivo volumio[5374]: verbose: CURRENT POSITION 15 Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus stop Apr 08 21:25:05 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:05 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:05 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":210,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396323","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396323","trackType":"qobuz"} Apr 08 21:25:05 rivo volumio[5374]: verbose: CURRENT POSITION 15 Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:05 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:05 rivo volumio[5374]: info: ------------------------------ 37ms Apr 08 21:25:05 rivo volumio[5374]: info: ------------------------------ 41ms Apr 08 21:25:05 rivo volumio[5374]: info: Apr 08 21:25:05 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:05 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:05 rivo volumio[5374]: info: Apr 08 21:25:05 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:05 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:05 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 32 milliseconds Apr 08 21:25:05 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 31 milliseconds Apr 08 21:25:05 rivo volumio[5374]: info: sendMpdCommand status took 5 milliseconds Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:05 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:05 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:05 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":210,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396323","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396323","trackType":"qobuz"} Apr 08 21:25:05 rivo volumio[5374]: verbose: CURRENT POSITION 15 Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:05 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:05 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:05 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:05 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":210,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396323","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396323","trackType":"qobuz"} Apr 08 21:25:05 rivo volumio[5374]: verbose: CURRENT POSITION 15 Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:05 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:05 rivo volumio[5374]: info: ------------------------------ 104ms Apr 08 21:25:05 rivo volumio[5374]: info: ------------------------------ 99ms Apr 08 21:25:05 rivo volumio[5374]: info: sendMpdCommand status took 100 milliseconds Apr 08 21:25:05 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 97 milliseconds Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:05 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:05 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:05 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":210,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1924 Kbps","isStreaming":false,"title":"22396323","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396323","trackType":"qobuz"} Apr 08 21:25:05 rivo volumio[5374]: verbose: CURRENT POSITION 15 Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:05 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:05 rivo volumio[5374]: info: ------------------------------ 126ms Apr 08 21:25:05 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 30 milliseconds Apr 08 21:25:05 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:05 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:05 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:05 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":210,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1924 Kbps","isStreaming":false,"title":"22396323","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396323","trackType":"qobuz"} Apr 08 21:25:05 rivo volumio[5374]: verbose: CURRENT POSITION 15 Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:05 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:05 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:05 rivo volumio[5374]: info: ------------------------------ 172ms Apr 08 21:25:09 rivo volumio[5374]: info: CoreCommandRouter::volumioSeek Apr 08 21:25:09 rivo volumio[5374]: info: CoreStateMachine::seek Apr 08 21:25:09 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:09 rivo volumio[5374]: info: TRACKBLOCK {"uri":"qobuz://song/22396323","service":"qobuz","name":"Giving It Up (Ace Version)","title":"Giving It Up (Ace Version)","album":"Happy Nation (U.S. Version) [Remastered]","type":"track","tracknumber":16,"volumeNumber":1,"albumart":"https://static.qobuz.com/images/covers/09/11/7332181061109_600.jpg","duration":210,"explicit":false,"artist":"Ace Of Base","artistUri":"qobuz://artist/232605","albumUri":"qobuz://album/7332181061109","audioQuality":"","tagImage":""} Apr 08 21:25:09 rivo volumio[5374]: info: CoreStateMachine::startPlaybackTimer Apr 08 21:25:09 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:09 rivo volumio[5374]: info: [1712604309702] ControllerQobuz::seek Apr 08 21:25:09 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 08 21:25:09 rivo volumio[5374]: info: ControllerMpd::seek Apr 08 21:25:09 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:09 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:09 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:09 rivo volumio[5374]: error: null Apr 08 21:25:09 rivo volumio[5374]: info: Apr 08 21:25:09 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:09 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:09 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:09 rivo volumio[5374]: info: Apr 08 21:25:09 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:09 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:09 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:09 rivo volumio[5374]: info: Apr 08 21:25:09 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:09 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:09 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:09 rivo volumio[5374]: info: sendMpdCommand status took 13 milliseconds Apr 08 21:25:09 rivo volumio[5374]: info: sendMpdCommand status took 6 milliseconds Apr 08 21:25:09 rivo volumio[5374]: info: sendMpdCommand status took 4 milliseconds Apr 08 21:25:09 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:09 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:09 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:09 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:09 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:09 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:09 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 08 21:25:09 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 08 21:25:09 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 08 21:25:09 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:09 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:09 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:09 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:09 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":49000,"duration":210,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1685 Kbps","isStreaming":false,"title":"22396323","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396323","trackType":"qobuz"} Apr 08 21:25:09 rivo volumio[5374]: verbose: CURRENT POSITION 15 Apr 08 21:25:09 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:09 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:09 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:09 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:09 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:09 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:09 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:09 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:09 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:09 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:09 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:09 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":49000,"duration":210,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1685 Kbps","isStreaming":false,"title":"22396323","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396323","trackType":"qobuz"} Apr 08 21:25:09 rivo volumio[5374]: verbose: CURRENT POSITION 15 Apr 08 21:25:09 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:09 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:09 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:09 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:09 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:09 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:09 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:09 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:09 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:09 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:09 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":49000,"duration":210,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1685 Kbps","isStreaming":false,"title":"22396323","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396323","trackType":"qobuz"} Apr 08 21:25:09 rivo volumio[5374]: verbose: CURRENT POSITION 15 Apr 08 21:25:09 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:09 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:09 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:09 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:09 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:09 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:09 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:09 rivo volumio[5374]: info: ------------------------------ 77ms Apr 08 21:25:09 rivo volumio[5374]: info: ------------------------------ 71ms Apr 08 21:25:09 rivo volumio[5374]: info: ------------------------------ 70ms Apr 08 21:25:12 rivo volumio[5374]: STREAMING PROXY: Client dropped request, destroying Apr 08 21:25:13 rivo volumio[5374]: info: CoreCommandRouter::volumioNext Apr 08 21:25:13 rivo volumio[5374]: info: CoreStateMachine::next Apr 08 21:25:13 rivo volumio[5374]: info: [1712604313172] ControllerQobuz::next Apr 08 21:25:13 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:25:13 rivo volumio[5374]: info: CoreStateMachine::next Apr 08 21:25:13 rivo volumio[5374]: info: CoreStateMachine::stop Apr 08 21:25:13 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:25:13 rivo volumio[5374]: info: CoreStateMachine::stPlaybackTimer Apr 08 21:25:13 rivo volumio[5374]: info: CoreStateMachine::updateTrackBlock Apr 08 21:25:13 rivo volumio[5374]: info: CorePlayQueue::getTrackBlock Apr 08 21:25:13 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:13 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:13 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:13 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:13 rivo volumio[5374]: info: CoreStateMachine::serviceStop Apr 08 21:25:13 rivo volumio[5374]: info: CorePlayQueue::getTrack 15 Apr 08 21:25:13 rivo volumio[5374]: info: CoreCommandRouter::serviceStop Apr 08 21:25:13 rivo volumio[5374]: info: [1712604313182] ControllerQobuz::stop Apr 08 21:25:13 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 08 21:25:13 rivo volumio[5374]: info: ControllerMpd::stop Apr 08 21:25:13 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand stop Apr 08 21:25:13 rivo volumio[5374]: info: Apr 08 21:25:13 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:13 rivo volumio[5374]: info: sendMpdCommand stop took 59 milliseconds Apr 08 21:25:13 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:13 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:13 rivo volumio[5374]: info: CoreStateMachine::play index undefined Apr 08 21:25:13 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:25:13 rivo volumio[5374]: info: CorePlayQueue::getTrack 16 Apr 08 21:25:13 rivo volumio[5374]: info: Apr 08 21:25:13 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:13 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:13 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:13 rivo volumio[5374]: info: Apr 08 21:25:13 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:13 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:13 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:13 rivo volumio[5374]: info: sendMpdCommand status took 9 milliseconds Apr 08 21:25:13 rivo volumio[5374]: info: sendMpdCommand status took 5 milliseconds Apr 08 21:25:13 rivo volumio[5374]: info: sendMpdCommand status took 3 milliseconds Apr 08 21:25:13 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:13 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:13 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:13 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:13 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:13 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:13 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 08 21:25:13 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 8 milliseconds Apr 08 21:25:13 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 8 milliseconds Apr 08 21:25:13 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:13 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:13 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:13 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:13 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:13 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:13 rivo volumio[5374]: info: CorePlayQueue::getTrack 0 Apr 08 21:25:13 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:13 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:13 rivo volumio[5374]: info: CorePlayQueue::getTrack 0 Apr 08 21:25:13 rivo volumio[5374]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Apr 08 21:25:13 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:13 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:13 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:13 rivo volumio[5374]: info: CorePlayQueue::getTrack 0 Apr 08 21:25:13 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:13 rivo volumio[5374]: info: CorePlayQueue::getTrack 0 Apr 08 21:25:13 rivo volumio[5374]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Apr 08 21:25:13 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:13 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:13 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:13 rivo volumio[5374]: info: CorePlayQueue::getTrack 0 Apr 08 21:25:13 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:13 rivo volumio[5374]: info: CorePlayQueue::getTrack 0 Apr 08 21:25:13 rivo volumio[5374]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Apr 08 21:25:13 rivo volumio[5374]: info: ------------------------------ 40ms Apr 08 21:25:13 rivo volumio[5374]: info: ------------------------------ 35ms Apr 08 21:25:13 rivo volumio[5374]: info: ------------------------------ 34ms Apr 08 21:25:17 rivo volumio[5374]: info: CoreCommandRouter::volumioPlay Apr 08 21:25:17 rivo volumio[5374]: info: CoreStateMachine::play index undefined Apr 08 21:25:17 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:25:17 rivo volumio[5374]: info: CorePlayQueue::getTrack 0 Apr 08 21:25:17 rivo volumio[5374]: info: CoreStateMachine::startPlaybackTimer Apr 08 21:25:17 rivo volumio[5374]: info: CorePlayQueue::getTrack 0 Apr 08 21:25:17 rivo volumio[5374]: info: [1712604317726] ControllerQobuz::clearAddPlayTrack Apr 08 21:25:17 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand stop Apr 08 21:25:17 rivo volumio[5374]: info: sendMpdCommand stop took 1 milliseconds Apr 08 21:25:17 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand clear Apr 08 21:25:17 rivo volumio[5374]: info: Apr 08 21:25:17 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:17 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:17 rivo volumio[5374]: info: sendMpdCommand clear took 1 milliseconds Apr 08 21:25:17 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/22396308" Apr 08 21:25:17 rivo volumio[5374]: info: Apr 08 21:25:17 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:17 rivo volumio[5374]: STREAMING PROXY: Handling url /?data=qobuz://song/22396308 Apr 08 21:25:17 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:17 rivo volumio[5374]: info: Apr 08 21:25:17 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:17 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:17 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:25:17 rivo volumio[5374]: info: ------------------------------ 12ms Apr 08 21:25:17 rivo volumio[5374]: info: Executing endpoint getStreamUrlqobuz Apr 08 21:25:17 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 08 21:25:18 rivo volumio[5374]: info: getStreamUrl took 268 milliseconds Apr 08 21:25:18 rivo volumio[5374]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2676332&eid=22396308&fmt=7&profile=raw&app_id=539451548&cid=1859196&etsp=1712607917&hmac=N9vJDQE8DpVa5P6cquvXTHIqegI Apr 08 21:25:18 rivo volumio[5374]: STREAMING PROXY: Response: 200, length: 43083492 Apr 08 21:25:18 rivo volumio[5374]: STREAMING PROXY: Client dropped request, destroying Apr 08 21:25:18 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:25:18 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/22396308" Apr 08 21:25:18 rivo volumio[5374]: info: ------------------------------ 340ms Apr 08 21:25:18 rivo volumio[5374]: info: ------------------------------ 330ms Apr 08 21:25:18 rivo volumio[5374]: info: Apr 08 21:25:18 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:18 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:18 rivo volumio[5374]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/22396308" took 2 milliseconds Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand play Apr 08 21:25:18 rivo volumio[5374]: info: Apr 08 21:25:18 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:18 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:18 rivo volumio[5374]: info: Apr 08 21:25:18 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:18 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:18 rivo volumio[5374]: STREAMING PROXY: Handling url /?data=qobuz://song/22396308 Apr 08 21:25:18 rivo volumio[5374]: info: ------------------------------ 5ms Apr 08 21:25:18 rivo volumio[5374]: info: sendMpdCommand play took 4 milliseconds Apr 08 21:25:18 rivo volumio[5374]: info: ------------------------------ 3ms Apr 08 21:25:18 rivo volumio[5374]: info: ------------------------------ 10ms Apr 08 21:25:18 rivo volumio[5374]: info: Executing endpoint getStreamUrlqobuz Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 08 21:25:18 rivo volumio[5374]: info: getStreamUrl took 265 milliseconds Apr 08 21:25:18 rivo volumio[5374]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2676332&eid=22396308&fmt=7&profile=raw&app_id=539451548&cid=1859196&etsp=1712607918&hmac=nT3axoKu7EbGtL8IfK80CTRXdp4 Apr 08 21:25:18 rivo volumio[5374]: STREAMING PROXY: Response: 200, length: 43083492 Apr 08 21:25:18 rivo volumio[5374]: info: Apr 08 21:25:18 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:18 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:18 rivo volumio[5374]: info: Apr 08 21:25:18 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:18 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:18 rivo volumio[5374]: info: Apr 08 21:25:18 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:18 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:18 rivo volumio[5374]: info: Apr 08 21:25:18 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:18 rivo volumio[5374]: info: sendMpdCommand status took 26 milliseconds Apr 08 21:25:18 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:18 rivo volumio[5374]: info: sendMpdCommand status took 27 milliseconds Apr 08 21:25:18 rivo volumio[5374]: info: sendMpdCommand status took 25 milliseconds Apr 08 21:25:18 rivo volumio[5374]: info: sendMpdCommand status took 2 milliseconds Apr 08 21:25:18 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:18 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:18 rivo volumio[5374]: info: CorePlayQueue::getTrack 0 Apr 08 21:25:18 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396308","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396308","trackType":"qobuz"} Apr 08 21:25:18 rivo volumio[5374]: verbose: CURRENT POSITION 0 Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus stop Apr 08 21:25:18 rivo volumio[5374]: info: ------------------------------ 36ms Apr 08 21:25:18 rivo volumio[5374]: info: Apr 08 21:25:18 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:18 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:18 rivo volumio[5374]: info: Apr 08 21:25:18 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:18 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:18 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 8 milliseconds Apr 08 21:25:18 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 9 milliseconds Apr 08 21:25:18 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 8 milliseconds Apr 08 21:25:18 rivo volumio[5374]: info: sendMpdCommand status took 5 milliseconds Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:18 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:18 rivo volumio[5374]: info: CorePlayQueue::getTrack 0 Apr 08 21:25:18 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396308","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396308","trackType":"qobuz"} Apr 08 21:25:18 rivo volumio[5374]: verbose: CURRENT POSITION 0 Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:18 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:18 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:18 rivo volumio[5374]: info: CorePlayQueue::getTrack 0 Apr 08 21:25:18 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396308","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396308","trackType":"qobuz"} Apr 08 21:25:18 rivo volumio[5374]: verbose: CURRENT POSITION 0 Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:18 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:18 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:18 rivo volumio[5374]: info: CorePlayQueue::getTrack 0 Apr 08 21:25:18 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396308","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396308","trackType":"qobuz"} Apr 08 21:25:18 rivo volumio[5374]: verbose: CURRENT POSITION 0 Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:18 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:18 rivo volumio[5374]: info: ------------------------------ 104ms Apr 08 21:25:18 rivo volumio[5374]: info: ------------------------------ 104ms Apr 08 21:25:18 rivo volumio[5374]: info: ------------------------------ 84ms Apr 08 21:25:18 rivo volumio[5374]: info: sendMpdCommand status took 74 milliseconds Apr 08 21:25:18 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 70 milliseconds Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:18 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:18 rivo volumio[5374]: info: CorePlayQueue::getTrack 0 Apr 08 21:25:18 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396308","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396308","trackType":"qobuz"} Apr 08 21:25:18 rivo volumio[5374]: verbose: CURRENT POSITION 0 Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:18 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:18 rivo volumio[5374]: info: ------------------------------ 110ms Apr 08 21:25:18 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 84 milliseconds Apr 08 21:25:18 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:18 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:18 rivo volumio[5374]: info: CorePlayQueue::getTrack 0 Apr 08 21:25:18 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396308","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396308","trackType":"qobuz"} Apr 08 21:25:18 rivo volumio[5374]: verbose: CURRENT POSITION 0 Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:18 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:18 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:18 rivo volumio[5374]: info: ------------------------------ 176ms Apr 08 21:25:20 rivo volumio[5374]: info: CoreCommandRouter::volumioNext Apr 08 21:25:20 rivo volumio[5374]: info: CoreStateMachine::next Apr 08 21:25:20 rivo volumio[5374]: info: [1712604320466] ControllerQobuz::next Apr 08 21:25:20 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:25:20 rivo volumio[5374]: info: CoreStateMachine::next Apr 08 21:25:20 rivo volumio[5374]: info: CoreStateMachine::stop Apr 08 21:25:20 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:25:20 rivo volumio[5374]: info: CoreStateMachine::stPlaybackTimer Apr 08 21:25:20 rivo volumio[5374]: info: CoreStateMachine::updateTrackBlock Apr 08 21:25:20 rivo volumio[5374]: info: CorePlayQueue::getTrackBlock Apr 08 21:25:20 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:20 rivo volumio[5374]: info: CorePlayQueue::getTrack 0 Apr 08 21:25:20 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:20 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:20 rivo volumio[5374]: info: CoreStateMachine::serviceStop Apr 08 21:25:20 rivo volumio[5374]: info: CorePlayQueue::getTrack 0 Apr 08 21:25:20 rivo volumio[5374]: info: CoreCommandRouter::serviceStop Apr 08 21:25:20 rivo volumio[5374]: info: [1712604320473] ControllerQobuz::stop Apr 08 21:25:20 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 08 21:25:20 rivo volumio[5374]: info: ControllerMpd::stop Apr 08 21:25:20 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand stop Apr 08 21:25:20 rivo volumio[5374]: STREAMING PROXY: Client dropped request, destroying Apr 08 21:25:20 rivo volumio[5374]: info: sendMpdCommand stop took 63 milliseconds Apr 08 21:25:20 rivo volumio[5374]: info: CoreStateMachine::play index undefined Apr 08 21:25:20 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:25:20 rivo volumio[5374]: info: CorePlayQueue::getTrack 1 Apr 08 21:25:20 rivo volumio[5374]: info: CoreStateMachine::startPlaybackTimer Apr 08 21:25:20 rivo volumio[5374]: info: CorePlayQueue::getTrack 1 Apr 08 21:25:20 rivo volumio[5374]: info: [1712604320539] ControllerQobuz::clearAddPlayTrack Apr 08 21:25:20 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand stop Apr 08 21:25:20 rivo volumio[5374]: info: CoreStateMachine::updateTrackBlock Apr 08 21:25:20 rivo volumio[5374]: info: CorePlayQueue::getTrackBlock Apr 08 21:25:20 rivo volumio[5374]: info: Apr 08 21:25:20 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:20 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:20 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:20 rivo volumio[5374]: info: sendMpdCommand stop took 3 milliseconds Apr 08 21:25:20 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand clear Apr 08 21:25:20 rivo volumio[5374]: info: Apr 08 21:25:20 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:20 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:20 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:20 rivo volumio[5374]: info: Apr 08 21:25:20 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:20 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:20 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:20 rivo volumio[5374]: info: Apr 08 21:25:20 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:20 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:20 rivo volumio[5374]: info: sendMpdCommand status took 17 milliseconds Apr 08 21:25:20 rivo volumio[5374]: info: sendMpdCommand clear took 17 milliseconds Apr 08 21:25:20 rivo volumio[5374]: info: sendMpdCommand status took 13 milliseconds Apr 08 21:25:20 rivo volumio[5374]: info: sendMpdCommand status took 8 milliseconds Apr 08 21:25:20 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:20 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:20 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/22396309" Apr 08 21:25:20 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:20 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:20 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:20 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:20 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:20 rivo volumio[5374]: info: CorePlayQueue::getTrack 1 Apr 08 21:25:20 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:20 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:20 rivo volumio[5374]: STREAMING PROXY: Handling url /?data=qobuz://song/22396309 Apr 08 21:25:20 rivo volumio[5374]: info: CorePlayQueue::getTrack 1 Apr 08 21:25:20 rivo volumio[5374]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Apr 08 21:25:20 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:20 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:20 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:20 rivo volumio[5374]: info: CorePlayQueue::getTrack 1 Apr 08 21:25:20 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:20 rivo volumio[5374]: info: CorePlayQueue::getTrack 1 Apr 08 21:25:20 rivo volumio[5374]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Apr 08 21:25:20 rivo volumio[5374]: info: ------------------------------ 52ms Apr 08 21:25:20 rivo volumio[5374]: info: ------------------------------ 47ms Apr 08 21:25:20 rivo volumio[5374]: info: Apr 08 21:25:20 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:20 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:20 rivo volumio[5374]: info: Apr 08 21:25:20 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:20 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:20 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:25:20 rivo volumio[5374]: info: ------------------------------ 46ms Apr 08 21:25:20 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 37 milliseconds Apr 08 21:25:20 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:20 rivo volumio[5374]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 08 21:25:20 rivo volumio[5374]: info: ------------------------------ 63ms Apr 08 21:25:20 rivo volumio[5374]: info: Executing endpoint getStreamUrlqobuz Apr 08 21:25:20 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 08 21:25:20 rivo volumio[5374]: info: getStreamUrl took 277 milliseconds Apr 08 21:25:20 rivo volumio[5374]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2676332&eid=22396309&fmt=7&profile=raw&app_id=539451548&cid=1859196&etsp=1712607920&hmac=N1_aoe7heuO4pwOQgLfDOrJ67hY Apr 08 21:25:20 rivo volumio[5374]: STREAMING PROXY: Response: 200, length: 48143013 Apr 08 21:25:20 rivo volumio[5374]: STREAMING PROXY: Client dropped request, destroying Apr 08 21:25:20 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/22396309" Apr 08 21:25:20 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:25:21 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:25:21 rivo volumio[5374]: info: Apr 08 21:25:21 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:21 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:21 rivo volumio[5374]: info: ------------------------------ 402ms Apr 08 21:25:21 rivo volumio[5374]: info: ------------------------------ 404ms Apr 08 21:25:21 rivo volumio[5374]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/22396309" took 7 milliseconds Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand play Apr 08 21:25:21 rivo volumio[5374]: info: Apr 08 21:25:21 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:21 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:21 rivo volumio[5374]: STREAMING PROXY: Handling url /?data=qobuz://song/22396309 Apr 08 21:25:21 rivo volumio[5374]: info: Apr 08 21:25:21 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:21 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:21 rivo volumio[5374]: info: ------------------------------ 11ms Apr 08 21:25:21 rivo volumio[5374]: info: sendMpdCommand play took 6 milliseconds Apr 08 21:25:21 rivo volumio[5374]: info: ------------------------------ 6ms Apr 08 21:25:21 rivo volumio[5374]: info: ------------------------------ 4ms Apr 08 21:25:21 rivo volumio[5374]: info: Executing endpoint getStreamUrlqobuz Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 08 21:25:21 rivo volumio[5374]: info: getStreamUrl took 278 milliseconds Apr 08 21:25:21 rivo volumio[5374]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2676332&eid=22396309&fmt=7&profile=raw&app_id=539451548&cid=1859196&etsp=1712607921&hmac=8Y7F6J8tZZrtlVKZpx4HH9RtY0c Apr 08 21:25:21 rivo volumio[5374]: STREAMING PROXY: Response: 200, length: 48143013 Apr 08 21:25:21 rivo volumio[5374]: info: Apr 08 21:25:21 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:21 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:21 rivo volumio[5374]: info: Apr 08 21:25:21 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:21 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:21 rivo volumio[5374]: info: Apr 08 21:25:21 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:21 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:21 rivo volumio[5374]: info: Apr 08 21:25:21 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:21 rivo volumio[5374]: info: sendMpdCommand status took 23 milliseconds Apr 08 21:25:21 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:21 rivo volumio[5374]: info: sendMpdCommand status took 26 milliseconds Apr 08 21:25:21 rivo volumio[5374]: info: sendMpdCommand status took 25 milliseconds Apr 08 21:25:21 rivo volumio[5374]: info: sendMpdCommand status took 3 milliseconds Apr 08 21:25:21 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:21 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:21 rivo volumio[5374]: info: CorePlayQueue::getTrack 1 Apr 08 21:25:21 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":230,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396309","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396309","trackType":"qobuz"} Apr 08 21:25:21 rivo volumio[5374]: verbose: CURRENT POSITION 1 Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus stop Apr 08 21:25:21 rivo volumio[5374]: info: ------------------------------ 40ms Apr 08 21:25:21 rivo volumio[5374]: info: Apr 08 21:25:21 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:21 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:21 rivo volumio[5374]: info: Apr 08 21:25:21 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:21 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:21 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 14 milliseconds Apr 08 21:25:21 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 14 milliseconds Apr 08 21:25:21 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 14 milliseconds Apr 08 21:25:21 rivo volumio[5374]: info: sendMpdCommand status took 5 milliseconds Apr 08 21:25:21 rivo volumio[5374]: info: sendMpdCommand status took 3 milliseconds Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:21 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:21 rivo volumio[5374]: info: CorePlayQueue::getTrack 1 Apr 08 21:25:21 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":230,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396309","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396309","trackType":"qobuz"} Apr 08 21:25:21 rivo volumio[5374]: verbose: CURRENT POSITION 1 Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:21 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:21 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:21 rivo volumio[5374]: info: CorePlayQueue::getTrack 1 Apr 08 21:25:21 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":230,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396309","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396309","trackType":"qobuz"} Apr 08 21:25:21 rivo volumio[5374]: verbose: CURRENT POSITION 1 Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:21 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:21 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:21 rivo volumio[5374]: info: CorePlayQueue::getTrack 1 Apr 08 21:25:21 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":230,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396309","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396309","trackType":"qobuz"} Apr 08 21:25:21 rivo volumio[5374]: verbose: CURRENT POSITION 1 Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:21 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:21 rivo volumio[5374]: info: ------------------------------ 85ms Apr 08 21:25:21 rivo volumio[5374]: info: ------------------------------ 66ms Apr 08 21:25:21 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 42 milliseconds Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:21 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:21 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:21 rivo volumio[5374]: info: CorePlayQueue::getTrack 1 Apr 08 21:25:21 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":230,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1119 Kbps","isStreaming":false,"title":"22396309","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396309","trackType":"qobuz"} Apr 08 21:25:21 rivo volumio[5374]: verbose: CURRENT POSITION 1 Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:21 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:21 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:21 rivo volumio[5374]: info: CorePlayQueue::getTrack 1 Apr 08 21:25:21 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":230,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1119 Kbps","isStreaming":false,"title":"22396309","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396309","trackType":"qobuz"} Apr 08 21:25:21 rivo volumio[5374]: verbose: CURRENT POSITION 1 Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:21 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:21 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:21 rivo volumio[5374]: info: ------------------------------ 79ms Apr 08 21:25:21 rivo volumio[5374]: info: ------------------------------ 79ms Apr 08 21:25:27 rivo volumio[5374]: STREAMING PROXY: Client dropped request, destroying Apr 08 21:25:44 rivo volumio[5374]: info: CoreCommandRouter::volumioNext Apr 08 21:25:44 rivo volumio[5374]: info: CoreStateMachine::next Apr 08 21:25:44 rivo volumio[5374]: info: [1712604344605] ControllerQobuz::next Apr 08 21:25:44 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:25:44 rivo volumio[5374]: info: CoreStateMachine::next Apr 08 21:25:44 rivo volumio[5374]: info: CoreStateMachine::stop Apr 08 21:25:44 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:25:44 rivo volumio[5374]: info: CoreStateMachine::stPlaybackTimer Apr 08 21:25:44 rivo volumio[5374]: info: CoreStateMachine::updateTrackBlock Apr 08 21:25:44 rivo volumio[5374]: info: CorePlayQueue::getTrackBlock Apr 08 21:25:44 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:44 rivo volumio[5374]: info: CorePlayQueue::getTrack 1 Apr 08 21:25:44 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:44 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:44 rivo volumio[5374]: info: CoreStateMachine::serviceStop Apr 08 21:25:44 rivo volumio[5374]: info: CorePlayQueue::getTrack 1 Apr 08 21:25:44 rivo volumio[5374]: info: CoreCommandRouter::serviceStop Apr 08 21:25:44 rivo volumio[5374]: info: [1712604344611] ControllerQobuz::stop Apr 08 21:25:44 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 08 21:25:44 rivo volumio[5374]: info: ControllerMpd::stop Apr 08 21:25:44 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand stop Apr 08 21:25:44 rivo volumio[5374]: info: Apr 08 21:25:44 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:44 rivo volumio[5374]: info: sendMpdCommand stop took 64 milliseconds Apr 08 21:25:44 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:44 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:44 rivo volumio[5374]: info: CoreStateMachine::play index undefined Apr 08 21:25:44 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:25:44 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:44 rivo volumio[5374]: info: CoreStateMachine::startPlaybackTimer Apr 08 21:25:44 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:44 rivo volumio[5374]: info: [1712604344688] ControllerQobuz::clearAddPlayTrack Apr 08 21:25:44 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand stop Apr 08 21:25:44 rivo volumio[5374]: info: CoreStateMachine::updateTrackBlock Apr 08 21:25:44 rivo volumio[5374]: info: CorePlayQueue::getTrackBlock Apr 08 21:25:44 rivo volumio[5374]: info: Apr 08 21:25:44 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:44 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:44 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:44 rivo volumio[5374]: info: Apr 08 21:25:44 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:44 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:44 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:44 rivo volumio[5374]: info: sendMpdCommand status took 17 milliseconds Apr 08 21:25:44 rivo volumio[5374]: info: sendMpdCommand stop took 6 milliseconds Apr 08 21:25:44 rivo volumio[5374]: info: sendMpdCommand status took 4 milliseconds Apr 08 21:25:44 rivo volumio[5374]: info: sendMpdCommand status took 3 milliseconds Apr 08 21:25:44 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:44 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:44 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand clear Apr 08 21:25:44 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:44 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:44 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:44 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:44 rivo volumio[5374]: info: Apr 08 21:25:44 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:44 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:44 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 08 21:25:44 rivo volumio[5374]: info: sendMpdCommand clear took 5 milliseconds Apr 08 21:25:44 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 08 21:25:44 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 08 21:25:44 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:44 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/22396310" Apr 08 21:25:44 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:44 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:44 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:44 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:44 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:44 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:44 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:44 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:44 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:44 rivo volumio[5374]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Apr 08 21:25:44 rivo volumio[5374]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 08 21:25:44 rivo volumio[5374]: STREAMING PROXY: Handling url /?data=qobuz://song/22396310 Apr 08 21:25:44 rivo volumio[5374]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 08 21:25:44 rivo volumio[5374]: info: ------------------------------ 41ms Apr 08 21:25:44 rivo volumio[5374]: info: ------------------------------ 26ms Apr 08 21:25:44 rivo volumio[5374]: info: ------------------------------ 24ms Apr 08 21:25:44 rivo volumio[5374]: info: Apr 08 21:25:44 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:44 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:44 rivo volumio[5374]: info: Apr 08 21:25:44 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:44 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:44 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:25:44 rivo volumio[5374]: info: ------------------------------ 35ms Apr 08 21:25:44 rivo volumio[5374]: info: Executing endpoint getStreamUrlqobuz Apr 08 21:25:44 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 08 21:25:45 rivo volumio[5374]: info: getStreamUrl took 286 milliseconds Apr 08 21:25:45 rivo volumio[5374]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2676332&eid=22396310&fmt=7&profile=raw&app_id=539451548&cid=1859196&etsp=1712607944&hmac=6O3SaGtd01NqEG1WFXXUlRP_vjs Apr 08 21:25:45 rivo volumio[5374]: STREAMING PROXY: Response: 200, length: 51328646 Apr 08 21:25:45 rivo volumio[5374]: STREAMING PROXY: Client dropped request, destroying Apr 08 21:25:45 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:25:45 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/22396310" Apr 08 21:25:45 rivo volumio[5374]: info: ------------------------------ 591ms Apr 08 21:25:45 rivo volumio[5374]: info: ------------------------------ 577ms Apr 08 21:25:45 rivo volumio[5374]: info: Apr 08 21:25:45 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:45 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:45 rivo volumio[5374]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/22396310" took 4 milliseconds Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand play Apr 08 21:25:45 rivo volumio[5374]: info: Apr 08 21:25:45 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:45 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:45 rivo volumio[5374]: info: Apr 08 21:25:45 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:45 rivo volumio[5374]: STREAMING PROXY: Handling url /?data=qobuz://song/22396310 Apr 08 21:25:45 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:45 rivo volumio[5374]: info: ------------------------------ 18ms Apr 08 21:25:45 rivo volumio[5374]: info: sendMpdCommand play took 14 milliseconds Apr 08 21:25:45 rivo volumio[5374]: info: ------------------------------ 14ms Apr 08 21:25:45 rivo volumio[5374]: info: ------------------------------ 12ms Apr 08 21:25:45 rivo volumio[5374]: info: Executing endpoint getStreamUrlqobuz Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 08 21:25:45 rivo volumio[5374]: info: getStreamUrl took 291 milliseconds Apr 08 21:25:45 rivo volumio[5374]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2676332&eid=22396310&fmt=7&profile=raw&app_id=539451548&cid=1859196&etsp=1712607945&hmac=N16-WXoUXMmmGQ1oc5TyRQIuRWM Apr 08 21:25:45 rivo volumio[5374]: STREAMING PROXY: Response: 200, length: 51328646 Apr 08 21:25:45 rivo volumio[5374]: info: Apr 08 21:25:45 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:45 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:45 rivo volumio[5374]: info: Apr 08 21:25:45 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:45 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:45 rivo volumio[5374]: info: Apr 08 21:25:45 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:45 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:45 rivo volumio[5374]: info: Apr 08 21:25:45 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:45 rivo volumio[5374]: info: sendMpdCommand status took 14 milliseconds Apr 08 21:25:45 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:45 rivo volumio[5374]: info: sendMpdCommand status took 14 milliseconds Apr 08 21:25:45 rivo volumio[5374]: info: sendMpdCommand status took 12 milliseconds Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:45 rivo volumio[5374]: info: Apr 08 21:25:45 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:45 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:45 rivo volumio[5374]: info: Apr 08 21:25:45 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:45 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:45 rivo volumio[5374]: info: sendMpdCommand status took 11 milliseconds Apr 08 21:25:45 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 10 milliseconds Apr 08 21:25:45 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 8 milliseconds Apr 08 21:25:45 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 08 21:25:45 rivo volumio[5374]: info: sendMpdCommand status took 5 milliseconds Apr 08 21:25:45 rivo volumio[5374]: info: sendMpdCommand status took 3 milliseconds Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:45 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:45 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:45 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":237,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396310","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396310","trackType":"qobuz"} Apr 08 21:25:45 rivo volumio[5374]: verbose: CURRENT POSITION 2 Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus stop Apr 08 21:25:45 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:45 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:45 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":237,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396310","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396310","trackType":"qobuz"} Apr 08 21:25:45 rivo volumio[5374]: verbose: CURRENT POSITION 2 Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:45 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:45 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:45 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:45 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":237,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396310","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396310","trackType":"qobuz"} Apr 08 21:25:45 rivo volumio[5374]: verbose: CURRENT POSITION 2 Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:45 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:45 rivo volumio[5374]: info: ------------------------------ 52ms Apr 08 21:25:45 rivo volumio[5374]: info: ------------------------------ 61ms Apr 08 21:25:45 rivo volumio[5374]: info: ------------------------------ 60ms Apr 08 21:25:45 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 36 milliseconds Apr 08 21:25:45 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 35 milliseconds Apr 08 21:25:45 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 35 milliseconds Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:45 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:45 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:45 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:45 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":237,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396310","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396310","trackType":"qobuz"} Apr 08 21:25:45 rivo volumio[5374]: verbose: CURRENT POSITION 2 Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:45 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:45 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:45 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:45 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":237,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396310","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396310","trackType":"qobuz"} Apr 08 21:25:45 rivo volumio[5374]: verbose: CURRENT POSITION 2 Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:45 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:45 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:45 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:45 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":237,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396310","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396310","trackType":"qobuz"} Apr 08 21:25:45 rivo volumio[5374]: verbose: CURRENT POSITION 2 Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:45 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:45 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:45 rivo volumio[5374]: info: ------------------------------ 94ms Apr 08 21:25:45 rivo volumio[5374]: info: ------------------------------ 89ms Apr 08 21:25:45 rivo volumio[5374]: info: ------------------------------ 93ms Apr 08 21:25:50 rivo volumio[5374]: info: CoreCommandRouter::volumioSeek Apr 08 21:25:50 rivo volumio[5374]: info: CoreStateMachine::seek Apr 08 21:25:50 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:50 rivo volumio[5374]: info: TRACKBLOCK {"uri":"qobuz://song/22396310","service":"qobuz","name":"Young and Proud","title":"Young and Proud","album":"Happy Nation (U.S. Version) [Remastered]","type":"track","tracknumber":3,"volumeNumber":1,"albumart":"https://static.qobuz.com/images/covers/09/11/7332181061109_600.jpg","duration":237,"explicit":false,"artist":"Ace Of Base","artistUri":"qobuz://artist/232605","albumUri":"qobuz://album/7332181061109","audioQuality":"","tagImage":""} Apr 08 21:25:50 rivo volumio[5374]: info: CoreStateMachine::startPlaybackTimer Apr 08 21:25:50 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:50 rivo volumio[5374]: info: [1712604350605] ControllerQobuz::seek Apr 08 21:25:50 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 08 21:25:50 rivo volumio[5374]: info: ControllerMpd::seek Apr 08 21:25:50 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:50 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:50 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:50 rivo volumio[5374]: error: null Apr 08 21:25:50 rivo volumio[5374]: info: Apr 08 21:25:50 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:50 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:50 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:50 rivo volumio[5374]: info: Apr 08 21:25:50 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:50 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:50 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:50 rivo volumio[5374]: info: Apr 08 21:25:50 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:50 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:50 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:50 rivo volumio[5374]: info: sendMpdCommand status took 11 milliseconds Apr 08 21:25:50 rivo volumio[5374]: info: sendMpdCommand status took 4 milliseconds Apr 08 21:25:50 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:50 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:50 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:50 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:50 rivo volumio[5374]: info: sendMpdCommand status took 7 milliseconds Apr 08 21:25:50 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 08 21:25:50 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 08 21:25:50 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:50 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:50 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:50 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:50 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:50 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:50 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":70000,"duration":237,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1520 Kbps","isStreaming":false,"title":"22396310","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396310","trackType":"qobuz"} Apr 08 21:25:50 rivo volumio[5374]: verbose: CURRENT POSITION 2 Apr 08 21:25:50 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:50 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:50 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:50 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:50 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:50 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:50 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:50 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:50 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:50 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:50 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:50 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":70000,"duration":237,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1520 Kbps","isStreaming":false,"title":"22396310","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396310","trackType":"qobuz"} Apr 08 21:25:50 rivo volumio[5374]: verbose: CURRENT POSITION 2 Apr 08 21:25:50 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:50 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:50 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:50 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:50 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:50 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:50 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:50 rivo volumio[5374]: info: ------------------------------ 54ms Apr 08 21:25:50 rivo volumio[5374]: info: ------------------------------ 46ms Apr 08 21:25:50 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 35 milliseconds Apr 08 21:25:50 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:50 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:50 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:50 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:50 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":70000,"duration":237,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1520 Kbps","isStreaming":false,"title":"22396310","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396310","trackType":"qobuz"} Apr 08 21:25:50 rivo volumio[5374]: verbose: CURRENT POSITION 2 Apr 08 21:25:50 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:50 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:50 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:50 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:50 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:50 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:50 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:50 rivo volumio[5374]: info: ------------------------------ 65ms Apr 08 21:25:52 rivo volumio[5374]: info: CoreCommandRouter::volumioNext Apr 08 21:25:52 rivo volumio[5374]: info: CoreStateMachine::next Apr 08 21:25:52 rivo volumio[5374]: info: [1712604352480] ControllerQobuz::next Apr 08 21:25:52 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:25:52 rivo volumio[5374]: info: CoreStateMachine::next Apr 08 21:25:52 rivo volumio[5374]: info: CoreStateMachine::stop Apr 08 21:25:52 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:25:52 rivo volumio[5374]: info: CoreStateMachine::stPlaybackTimer Apr 08 21:25:52 rivo volumio[5374]: info: CoreStateMachine::updateTrackBlock Apr 08 21:25:52 rivo volumio[5374]: info: CorePlayQueue::getTrackBlock Apr 08 21:25:52 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:52 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:52 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:52 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:52 rivo volumio[5374]: info: CoreStateMachine::serviceStop Apr 08 21:25:52 rivo volumio[5374]: info: CorePlayQueue::getTrack 2 Apr 08 21:25:52 rivo volumio[5374]: info: CoreCommandRouter::serviceStop Apr 08 21:25:52 rivo volumio[5374]: info: [1712604352491] ControllerQobuz::stop Apr 08 21:25:52 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 08 21:25:52 rivo volumio[5374]: info: ControllerMpd::stop Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand stop Apr 08 21:25:52 rivo volumio[5374]: STREAMING PROXY: Client dropped request, destroying Apr 08 21:25:52 rivo volumio[5374]: info: Apr 08 21:25:52 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:52 rivo volumio[5374]: info: sendMpdCommand stop took 48 milliseconds Apr 08 21:25:52 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:52 rivo volumio[5374]: info: CoreStateMachine::play index undefined Apr 08 21:25:52 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:25:52 rivo volumio[5374]: info: CorePlayQueue::getTrack 3 Apr 08 21:25:52 rivo volumio[5374]: info: CoreStateMachine::startPlaybackTimer Apr 08 21:25:52 rivo volumio[5374]: info: CorePlayQueue::getTrack 3 Apr 08 21:25:52 rivo volumio[5374]: info: [1712604352542] ControllerQobuz::clearAddPlayTrack Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand stop Apr 08 21:25:52 rivo volumio[5374]: info: CoreStateMachine::updateTrackBlock Apr 08 21:25:52 rivo volumio[5374]: info: CorePlayQueue::getTrackBlock Apr 08 21:25:52 rivo volumio[5374]: info: Apr 08 21:25:52 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:52 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:52 rivo volumio[5374]: info: Apr 08 21:25:52 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:52 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:52 rivo volumio[5374]: info: sendMpdCommand status took 8 milliseconds Apr 08 21:25:52 rivo volumio[5374]: info: sendMpdCommand stop took 7 milliseconds Apr 08 21:25:52 rivo volumio[5374]: info: sendMpdCommand status took 4 milliseconds Apr 08 21:25:52 rivo volumio[5374]: info: sendMpdCommand status took 2 milliseconds Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand clear Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:52 rivo volumio[5374]: info: Apr 08 21:25:52 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:52 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:52 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 08 21:25:52 rivo volumio[5374]: info: sendMpdCommand clear took 4 milliseconds Apr 08 21:25:52 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 08 21:25:52 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/22396311" Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:52 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:52 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:52 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:52 rivo volumio[5374]: info: CorePlayQueue::getTrack 3 Apr 08 21:25:52 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:52 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:52 rivo volumio[5374]: info: CorePlayQueue::getTrack 3 Apr 08 21:25:52 rivo volumio[5374]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Apr 08 21:25:52 rivo volumio[5374]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 08 21:25:52 rivo volumio[5374]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 08 21:25:52 rivo volumio[5374]: info: ------------------------------ 29ms Apr 08 21:25:52 rivo volumio[5374]: info: ------------------------------ 25ms Apr 08 21:25:52 rivo volumio[5374]: info: ------------------------------ 22ms Apr 08 21:25:52 rivo volumio[5374]: info: Apr 08 21:25:52 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:52 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:52 rivo volumio[5374]: info: Apr 08 21:25:52 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:52 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:52 rivo volumio[5374]: STREAMING PROXY: Handling url /?data=qobuz://song/22396311 Apr 08 21:25:52 rivo volumio[5374]: info: Executing endpoint getStreamUrlqobuz Apr 08 21:25:52 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 08 21:25:52 rivo volumio[5374]: info: getStreamUrl took 280 milliseconds Apr 08 21:25:52 rivo volumio[5374]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2676332&eid=22396311&fmt=7&profile=raw&app_id=539451548&cid=1859196&etsp=1712607952&hmac=GY57h03VlQSnr_agyR3gACoxURE Apr 08 21:25:52 rivo volumio[5374]: STREAMING PROXY: Response: 200, length: 41452278 Apr 08 21:25:52 rivo volumio[5374]: STREAMING PROXY: Client dropped request, destroying Apr 08 21:25:52 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:25:52 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:25:52 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:25:52 rivo volumio[5374]: info: ------------------------------ 395ms Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/22396311" Apr 08 21:25:52 rivo volumio[5374]: info: ------------------------------ 379ms Apr 08 21:25:52 rivo volumio[5374]: info: ------------------------------ 378ms Apr 08 21:25:52 rivo volumio[5374]: info: Apr 08 21:25:52 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:52 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:52 rivo volumio[5374]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/22396311" took 2 milliseconds Apr 08 21:25:52 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 08 21:25:52 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand play Apr 08 21:25:52 rivo volumio[5374]: info: Apr 08 21:25:52 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:52 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:52 rivo volumio[5374]: info: Apr 08 21:25:52 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:25:52 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:25:52 rivo volumio[5374]: STREAMING PROXY: Handling url /?data=qobuz://song/22396311 Apr 08 21:25:52 rivo volumio[5374]: info: ------------------------------ 7ms Apr 08 21:25:52 rivo volumio[5374]: info: sendMpdCommand play took 6 milliseconds Apr 08 21:25:52 rivo volumio[5374]: info: ------------------------------ 4ms Apr 08 21:25:52 rivo volumio[5374]: info: ------------------------------ 3ms Apr 08 21:25:52 rivo volumio[5374]: info: Executing endpoint getStreamUrlqobuz Apr 08 21:25:52 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 08 21:25:53 rivo volumio[5374]: info: getStreamUrl took 262 milliseconds Apr 08 21:25:53 rivo volumio[5374]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2676332&eid=22396311&fmt=7&profile=raw&app_id=539451548&cid=1859196&etsp=1712607953&hmac=ZcLhQxmRZr6jFg-Iqa6rt5SOtSA Apr 08 21:25:53 rivo volumio[5374]: STREAMING PROXY: Response: 200, length: 41452278 Apr 08 21:25:53 rivo volumio[5374]: info: Apr 08 21:25:53 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:53 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:53 rivo volumio[5374]: info: Apr 08 21:25:53 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:53 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:53 rivo volumio[5374]: info: Apr 08 21:25:53 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:53 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:53 rivo volumio[5374]: info: Apr 08 21:25:53 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:53 rivo volumio[5374]: info: sendMpdCommand status took 27 milliseconds Apr 08 21:25:53 rivo volumio[5374]: info: sendMpdCommand status took 26 milliseconds Apr 08 21:25:53 rivo volumio[5374]: info: sendMpdCommand status took 24 milliseconds Apr 08 21:25:53 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:53 rivo volumio[5374]: info: Apr 08 21:25:53 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:53 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:53 rivo volumio[5374]: info: Apr 08 21:25:53 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:25:53 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:25:53 rivo volumio[5374]: info: sendMpdCommand status took 10 milliseconds Apr 08 21:25:53 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 11 milliseconds Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:53 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:53 rivo volumio[5374]: info: CorePlayQueue::getTrack 3 Apr 08 21:25:53 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396311","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396311","trackType":"qobuz"} Apr 08 21:25:53 rivo volumio[5374]: verbose: CURRENT POSITION 3 Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus stop Apr 08 21:25:53 rivo volumio[5374]: info: ------------------------------ 48ms Apr 08 21:25:53 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 20 milliseconds Apr 08 21:25:53 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 20 milliseconds Apr 08 21:25:53 rivo volumio[5374]: info: sendMpdCommand status took 18 milliseconds Apr 08 21:25:53 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 9 milliseconds Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:53 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:53 rivo volumio[5374]: info: CorePlayQueue::getTrack 3 Apr 08 21:25:53 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396311","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396311","trackType":"qobuz"} Apr 08 21:25:53 rivo volumio[5374]: verbose: CURRENT POSITION 3 Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:53 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:53 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:53 rivo volumio[5374]: info: CorePlayQueue::getTrack 3 Apr 08 21:25:53 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396311","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396311","trackType":"qobuz"} Apr 08 21:25:53 rivo volumio[5374]: verbose: CURRENT POSITION 3 Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:53 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:53 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:53 rivo volumio[5374]: info: CorePlayQueue::getTrack 3 Apr 08 21:25:53 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396311","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396311","trackType":"qobuz"} Apr 08 21:25:53 rivo volumio[5374]: verbose: CURRENT POSITION 3 Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:53 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:53 rivo volumio[5374]: info: ------------------------------ 113ms Apr 08 21:25:53 rivo volumio[5374]: info: ------------------------------ 115ms Apr 08 21:25:53 rivo volumio[5374]: info: ------------------------------ 93ms Apr 08 21:25:53 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 68 milliseconds Apr 08 21:25:53 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 69 milliseconds Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:53 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:25:53 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:53 rivo volumio[5374]: info: CorePlayQueue::getTrack 3 Apr 08 21:25:53 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396311","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396311","trackType":"qobuz"} Apr 08 21:25:53 rivo volumio[5374]: verbose: CURRENT POSITION 3 Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:53 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:53 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:25:53 rivo volumio[5374]: info: CorePlayQueue::getTrack 3 Apr 08 21:25:53 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396311","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396311","trackType":"qobuz"} Apr 08 21:25:53 rivo volumio[5374]: verbose: CURRENT POSITION 3 Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:25:53 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:25:53 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:25:53 rivo volumio[5374]: info: ------------------------------ 140ms Apr 08 21:25:53 rivo volumio[5374]: info: ------------------------------ 141ms Apr 08 21:25:58 rivo volumio[5374]: STREAMING PROXY: Client dropped request, destroying Apr 08 21:26:09 rivo volumio[5374]: info: CoreCommandRouter::volumioNext Apr 08 21:26:09 rivo volumio[5374]: info: CoreStateMachine::next Apr 08 21:26:09 rivo volumio[5374]: info: [1712604369616] ControllerQobuz::next Apr 08 21:26:09 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:26:09 rivo volumio[5374]: info: CoreStateMachine::next Apr 08 21:26:09 rivo volumio[5374]: info: CoreStateMachine::stop Apr 08 21:26:09 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:26:09 rivo volumio[5374]: info: CoreStateMachine::stPlaybackTimer Apr 08 21:26:09 rivo volumio[5374]: info: CoreStateMachine::updateTrackBlock Apr 08 21:26:09 rivo volumio[5374]: info: CorePlayQueue::getTrackBlock Apr 08 21:26:09 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:26:09 rivo volumio[5374]: info: CorePlayQueue::getTrack 3 Apr 08 21:26:09 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:26:09 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:26:09 rivo volumio[5374]: info: CoreStateMachine::serviceStop Apr 08 21:26:09 rivo volumio[5374]: info: CorePlayQueue::getTrack 3 Apr 08 21:26:09 rivo volumio[5374]: info: CoreCommandRouter::serviceStop Apr 08 21:26:09 rivo volumio[5374]: info: [1712604369633] ControllerQobuz::stop Apr 08 21:26:09 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 08 21:26:09 rivo volumio[5374]: info: ControllerMpd::stop Apr 08 21:26:09 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand stop Apr 08 21:26:09 rivo volumio[5374]: info: Apr 08 21:26:09 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:26:09 rivo volumio[5374]: info: sendMpdCommand stop took 66 milliseconds Apr 08 21:26:09 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:26:09 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:26:09 rivo volumio[5374]: info: CoreStateMachine::play index undefined Apr 08 21:26:09 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 08 21:26:09 rivo volumio[5374]: info: CorePlayQueue::getTrack 4 Apr 08 21:26:09 rivo volumio[5374]: info: CoreStateMachine::startPlaybackTimer Apr 08 21:26:09 rivo volumio[5374]: info: CorePlayQueue::getTrack 4 Apr 08 21:26:09 rivo volumio[5374]: info: [1712604369701] ControllerQobuz::clearAddPlayTrack Apr 08 21:26:09 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand stop Apr 08 21:26:09 rivo volumio[5374]: info: CoreStateMachine::updateTrackBlock Apr 08 21:26:09 rivo volumio[5374]: info: CorePlayQueue::getTrackBlock Apr 08 21:26:09 rivo volumio[5374]: info: Apr 08 21:26:09 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:26:09 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:26:09 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:26:09 rivo volumio[5374]: info: Apr 08 21:26:09 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:26:09 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:26:09 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:26:09 rivo volumio[5374]: info: sendMpdCommand status took 7 milliseconds Apr 08 21:26:09 rivo volumio[5374]: info: sendMpdCommand stop took 5 milliseconds Apr 08 21:26:09 rivo volumio[5374]: info: sendMpdCommand status took 3 milliseconds Apr 08 21:26:09 rivo volumio[5374]: info: sendMpdCommand status took 2 milliseconds Apr 08 21:26:09 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:26:09 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:26:09 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand clear Apr 08 21:26:09 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:26:09 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:26:09 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:26:09 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:26:09 rivo volumio[5374]: info: Apr 08 21:26:09 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:26:09 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:26:09 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 08 21:26:09 rivo volumio[5374]: info: sendMpdCommand clear took 4 milliseconds Apr 08 21:26:09 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 08 21:26:09 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 08 21:26:09 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:26:09 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/22396312" Apr 08 21:26:09 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:26:09 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:26:09 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:26:09 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:26:09 rivo volumio[5374]: info: CorePlayQueue::getTrack 4 Apr 08 21:26:09 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:26:09 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:26:09 rivo volumio[5374]: info: CorePlayQueue::getTrack 4 Apr 08 21:26:09 rivo volumio[5374]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd Apr 08 21:26:09 rivo volumio[5374]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 08 21:26:09 rivo volumio[5374]: STREAMING PROXY: Handling url /?data=qobuz://song/22396312 Apr 08 21:26:09 rivo volumio[5374]: info: ------------------------------ 31ms Apr 08 21:26:09 rivo volumio[5374]: info: ------------------------------ 26ms Apr 08 21:26:09 rivo volumio[5374]: info: ------------------------------ 25ms Apr 08 21:26:09 rivo volumio[5374]: info: Apr 08 21:26:09 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:26:09 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:26:09 rivo volumio[5374]: info: Apr 08 21:26:09 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:26:09 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:26:09 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:26:09 rivo volumio[5374]: info: ------------------------------ 22ms Apr 08 21:26:09 rivo volumio[5374]: info: Executing endpoint getStreamUrlqobuz Apr 08 21:26:09 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 08 21:26:10 rivo volumio[5374]: info: getStreamUrl took 321 milliseconds Apr 08 21:26:10 rivo volumio[5374]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2676332&eid=22396312&fmt=7&profile=raw&app_id=539451548&cid=1859196&etsp=1712607970&hmac=HLffrcxERX6wpaIMl2qYt179JoA Apr 08 21:26:10 rivo volumio[5374]: STREAMING PROXY: Response: 200, length: 48918941 Apr 08 21:26:10 rivo volumio[5374]: STREAMING PROXY: Client dropped request, destroying Apr 08 21:26:10 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:26:10 rivo volumio[5374]: error: updateQueue error: null Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/22396312" Apr 08 21:26:10 rivo volumio[5374]: info: ------------------------------ 595ms Apr 08 21:26:10 rivo volumio[5374]: info: ------------------------------ 595ms Apr 08 21:26:10 rivo volumio[5374]: info: Apr 08 21:26:10 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:26:10 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:26:10 rivo volumio[5374]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/22396312" took 2 milliseconds Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand play Apr 08 21:26:10 rivo volumio[5374]: info: Apr 08 21:26:10 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:26:10 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:26:10 rivo volumio[5374]: STREAMING PROXY: Handling url /?data=qobuz://song/22396312 Apr 08 21:26:10 rivo volumio[5374]: info: Apr 08 21:26:10 rivo volumio[5374]: ---------------------------- MPD announces system playlist update Apr 08 21:26:10 rivo volumio[5374]: info: Ignoring MPD Status Update Apr 08 21:26:10 rivo volumio[5374]: info: ------------------------------ 6ms Apr 08 21:26:10 rivo volumio[5374]: info: sendMpdCommand play took 5 milliseconds Apr 08 21:26:10 rivo volumio[5374]: info: ------------------------------ 5ms Apr 08 21:26:10 rivo volumio[5374]: info: ------------------------------ 3ms Apr 08 21:26:10 rivo volumio[5374]: info: Executing endpoint getStreamUrlqobuz Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Apr 08 21:26:10 rivo volumio[5374]: info: getStreamUrl took 293 milliseconds Apr 08 21:26:10 rivo volumio[5374]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2676332&eid=22396312&fmt=7&profile=raw&app_id=539451548&cid=1859196&etsp=1712607970&hmac=HLffrcxERX6wpaIMl2qYt179JoA Apr 08 21:26:10 rivo volumio[5374]: STREAMING PROXY: Response: 200, length: 48918941 Apr 08 21:26:10 rivo volumio[5374]: info: Apr 08 21:26:10 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:26:10 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:26:10 rivo volumio[5374]: info: Apr 08 21:26:10 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:26:10 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:26:10 rivo volumio[5374]: info: Apr 08 21:26:10 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:26:10 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:26:10 rivo volumio[5374]: info: sendMpdCommand status took 31 milliseconds Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:26:10 rivo volumio[5374]: info: Apr 08 21:26:10 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:26:10 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:26:10 rivo volumio[5374]: info: sendMpdCommand status took 36 milliseconds Apr 08 21:26:10 rivo volumio[5374]: info: sendMpdCommand status took 36 milliseconds Apr 08 21:26:10 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:26:10 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:26:10 rivo volumio[5374]: info: CorePlayQueue::getTrack 4 Apr 08 21:26:10 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":223,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396312","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396312","trackType":"qobuz"} Apr 08 21:26:10 rivo volumio[5374]: verbose: CURRENT POSITION 4 Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus stop Apr 08 21:26:10 rivo volumio[5374]: info: ------------------------------ 54ms Apr 08 21:26:10 rivo volumio[5374]: info: Apr 08 21:26:10 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:26:10 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:26:10 rivo volumio[5374]: info: Apr 08 21:26:10 rivo volumio[5374]: ---------------------------- MPD announces state update: player Apr 08 21:26:10 rivo volumio[5374]: info: ControllerMpd::getState Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand status Apr 08 21:26:10 rivo volumio[5374]: info: sendMpdCommand status took 23 milliseconds Apr 08 21:26:10 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 21 milliseconds Apr 08 21:26:10 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 19 milliseconds Apr 08 21:26:10 rivo volumio[5374]: info: sendMpdCommand status took 7 milliseconds Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:26:10 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:26:10 rivo volumio[5374]: info: CorePlayQueue::getTrack 4 Apr 08 21:26:10 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":223,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396312","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396312","trackType":"qobuz"} Apr 08 21:26:10 rivo volumio[5374]: verbose: CURRENT POSITION 4 Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:26:10 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:26:10 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:26:10 rivo volumio[5374]: info: CorePlayQueue::getTrack 4 Apr 08 21:26:10 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":223,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396312","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396312","trackType":"qobuz"} Apr 08 21:26:10 rivo volumio[5374]: verbose: CURRENT POSITION 4 Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:26:10 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:26:10 rivo volumio[5374]: info: ------------------------------ 114ms Apr 08 21:26:10 rivo volumio[5374]: info: ------------------------------ 116ms Apr 08 21:26:10 rivo volumio[5374]: info: sendMpdCommand status took 62 milliseconds Apr 08 21:26:10 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 57 milliseconds Apr 08 21:26:10 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 54 milliseconds Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::parseState Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:26:10 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:26:10 rivo volumio[5374]: info: CorePlayQueue::getTrack 4 Apr 08 21:26:10 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":223,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"22396312","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396312","trackType":"qobuz"} Apr 08 21:26:10 rivo volumio[5374]: verbose: CURRENT POSITION 4 Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:26:10 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:26:10 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:26:10 rivo volumio[5374]: info: CorePlayQueue::getTrack 4 Apr 08 21:26:10 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":223,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1594 Kbps","isStreaming":false,"title":"22396312","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396312","trackType":"qobuz"} Apr 08 21:26:10 rivo volumio[5374]: verbose: CURRENT POSITION 4 Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:26:10 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:26:10 rivo volumio[5374]: info: ------------------------------ 171ms Apr 08 21:26:10 rivo volumio[5374]: info: ------------------------------ 155ms Apr 08 21:26:10 rivo volumio[5374]: info: sendMpdCommand playlistinfo took 124 milliseconds Apr 08 21:26:10 rivo volumio[5374]: verbose: ControllerMpd::parseTrackInfo Apr 08 21:26:10 rivo volumio[5374]: info: ControllerMpd::pushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::servicePushState Apr 08 21:26:10 rivo volumio[5374]: info: CorePlayQueue::getTrack 4 Apr 08 21:26:10 rivo volumio[5374]: verbose: STATE SERVICE {"status":"play","position":0,"seek":986,"duration":223,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1594 Kbps","isStreaming":false,"title":"22396312","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/22396312","trackType":"qobuz"} Apr 08 21:26:10 rivo volumio[5374]: verbose: CURRENT POSITION 4 Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::syncState stateService play Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::syncState currentStatus play Apr 08 21:26:10 rivo volumio[5374]: info: Received an update from plugin. extracting info from payload Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreStateMachine::pushState Apr 08 21:26:10 rivo volumio[5374]: info: CoreCommandRouter::volumioPushState Apr 08 21:26:10 rivo volumio[5374]: info: ------------------------------ 210ms Apr 08 21:26:17 rivo volumio[5374]: STREAMING PROXY: Client dropped request, destroying Apr 08 21:26:21 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Apr 08 21:26:21 rivo volumio[5374]: info: handleBrowseUri took 130 milliseconds Apr 08 21:26:21 rivo volumio[5374]: info: Preload queue cleared Apr 08 21:26:21 rivo volumio[5374]: info: Preload queue cleared Apr 08 21:26:39 rivo volumio[5374]: info: CoreCommandRouter::executeOnPlugin: metavolumio , superSearch Apr 08 21:26:39 rivo volumio[5374]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 08 21:26:39 rivo volumio[5374]: TypeError: Cannot read property 'then' of undefined Apr 08 21:26:39 rivo volumio[5374]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:470:20) Apr 08 21:26:39 rivo volumio[5374]: at Socket.emit (events.js:400:28) Apr 08 21:26:39 rivo volumio[5374]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Apr 08 21:26:39 rivo volumio[5374]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Apr 08 21:26:39 rivo volumio[5374]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 08 21:26:40 rivo sudo[11377]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-08 21:25 Apr 08 21:26:40 rivo sudo[11377]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="e831866afe2db61aee9333a8f5ba9d9fd36609c7" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sun 18 Feb 2024 11:41:55 AM CET" VOLUMIO_VERSION="3.629" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="b0437c7088d6645a661a49f6d9fa596a"