-- Logs begin at Sun 2025-01-12 10:28:29 UTC, end at Sun 2025-01-12 17:35:34 UTC. -- Jan 12 17:34:03 volumio volumio[19824]: Searching plugin music_service/qobuz Jan 12 17:34:03 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 12 17:34:06 volumio volumio[19824]: info: searchQOBUZUri took 3208 milliseconds Jan 12 17:34:06 volumio volumio[19824]: info: All search sources collected, pushing search results Jan 12 17:34:07 volumio volumio[19824]: Searching plugin music_service/qobuz Jan 12 17:34:07 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 12 17:34:08 volumio volumio[19824]: Searching plugin music_service/qobuz Jan 12 17:34:08 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 12 17:34:10 volumio volumio[19824]: info: searchQOBUZUri took 2612 milliseconds Jan 12 17:34:10 volumio volumio[19824]: info: All search sources collected, pushing search results Jan 12 17:34:11 volumio volumio[19824]: Searching plugin music_service/qobuz Jan 12 17:34:11 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 12 17:34:11 volumio volumio[19824]: info: searchQOBUZUri took 2479 milliseconds Jan 12 17:34:11 volumio volumio[19824]: info: All search sources collected, pushing search results Jan 12 17:34:12 volumio volumio[19824]: Searching plugin music_service/qobuz Jan 12 17:34:12 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Jan 12 17:34:13 volumio volumio[19824]: info: searchQOBUZUri took 2134 milliseconds Jan 12 17:34:13 volumio volumio[19824]: info: All search sources collected, pushing search results Jan 12 17:34:14 volumio volumio[19824]: info: searchQOBUZUri took 2211 milliseconds Jan 12 17:34:14 volumio volumio[19824]: info: All search sources collected, pushing search results Jan 12 17:34:19 volumio volumio[19824]: info: CorePlayQueue::getTrack 9 Jan 12 17:34:19 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:19 volumio volumio[19824]: info: Prefetching next song Jan 12 17:34:19 volumio volumio[19824]: info: [1736703259728] ControllerQobuz::prefetch Jan 12 17:34:19 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/31773429" Jan 12 17:34:19 volumio volumio[19824]: STREAMING PROXY: Handling url /?data=qobuz://song/31773429 Jan 12 17:34:19 volumio volumio[19824]: info: Executing endpoint getStreamUrlqobuz Jan 12 17:34:19 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jan 12 17:34:20 volumio volumio[19824]: info: getStreamUrl took 536 milliseconds Jan 12 17:34:20 volumio volumio[19824]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1672396&eid=31773429&fmt=7&profile=raw&app_id=539451548&cid=2018744&etsp=1736706860&hmac=_1IFsvVhuuFJKwkPhM7DNg4_1h8 Jan 12 17:34:21 volumio volumio[19824]: STREAMING PROXY: Response: 200, length: 53839177 Jan 12 17:34:21 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/31773429" Jan 12 17:34:21 volumio volumio[19824]: STREAMING PROXY: Client dropped request, destroying Jan 12 17:34:21 volumio volumio[19824]: info: Jan 12 17:34:21 volumio volumio[19824]: ---------------------------- MPD announces system playlist update Jan 12 17:34:21 volumio volumio[19824]: info: Ignoring MPD Status Update Jan 12 17:34:21 volumio volumio[19824]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/31773429" took 1 milliseconds Jan 12 17:34:21 volumio volumio[19824]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 12 17:34:21 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand consume 1 Jan 12 17:34:21 volumio volumio[19824]: info: Jan 12 17:34:21 volumio volumio[19824]: ---------------------------- MPD announces system playlist update Jan 12 17:34:21 volumio volumio[19824]: info: Ignoring MPD Status Update Jan 12 17:34:21 volumio volumio[19824]: STREAMING PROXY: Handling url /?data=qobuz://song/31773429 Jan 12 17:34:21 volumio volumio[19824]: info: Jan 12 17:34:21 volumio volumio[19824]: ---------------------------- MPD announces system playlist update Jan 12 17:34:21 volumio volumio[19824]: info: Ignoring MPD Status Update Jan 12 17:34:21 volumio volumio[19824]: info: Jan 12 17:34:21 volumio volumio[19824]: ---------------------------- MPD announces system playlist update Jan 12 17:34:21 volumio volumio[19824]: info: Ignoring MPD Status Update Jan 12 17:34:21 volumio volumio[19824]: info: ------------------------------ 4ms Jan 12 17:34:21 volumio volumio[19824]: info: sendMpdCommand consume 1 took 4 milliseconds Jan 12 17:34:21 volumio volumio[19824]: info: ------------------------------ 3ms Jan 12 17:34:21 volumio volumio[19824]: info: ------------------------------ 2ms Jan 12 17:34:21 volumio volumio[19824]: info: Executing endpoint getStreamUrlqobuz Jan 12 17:34:21 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jan 12 17:34:21 volumio volumio[19824]: info: getStreamUrl took 682 milliseconds Jan 12 17:34:21 volumio volumio[19824]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1672396&eid=31773429&fmt=7&profile=raw&app_id=539451548&cid=2018744&etsp=1736706861&hmac=rVhbbL1-cjnfPpAF5gHcaDFxh-M Jan 12 17:34:21 volumio volumio[19824]: STREAMING PROXY: Response: 200, length: 53839177 Jan 12 17:34:24 volumio volumio[19824]: info: CoreStateMachine::startPlaybackTimer Jan 12 17:34:24 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:24 volumio volumio[19824]: info: Jan 12 17:34:24 volumio volumio[19824]: ---------------------------- MPD announces system playlist update Jan 12 17:34:24 volumio volumio[19824]: info: Ignoring MPD Status Update Jan 12 17:34:24 volumio volumio[19824]: info: Jan 12 17:34:24 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:24 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:24 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:24 volumio volumio[19824]: info: Jan 12 17:34:24 volumio volumio[19824]: ---------------------------- MPD announces system playlist update Jan 12 17:34:24 volumio volumio[19824]: info: Ignoring MPD Status Update Jan 12 17:34:24 volumio volumio[19824]: info: Jan 12 17:34:24 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:24 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:24 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:24 volumio volumio[19824]: info: ------------------------------ 2ms Jan 12 17:34:24 volumio volumio[19824]: info: Jan 12 17:34:24 volumio volumio[19824]: ---------------------------- MPD announces system playlist update Jan 12 17:34:24 volumio volumio[19824]: info: Ignoring MPD Status Update Jan 12 17:34:24 volumio volumio[19824]: info: Jan 12 17:34:24 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:24 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:24 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:24 volumio volumio[19824]: info: Jan 12 17:34:24 volumio volumio[19824]: ---------------------------- MPD announces system playlist update Jan 12 17:34:24 volumio volumio[19824]: info: Ignoring MPD Status Update Jan 12 17:34:24 volumio volumio[19824]: info: Jan 12 17:34:24 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:24 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:24 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:24 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:24 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:24 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 17:34:24 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:24 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:24 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Jan 12 17:34:25 volumio volumio[19824]: info: Jan 12 17:34:25 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:25 volumio volumio[19824]: info: sendMpdCommand status took 1134 milliseconds Jan 12 17:34:25 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:25 volumio volumio[19824]: info: ------------------------------ 1136ms Jan 12 17:34:25 volumio volumio[19824]: info: sendMpdCommand status took 1136 milliseconds Jan 12 17:34:25 volumio volumio[19824]: info: ------------------------------ 1135ms Jan 12 17:34:25 volumio volumio[19824]: info: sendMpdCommand status took 1135 milliseconds Jan 12 17:34:25 volumio volumio[19824]: info: ------------------------------ 1135ms Jan 12 17:34:25 volumio volumio[19824]: info: sendMpdCommand status took 1134 milliseconds Jan 12 17:34:25 volumio volumio[19824]: info: sendMpdCommand status took 2 milliseconds Jan 12 17:34:25 volumio volumio[19824]: info: sendMpdCommand playlistinfo took 3 milliseconds Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::parseTrackInfo Jan 12 17:34:25 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":305,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1180 Kbps","isStreaming":false,"title":"31773429","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/31773429","trackType":"qobuz"} Jan 12 17:34:25 volumio volumio[19824]: verbose: CURRENT POSITION 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::syncState stateService play Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus play Jan 12 17:34:25 volumio volumio[19824]: info: Received an update from plugin. extracting info from payload Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: ------------------------------ 1171ms Jan 12 17:34:25 volumio volumio[19824]: info: Jan 12 17:34:25 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:25 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:25 volumio volumio[19824]: info: Jan 12 17:34:25 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:25 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:25 volumio volumio[19824]: info: Jan 12 17:34:25 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:25 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:25 volumio volumio[19824]: info: sendMpdCommand playlistinfo took 37 milliseconds Jan 12 17:34:25 volumio volumio[19824]: info: sendMpdCommand playlistinfo took 38 milliseconds Jan 12 17:34:25 volumio volumio[19824]: info: sendMpdCommand status took 4 milliseconds Jan 12 17:34:25 volumio volumio[19824]: info: sendMpdCommand status took 1 milliseconds Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::parseTrackInfo Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:25 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: verbose: STATE SERVICE {"status":"play","position":0,"seek":411,"duration":305,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1192 Kbps","isStreaming":false,"title":"31773429","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/31773429","trackType":"qobuz"} Jan 12 17:34:25 volumio volumio[19824]: verbose: CURRENT POSITION 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::syncState stateService play Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus play Jan 12 17:34:25 volumio volumio[19824]: info: Received an update from plugin. extracting info from payload Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: verbose: STATE SERVICE {"status":"play","position":0,"seek":411,"duration":305,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1192 Kbps","isStreaming":false,"title":"31773429","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/31773429","trackType":"qobuz"} Jan 12 17:34:25 volumio volumio[19824]: verbose: CURRENT POSITION 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::syncState stateService play Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus play Jan 12 17:34:25 volumio volumio[19824]: info: Received an update from plugin. extracting info from payload Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: verbose: STATE SERVICE {"status":"play","position":0,"seek":411,"duration":305,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1192 Kbps","isStreaming":false,"title":"31773429","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/31773429","trackType":"qobuz"} Jan 12 17:34:25 volumio volumio[19824]: verbose: CURRENT POSITION 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::syncState stateService play Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus play Jan 12 17:34:25 volumio volumio[19824]: info: Received an update from plugin. extracting info from payload Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: verbose: STATE SERVICE {"status":"play","position":0,"seek":422,"duration":305,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1181 Kbps","isStreaming":false,"title":"31773429","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/31773429","trackType":"qobuz"} Jan 12 17:34:25 volumio volumio[19824]: verbose: CURRENT POSITION 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::syncState stateService play Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus play Jan 12 17:34:25 volumio volumio[19824]: info: Received an update from plugin. extracting info from payload Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: ------------------------------ 1204ms Jan 12 17:34:25 volumio volumio[19824]: info: ------------------------------ 1202ms Jan 12 17:34:25 volumio volumio[19824]: info: ------------------------------ 1203ms Jan 12 17:34:25 volumio volumio[19824]: info: ------------------------------ 71ms Jan 12 17:34:25 volumio volumio[19824]: info: sendMpdCommand playlistinfo took 55 milliseconds Jan 12 17:34:25 volumio volumio[19824]: info: sendMpdCommand playlistinfo took 56 milliseconds Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::parseTrackInfo Jan 12 17:34:25 volumio volumio[19824]: verbose: ControllerMpd::parseTrackInfo Jan 12 17:34:25 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1097,"duration":305,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1227 Kbps","isStreaming":false,"title":"31773429","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/31773429","trackType":"qobuz"} Jan 12 17:34:25 volumio volumio[19824]: verbose: CURRENT POSITION 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::syncState stateService play Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus play Jan 12 17:34:25 volumio volumio[19824]: info: Received an update from plugin. extracting info from payload Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1097,"duration":305,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1227 Kbps","isStreaming":false,"title":"31773429","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/31773429","trackType":"qobuz"} Jan 12 17:34:25 volumio volumio[19824]: verbose: CURRENT POSITION 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::syncState stateService play Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus play Jan 12 17:34:25 volumio volumio[19824]: info: Received an update from plugin. extracting info from payload Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":305,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1227 Kbps","isStreaming":false,"title":"31773429","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/31773429","trackType":"qobuz"} Jan 12 17:34:25 volumio volumio[19824]: verbose: CURRENT POSITION 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::syncState stateService play Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus play Jan 12 17:34:25 volumio volumio[19824]: info: Received an update from plugin. extracting info from payload Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:25 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:25 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:25 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:25 volumio volumio[19824]: info: ------------------------------ 84ms Jan 12 17:34:25 volumio volumio[19824]: info: ------------------------------ 83ms Jan 12 17:34:25 volumio volumio[19824]: info: ------------------------------ 84ms Jan 12 17:34:25 volumio volumio[19824]: STREAMING PROXY: Client dropped request, destroying Jan 12 17:34:26 volumio volumio[19824]: info: handleBrowseUri took 916 milliseconds Jan 12 17:34:26 volumio volumio[19824]: info: Preload queue cleared Jan 12 17:34:26 volumio volumio[19824]: info: Preloading song: qobuz://song/306251876 Jan 12 17:34:26 volumio volumio[19824]: info: Preloading song: qobuz://song/306251877 Jan 12 17:34:26 volumio volumio[19824]: info: Preloading song: qobuz://song/306251878 Jan 12 17:34:26 volumio volumio[19824]: info: Preloading song: qobuz://song/306251879 Jan 12 17:34:26 volumio volumio[19824]: info: Preloading song: qobuz://song/306251880 Jan 12 17:34:26 volumio volumio[19824]: info: Preloading song: qobuz://song/306251881 Jan 12 17:34:26 volumio volumio[19824]: info: Preloading song: qobuz://song/306251882 Jan 12 17:34:26 volumio volumio[19824]: info: Preloading song: qobuz://song/306251883 Jan 12 17:34:26 volumio volumio[19824]: info: Preloading song: qobuz://song/306251884 Jan 12 17:34:26 volumio volumio[19824]: info: Preloading song: qobuz://song/306251885 Jan 12 17:34:26 volumio volumio[19824]: info: Preloading song: qobuz://song/306251886 Jan 12 17:34:26 volumio volumio[19824]: info: Exploding uri qobuz://song/306251876 in service qobuz Jan 12 17:34:26 volumio volumio[19824]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 12 17:34:26 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:26 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:26 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:26 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:26 volumio volumio[19824]: info: Exploding uri qobuz://song/306251877 in service qobuz Jan 12 17:34:26 volumio volumio[19824]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 12 17:34:26 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:26 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:26 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:26 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:26 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:26 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:26 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:26 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:26 volumio volumio[19824]: info: Exploding uri qobuz://song/306251878 in service qobuz Jan 12 17:34:26 volumio volumio[19824]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 12 17:34:26 volumio volumio[19824]: info: Exploding uri qobuz://song/306251879 in service qobuz Jan 12 17:34:26 volumio volumio[19824]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 12 17:34:26 volumio volumio[19824]: info: Exploding uri qobuz://song/306251880 in service qobuz Jan 12 17:34:26 volumio volumio[19824]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 12 17:34:26 volumio volumio[19824]: info: Exploding uri qobuz://song/306251881 in service qobuz Jan 12 17:34:26 volumio volumio[19824]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 12 17:34:26 volumio volumio[19824]: info: Exploding uri qobuz://song/306251882 in service qobuz Jan 12 17:34:26 volumio volumio[19824]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 12 17:34:26 volumio volumio[19824]: info: Exploding uri qobuz://song/306251883 in service qobuz Jan 12 17:34:26 volumio volumio[19824]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 12 17:34:26 volumio volumio[19824]: info: Exploding uri qobuz://song/306251884 in service qobuz Jan 12 17:34:26 volumio volumio[19824]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 12 17:34:26 volumio volumio[19824]: info: Exploding uri qobuz://song/306251885 in service qobuz Jan 12 17:34:26 volumio volumio[19824]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 12 17:34:26 volumio volumio[19824]: info: Exploding uri qobuz://song/306251886 in service qobuz Jan 12 17:34:26 volumio volumio[19824]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 12 17:34:26 volumio volumio[19824]: info: explodeUri took 529 milliseconds Jan 12 17:34:26 volumio volumio[19824]: info: explodeUri took 634 milliseconds Jan 12 17:34:26 volumio volumio[19824]: info: explodeUri took 550 milliseconds Jan 12 17:34:26 volumio volumio[19824]: info: explodeUri took 527 milliseconds Jan 12 17:34:26 volumio volumio[19824]: info: explodeUri took 675 milliseconds Jan 12 17:34:26 volumio volumio[19824]: info: explodeUri took 520 milliseconds Jan 12 17:34:27 volumio volumio[19824]: info: explodeUri took 594 milliseconds Jan 12 17:34:27 volumio volumio[19824]: info: explodeUri took 563 milliseconds Jan 12 17:34:27 volumio volumio[19824]: info: explodeUri took 485 milliseconds Jan 12 17:34:27 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:27 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:27 volumio volumio[19824]: info: explodeUri took 602 milliseconds Jan 12 17:34:27 volumio volumio[19824]: info: explodeUri took 558 milliseconds Jan 12 17:34:27 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:27 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:27 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:27 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:27 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:27 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:27 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:27 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:28 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:28 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:28 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:28 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:28 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:28 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:28 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:28 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:29 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:29 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:29 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:29 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:30 volumio volumio[19824]: info: Preload queue cleared Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::ClearQueue Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::stop Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::stPlaybackTimer Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::updateTrackBlock Jan 12 17:34:30 volumio volumio[19824]: info: CorePlayQueue::getTrackBlock Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::serviceStop Jan 12 17:34:30 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::serviceStop Jan 12 17:34:30 volumio volumio[19824]: info: [1736703270395] ControllerQobuz::stop Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 12 17:34:30 volumio volumio[19824]: info: ControllerMpd::stop Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand stop Jan 12 17:34:30 volumio volumio[19824]: info: CorePlayQueue::clearPlayQueue Jan 12 17:34:30 volumio volumio[19824]: info: CorePlayQueue::saveQueue Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioPushQueue Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::addQueueItems Jan 12 17:34:30 volumio volumio[19824]: info: CorePlayQueue::addQueueItems Jan 12 17:34:30 volumio volumio[19824]: info: Preload queue cleared Jan 12 17:34:30 volumio volumio[19824]: info: Adding Item to queue: qobuz://album/np6zd2foa1xpa Jan 12 17:34:30 volumio volumio[19824]: info: Exploding uri qobuz://album/np6zd2foa1xpa in service qobuz Jan 12 17:34:30 volumio volumio[19824]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 12 17:34:30 volumio volumio[19824]: info: Jan 12 17:34:30 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:30 volumio volumio[19824]: info: sendMpdCommand stop took 15 milliseconds Jan 12 17:34:30 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:30 volumio volumio[19824]: info: sendMpdCommand status took 1 milliseconds Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:30 volumio volumio[19824]: info: Jan 12 17:34:30 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:30 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:30 volumio volumio[19824]: info: Jan 12 17:34:30 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:30 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:30 volumio volumio[19824]: info: Jan 12 17:34:30 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:30 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:30 volumio volumio[19824]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 12 17:34:30 volumio volumio[19824]: info: sendMpdCommand status took 3 milliseconds Jan 12 17:34:30 volumio volumio[19824]: info: sendMpdCommand status took 2 milliseconds Jan 12 17:34:30 volumio volumio[19824]: info: sendMpdCommand status took 1 milliseconds Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::parseTrackInfo Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:30 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:30 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:30 volumio volumio[19824]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"31773429","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/31773429","trackType":"qobuz"} Jan 12 17:34:30 volumio volumio[19824]: verbose: CURRENT POSITION 10 Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::syncState stateService stop Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus stop Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:30 volumio volumio[19824]: info: No code Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:30 volumio volumio[19824]: info: ------------------------------ 22ms Jan 12 17:34:30 volumio volumio[19824]: info: sendMpdCommand playlistinfo took 15 milliseconds Jan 12 17:34:30 volumio volumio[19824]: info: sendMpdCommand playlistinfo took 15 milliseconds Jan 12 17:34:30 volumio volumio[19824]: info: sendMpdCommand playlistinfo took 14 milliseconds Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::parseTrackInfo Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::parseTrackInfo Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::parseTrackInfo Jan 12 17:34:30 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:30 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:30 volumio volumio[19824]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"31773429","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/31773429","trackType":"qobuz"} Jan 12 17:34:30 volumio volumio[19824]: verbose: CURRENT POSITION 10 Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::syncState stateService stop Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus stop Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:30 volumio volumio[19824]: info: No code Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:30 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:30 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:30 volumio volumio[19824]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"31773429","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/31773429","trackType":"qobuz"} Jan 12 17:34:30 volumio volumio[19824]: verbose: CURRENT POSITION 10 Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::syncState stateService stop Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus stop Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:30 volumio volumio[19824]: info: No code Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:30 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:30 volumio volumio[19824]: info: CorePlayQueue::getTrack 10 Jan 12 17:34:30 volumio volumio[19824]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"31773429","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/31773429","trackType":"qobuz"} Jan 12 17:34:30 volumio volumio[19824]: verbose: CURRENT POSITION 10 Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::syncState stateService stop Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus stop Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:30 volumio volumio[19824]: info: No code Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:30 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:30 volumio volumio[19824]: info: ------------------------------ 52ms Jan 12 17:34:30 volumio volumio[19824]: info: ------------------------------ 51ms Jan 12 17:34:30 volumio volumio[19824]: info: ------------------------------ 51ms Jan 12 17:34:30 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:30 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:30 volumio volumio[19824]: info: explodeUri took 442 milliseconds Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioPushQueue Jan 12 17:34:30 volumio volumio[19824]: info: CorePlayQueue::saveQueue Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::updateTrackBlock Jan 12 17:34:30 volumio volumio[19824]: info: CorePlayQueue::getTrackBlock Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::volumioPlay Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::play index 0 Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::stop Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::play index undefined Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 17:34:30 volumio volumio[19824]: info: CorePlayQueue::getTrack 0 Jan 12 17:34:30 volumio volumio[19824]: info: CoreStateMachine::startPlaybackTimer Jan 12 17:34:30 volumio volumio[19824]: info: CorePlayQueue::getTrack 0 Jan 12 17:34:30 volumio volumio[19824]: info: [1736703270843] ControllerQobuz::clearAddPlayTrack Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand stop Jan 12 17:34:30 volumio volumio[19824]: info: sendMpdCommand stop took 2 milliseconds Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand clear Jan 12 17:34:30 volumio volumio[19824]: info: Jan 12 17:34:30 volumio volumio[19824]: ---------------------------- MPD announces system playlist update Jan 12 17:34:30 volumio volumio[19824]: info: Ignoring MPD Status Update Jan 12 17:34:30 volumio volumio[19824]: info: sendMpdCommand clear took 1 milliseconds Jan 12 17:34:30 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/306251876" Jan 12 17:34:30 volumio volumio[19824]: info: Jan 12 17:34:30 volumio volumio[19824]: ---------------------------- MPD announces system playlist update Jan 12 17:34:30 volumio volumio[19824]: info: Ignoring MPD Status Update Jan 12 17:34:30 volumio volumio[19824]: info: Jan 12 17:34:30 volumio volumio[19824]: ---------------------------- MPD announces system playlist update Jan 12 17:34:30 volumio volumio[19824]: info: Ignoring MPD Status Update Jan 12 17:34:30 volumio volumio[19824]: STREAMING PROXY: Handling url /?data=qobuz://song/306251876 Jan 12 17:34:30 volumio volumio[19824]: info: Jan 12 17:34:30 volumio volumio[19824]: ---------------------------- MPD announces system playlist update Jan 12 17:34:30 volumio volumio[19824]: info: Ignoring MPD Status Update Jan 12 17:34:30 volumio volumio[19824]: error: updateQueue error: null Jan 12 17:34:30 volumio volumio[19824]: info: ------------------------------ 3ms Jan 12 17:34:30 volumio volumio[19824]: info: Executing endpoint getStreamUrlqobuz Jan 12 17:34:30 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jan 12 17:34:31 volumio volumio[19824]: info: getStreamUrl took 474 milliseconds Jan 12 17:34:31 volumio volumio[19824]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1672396&eid=306251876&fmt=6&profile=raw&app_id=539451548&cid=2018744&etsp=1736706871&hmac=gbAHFzohJOiWyKT67GpnYnqhqPY Jan 12 17:34:31 volumio volumio[19824]: STREAMING PROXY: Response: 200, length: 17777086 Jan 12 17:34:31 volumio volumio[19824]: STREAMING PROXY: Client dropped request, destroying Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/306251876" Jan 12 17:34:31 volumio volumio[19824]: error: updateQueue error: null Jan 12 17:34:31 volumio volumio[19824]: error: updateQueue error: null Jan 12 17:34:31 volumio volumio[19824]: info: Jan 12 17:34:31 volumio volumio[19824]: ---------------------------- MPD announces system playlist update Jan 12 17:34:31 volumio volumio[19824]: info: Ignoring MPD Status Update Jan 12 17:34:31 volumio volumio[19824]: info: ------------------------------ 521ms Jan 12 17:34:31 volumio volumio[19824]: info: ------------------------------ 520ms Jan 12 17:34:31 volumio volumio[19824]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/306251876" took 1 milliseconds Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand play Jan 12 17:34:31 volumio volumio[19824]: info: ------------------------------ 1ms Jan 12 17:34:31 volumio volumio[19824]: info: Jan 12 17:34:31 volumio volumio[19824]: ---------------------------- MPD announces system playlist update Jan 12 17:34:31 volumio volumio[19824]: info: Ignoring MPD Status Update Jan 12 17:34:31 volumio volumio[19824]: info: Jan 12 17:34:31 volumio volumio[19824]: ---------------------------- MPD announces system playlist update Jan 12 17:34:31 volumio volumio[19824]: STREAMING PROXY: Handling url /?data=qobuz://song/306251876 Jan 12 17:34:31 volumio volumio[19824]: info: Ignoring MPD Status Update Jan 12 17:34:31 volumio volumio[19824]: info: Jan 12 17:34:31 volumio volumio[19824]: ---------------------------- MPD announces system playlist update Jan 12 17:34:31 volumio volumio[19824]: info: Ignoring MPD Status Update Jan 12 17:34:31 volumio volumio[19824]: info: sendMpdCommand play took 3 milliseconds Jan 12 17:34:31 volumio volumio[19824]: info: ------------------------------ 2ms Jan 12 17:34:31 volumio volumio[19824]: info: ------------------------------ 1ms Jan 12 17:34:31 volumio volumio[19824]: info: Executing endpoint getStreamUrlqobuz Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jan 12 17:34:31 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:31 volumio volumio[19824]: info: getStreamUrl took 467 milliseconds Jan 12 17:34:31 volumio volumio[19824]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1672396&eid=306251876&fmt=6&profile=raw&app_id=539451548&cid=2018744&etsp=1736706871&hmac=gbAHFzohJOiWyKT67GpnYnqhqPY Jan 12 17:34:31 volumio volumio[19824]: STREAMING PROXY: Response: 200, length: 17777086 Jan 12 17:34:31 volumio volumio[19824]: info: Jan 12 17:34:31 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:31 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:31 volumio volumio[19824]: info: Jan 12 17:34:31 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:31 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:31 volumio volumio[19824]: info: Jan 12 17:34:31 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:31 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:31 volumio volumio[19824]: info: Jan 12 17:34:31 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:31 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:31 volumio volumio[19824]: info: Jan 12 17:34:31 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:31 volumio volumio[19824]: info: sendMpdCommand status took 2 milliseconds Jan 12 17:34:31 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:31 volumio volumio[19824]: info: sendMpdCommand status took 2 milliseconds Jan 12 17:34:31 volumio volumio[19824]: info: sendMpdCommand status took 2 milliseconds Jan 12 17:34:31 volumio volumio[19824]: info: sendMpdCommand status took 1 milliseconds Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:31 volumio volumio[19824]: info: Jan 12 17:34:31 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:31 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:31 volumio volumio[19824]: info: Jan 12 17:34:31 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:31 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:31 volumio volumio[19824]: info: Jan 12 17:34:31 volumio volumio[19824]: ---------------------------- MPD announces state update: player Jan 12 17:34:31 volumio volumio[19824]: info: ControllerMpd::getState Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand status Jan 12 17:34:31 volumio volumio[19824]: info: sendMpdCommand status took 14 milliseconds Jan 12 17:34:31 volumio volumio[19824]: info: sendMpdCommand playlistinfo took 14 milliseconds Jan 12 17:34:31 volumio volumio[19824]: info: sendMpdCommand playlistinfo took 13 milliseconds Jan 12 17:34:31 volumio volumio[19824]: info: sendMpdCommand playlistinfo took 13 milliseconds Jan 12 17:34:31 volumio volumio[19824]: info: sendMpdCommand status took 13 milliseconds Jan 12 17:34:31 volumio volumio[19824]: info: sendMpdCommand status took 12 milliseconds Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::parseTrackInfo Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::parseState Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 17:34:31 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:31 volumio volumio[19824]: info: CorePlayQueue::getTrack 0 Jan 12 17:34:31 volumio volumio[19824]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":192,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"306251876","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/306251876","trackType":"qobuz"} Jan 12 17:34:31 volumio volumio[19824]: verbose: CURRENT POSITION 0 Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::syncState stateService play Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus stop Jan 12 17:34:31 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:31 volumio volumio[19824]: info: CorePlayQueue::getTrack 0 Jan 12 17:34:31 volumio volumio[19824]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":192,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"306251876","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/306251876","trackType":"qobuz"} Jan 12 17:34:31 volumio volumio[19824]: verbose: CURRENT POSITION 0 Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::syncState stateService play Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus play Jan 12 17:34:31 volumio volumio[19824]: info: Received an update from plugin. extracting info from payload Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:31 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:31 volumio volumio[19824]: info: CorePlayQueue::getTrack 0 Jan 12 17:34:31 volumio volumio[19824]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":192,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"306251876","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/306251876","trackType":"qobuz"} Jan 12 17:34:31 volumio volumio[19824]: verbose: CURRENT POSITION 0 Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::syncState stateService play Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus play Jan 12 17:34:31 volumio volumio[19824]: info: Received an update from plugin. extracting info from payload Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:31 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:31 volumio volumio[19824]: info: CorePlayQueue::getTrack 0 Jan 12 17:34:31 volumio volumio[19824]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":192,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"306251876","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/306251876","trackType":"qobuz"} Jan 12 17:34:31 volumio volumio[19824]: verbose: CURRENT POSITION 0 Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::syncState stateService play Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus play Jan 12 17:34:31 volumio volumio[19824]: info: Received an update from plugin. extracting info from payload Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:31 volumio volumio[19824]: info: ------------------------------ 41ms Jan 12 17:34:31 volumio volumio[19824]: info: ------------------------------ 58ms Jan 12 17:34:31 volumio volumio[19824]: info: ------------------------------ 58ms Jan 12 17:34:31 volumio volumio[19824]: info: ------------------------------ 58ms Jan 12 17:34:31 volumio volumio[19824]: info: sendMpdCommand playlistinfo took 41 milliseconds Jan 12 17:34:31 volumio volumio[19824]: info: sendMpdCommand playlistinfo took 42 milliseconds Jan 12 17:34:31 volumio volumio[19824]: info: sendMpdCommand playlistinfo took 41 milliseconds Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::parseTrackInfo Jan 12 17:34:31 volumio volumio[19824]: verbose: ControllerMpd::parseTrackInfo Jan 12 17:34:31 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:31 volumio volumio[19824]: info: CorePlayQueue::getTrack 0 Jan 12 17:34:31 volumio volumio[19824]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":192,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"306251876","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/306251876","trackType":"qobuz"} Jan 12 17:34:31 volumio volumio[19824]: verbose: CURRENT POSITION 0 Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::syncState stateService play Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus play Jan 12 17:34:31 volumio volumio[19824]: info: Received an update from plugin. extracting info from payload Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:31 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:31 volumio volumio[19824]: info: CorePlayQueue::getTrack 0 Jan 12 17:34:31 volumio volumio[19824]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":192,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"306251876","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/306251876","trackType":"qobuz"} Jan 12 17:34:31 volumio volumio[19824]: verbose: CURRENT POSITION 0 Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::syncState stateService play Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus play Jan 12 17:34:31 volumio volumio[19824]: info: Received an update from plugin. extracting info from payload Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:31 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:31 volumio volumio[19824]: info: CorePlayQueue::getTrack 0 Jan 12 17:34:31 volumio volumio[19824]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":192,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"306251876","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/306251876","trackType":"qobuz"} Jan 12 17:34:31 volumio volumio[19824]: verbose: CURRENT POSITION 0 Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::syncState stateService play Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus play Jan 12 17:34:31 volumio volumio[19824]: info: Received an update from plugin. extracting info from payload Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:31 volumio volumio[19824]: info: ControllerMpd::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::servicePushState Jan 12 17:34:31 volumio volumio[19824]: info: CorePlayQueue::getTrack 0 Jan 12 17:34:31 volumio volumio[19824]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":192,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"306251876","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/306251876","trackType":"qobuz"} Jan 12 17:34:31 volumio volumio[19824]: verbose: CURRENT POSITION 0 Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::syncState stateService play Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::syncState currentStatus play Jan 12 17:34:31 volumio volumio[19824]: info: Received an update from plugin. extracting info from payload Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:31 volumio volumio[19824]: info: CoreStateMachine::pushState Jan 12 17:34:31 volumio volumio[19824]: info: CoreCommandRouter::volumioPushState Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output update for this device Jan 12 17:34:31 volumio volumio[19824]: info: MRS: Pushing multiroomSync output Jan 12 17:34:31 volumio volumio[19824]: info: ------------------------------ 86ms Jan 12 17:34:31 volumio volumio[19824]: info: ------------------------------ 84ms Jan 12 17:34:31 volumio volumio[19824]: info: ------------------------------ 84ms Jan 12 17:34:31 volumio volumio[19824]: info: ------------------------------ 84ms Jan 12 17:34:32 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:32 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:32 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:32 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:33 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:33 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:33 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:33 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:33 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:33 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:33 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:33 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:33 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:33 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:33 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:33 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:33 volumio volumio[19824]: info: Executing endpoint metavolumio Jan 12 17:34:33 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 17:34:33 volumio volumio[19824]: error: Failed request for metavolumio API Jan 12 17:34:33 volumio volumio[19824]: STREAMING PROXY: Client dropped request, destroying Jan 12 17:34:34 volumio volumio[19824]: error: Failed request for metavolumio API Jan 12 17:34:35 volumio volumio[19824]: error: Failed request for metavolumio API Jan 12 17:34:37 volumio volumio[19824]: error: Failed request for metavolumio API Jan 12 17:34:39 volumio volumio[19824]: error: Failed request for metavolumio API Jan 12 17:34:50 volumio volumio[19824]: info: Adding qobuz://song/306251876 to favourites with specific qobuz method Jan 12 17:35:33 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: qobuz , explodeUri Jan 12 17:35:33 volumio volumio[19824]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 12 17:35:34 volumio volumio[19824]: info: explodeUri took 373 milliseconds Jan 12 17:35:34 volumio volumio[19824]: info: Saving Cloud item Antiphone . Blues Jan 12 17:35:34 volumio volumio[19824]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem Jan 12 17:35:34 volumio volumio[19824]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 17:35:34 volumio volumio[19824]: Error: Reference.child failed: First argument was an invalid path = "/user_data/ocJtCRBtasTYexfOM9zAs1w4iHr1/myPlaylists/Antiphone . Blues". Paths must be non-empty strings and can't contain ".", "#", "$", "[", or "]" Jan 12 17:35:34 volumio volumio[19824]: at validatePathString (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:1667:15) Jan 12 17:35:34 volumio volumio[19824]: at validateRootPathString (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:1679:5) Jan 12 17:35:34 volumio volumio[19824]: at Reference.child (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:13737:17) Jan 12 17:35:34 volumio volumio[19824]: at Database.ref (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:15115:48) Jan 12 17:35:34 volumio volumio[19824]: at myVolumio.syncJSONToCloud (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:28817) Jan 12 17:35:34 volumio volumio[19824]: at myVolumio.saveCloudMyPlaylist (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:23840) Jan 12 17:35:34 volumio volumio[19824]: at myVolumio.saveCloudItem (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:18337) Jan 12 17:35:34 volumio volumio[19824]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1097:32) Jan 12 17:35:34 volumio volumio[19824]: at PlaylistManager.saveJSONFile (/volumio/app/playlistManager.js:613:31) Jan 12 17:35:34 volumio volumio[19824]: at /volumio/app/playlistManager.js:588:20 Jan 12 17:35:34 volumio volumio[19824]: at /volumio/node_modules/jsonfile/index.js:46:5 Jan 12 17:35:34 volumio volumio[19824]: at /volumio/node_modules/graceful-fs/graceful-fs.js:123:16 Jan 12 17:35:34 volumio volumio[19824]: at FSReqCallback.readFileAfterClose [as oncomplete] (internal/fs/read_file_context.js:71:3) Jan 12 17:35:34 volumio volumio[19824]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 17:35:34 volumio sudo[23246]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-12 17:34 Jan 12 17:35:34 volumio sudo[23246]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:11:38 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="932fc3546f7cc8faa2b4d349036752dd"