-- Logs begin at Thu 2019-02-14 10:11:58 UTC, end at Fri 2025-01-10 22:26:45 UTC. -- Jan 10 22:25:08 volumio volumio[1258]: info: Preload queue cleared Jan 10 22:25:08 volumio volumio[1258]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 10 22:25:08 volumio volumio[1258]: info: CoreStateMachine::ClearQueue Jan 10 22:25:08 volumio volumio[1258]: info: CoreStateMachine::stop Jan 10 22:25:08 volumio volumio[1258]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 10 22:25:08 volumio volumio[1258]: info: CoreStateMachine::stPlaybackTimer Jan 10 22:25:08 volumio volumio[1258]: info: CoreStateMachine::updateTrackBlock Jan 10 22:25:08 volumio volumio[1258]: info: CorePlayQueue::getTrackBlock Jan 10 22:25:08 volumio volumio[1258]: info: CoreStateMachine::pushState Jan 10 22:25:08 volumio volumio[1258]: info: CorePlayQueue::getTrack 14 Jan 10 22:25:08 volumio volumio[1258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 22:25:08 volumio volumio[1258]: info: CoreCommandRouter::volumioPushState Jan 10 22:25:08 volumio volumio[1258]: info: MRS: Pushing multiroomSync output update for this device Jan 10 22:25:08 volumio volumio[1258]: info: MRS: Pushing multiroomSync output Jan 10 22:25:08 volumio volumio[1258]: info: CoreStateMachine::serviceStop Jan 10 22:25:08 volumio volumio[1258]: info: CorePlayQueue::getTrack 14 Jan 10 22:25:08 volumio volumio[1258]: info: CoreCommandRouter::serviceStop Jan 10 22:25:08 volumio volumio[1258]: info: [1736547908508] ControllerQobuz::stop Jan 10 22:25:08 volumio volumio[1258]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 10 22:25:08 volumio volumio[1258]: info: ControllerMpd::stop Jan 10 22:25:08 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand stop Jan 10 22:25:08 volumio volumio[1258]: info: CorePlayQueue::clearPlayQueue Jan 10 22:25:08 volumio volumio[1258]: info: CorePlayQueue::saveQueue Jan 10 22:25:08 volumio volumio[1258]: info: CoreCommandRouter::volumioPushQueue Jan 10 22:25:08 volumio volumio[1258]: info: CoreStateMachine::addQueueItems Jan 10 22:25:08 volumio volumio[1258]: info: CorePlayQueue::addQueueItems Jan 10 22:25:08 volumio volumio[1258]: info: Preload queue cleared Jan 10 22:25:08 volumio volumio[1258]: info: Adding Item to queue: qobuz://song/88653499 Jan 10 22:25:08 volumio volumio[1258]: info: Exploding uri qobuz://song/88653499 in service qobuz Jan 10 22:25:08 volumio volumio[1258]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 10 22:25:08 volumio volumio[1258]: info: Adding Item to queue: qobuz://song/218110042 Jan 10 22:25:08 volumio volumio[1258]: info: Exploding uri qobuz://song/218110042 in service qobuz Jan 10 22:25:08 volumio volumio[1258]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 10 22:25:08 volumio volumio[1258]: info: Jan 10 22:25:08 volumio volumio[1258]: ---------------------------- MPD announces state update: player Jan 10 22:25:08 volumio volumio[1258]: info: sendMpdCommand stop took 17 milliseconds Jan 10 22:25:08 volumio volumio[1258]: info: ControllerMpd::getState Jan 10 22:25:08 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand status Jan 10 22:25:08 volumio volumio[1258]: info: sendMpdCommand status took 4 milliseconds Jan 10 22:25:08 volumio volumio[1258]: verbose: ControllerMpd::parseState Jan 10 22:25:08 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 10 22:25:08 volumio volumio[1258]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 10 22:25:08 volumio volumio[1258]: verbose: ControllerMpd::parseTrackInfo Jan 10 22:25:08 volumio volumio[1258]: info: ControllerMpd::pushState Jan 10 22:25:08 volumio volumio[1258]: info: CoreCommandRouter::servicePushState Jan 10 22:25:08 volumio volumio[1258]: info: CoreStateMachine::pushState Jan 10 22:25:08 volumio volumio[1258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 22:25:08 volumio volumio[1258]: info: CoreCommandRouter::volumioPushState Jan 10 22:25:08 volumio volumio[1258]: info: MRS: Pushing multiroomSync output update for this device Jan 10 22:25:08 volumio volumio[1258]: info: MRS: Pushing multiroomSync output Jan 10 22:25:08 volumio volumio[1258]: info: CorePlayQueue::getTrack 14 Jan 10 22:25:08 volumio volumio[1258]: 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":"308099837","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/308099837","trackType":"qobuz"} Jan 10 22:25:08 volumio volumio[1258]: verbose: CURRENT POSITION 14 Jan 10 22:25:08 volumio volumio[1258]: info: CoreStateMachine::syncState stateService stop Jan 10 22:25:08 volumio volumio[1258]: info: CoreStateMachine::syncState currentStatus stop Jan 10 22:25:08 volumio volumio[1258]: info: CoreStateMachine::pushState Jan 10 22:25:08 volumio volumio[1258]: info: CoreCommandRouter::volumioPushState Jan 10 22:25:08 volumio volumio[1258]: info: MRS: Pushing multiroomSync output update for this device Jan 10 22:25:08 volumio volumio[1258]: info: MRS: Pushing multiroomSync output Jan 10 22:25:08 volumio volumio[1258]: info: No code Jan 10 22:25:08 volumio volumio[1258]: info: CoreStateMachine::pushState Jan 10 22:25:08 volumio volumio[1258]: info: CoreCommandRouter::volumioPushState Jan 10 22:25:08 volumio volumio[1258]: info: MRS: Pushing multiroomSync output update for this device Jan 10 22:25:08 volumio volumio[1258]: info: MRS: Pushing multiroomSync output Jan 10 22:25:08 volumio volumio[1258]: info: ------------------------------ 16ms Jan 10 22:25:09 volumio volumio[1258]: info: explodeUri took 605 milliseconds Jan 10 22:25:09 volumio volumio[1258]: info: explodeUri took 779 milliseconds Jan 10 22:25:09 volumio volumio[1258]: info: CoreCommandRouter::volumioPushQueue Jan 10 22:25:09 volumio volumio[1258]: info: CorePlayQueue::saveQueue Jan 10 22:25:09 volumio volumio[1258]: info: CoreStateMachine::updateTrackBlock Jan 10 22:25:09 volumio volumio[1258]: info: CorePlayQueue::getTrackBlock Jan 10 22:25:09 volumio volumio[1258]: info: CoreCommandRouter::volumioPlay Jan 10 22:25:09 volumio volumio[1258]: info: CoreStateMachine::play index 1 Jan 10 22:25:09 volumio volumio[1258]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 10 22:25:09 volumio volumio[1258]: info: CoreStateMachine::stop Jan 10 22:25:09 volumio volumio[1258]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 10 22:25:09 volumio volumio[1258]: info: CoreStateMachine::play index undefined Jan 10 22:25:09 volumio volumio[1258]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 10 22:25:09 volumio volumio[1258]: info: CorePlayQueue::getTrack 1 Jan 10 22:25:09 volumio volumio[1258]: info: CoreStateMachine::startPlaybackTimer Jan 10 22:25:09 volumio volumio[1258]: info: CorePlayQueue::getTrack 1 Jan 10 22:25:09 volumio volumio[1258]: info: CoreCommandRouter::volumioGetVisibleSources Jan 10 22:25:09 volumio volumio[1258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 10 22:25:09 volumio volumio[1258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jan 10 22:25:09 volumio volumio[1258]: info: [1736547909298] ControllerQobuz::clearAddPlayTrack Jan 10 22:25:09 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand stop Jan 10 22:25:09 volumio volumio[1258]: info: sendMpdCommand stop took 1 milliseconds Jan 10 22:25:09 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand clear Jan 10 22:25:09 volumio volumio[1258]: info: Jan 10 22:25:09 volumio volumio[1258]: ---------------------------- MPD announces system playlist update Jan 10 22:25:09 volumio volumio[1258]: info: Ignoring MPD Status Update Jan 10 22:25:09 volumio volumio[1258]: info: sendMpdCommand clear took 1 milliseconds Jan 10 22:25:09 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/218110042" Jan 10 22:25:09 volumio volumio[1258]: STREAMING PROXY: Handling url /?data=qobuz://song/218110042 Jan 10 22:25:09 volumio volumio[1258]: error: updateQueue error: null Jan 10 22:25:09 volumio volumio[1258]: info: ------------------------------ 3ms Jan 10 22:25:09 volumio volumio[1258]: info: Executing endpoint getStreamUrlqobuz Jan 10 22:25:09 volumio volumio[1258]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jan 10 22:25:09 volumio volumio[1258]: info: getStreamUrl took 615 milliseconds Jan 10 22:25:09 volumio volumio[1258]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1672396&eid=218110042&fmt=6&profile=raw&app_id=539451548&cid=2018744&etsp=1736551509&hmac=kcRqnbGC0w9E0ropof7txrR4WL4 Jan 10 22:25:10 volumio volumio[1258]: STREAMING PROXY: Response: 200, length: 29998757 Jan 10 22:25:10 volumio volumio[1258]: STREAMING PROXY: Client dropped request, destroying Jan 10 22:25:10 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/218110042" Jan 10 22:25:10 volumio volumio[1258]: info: Jan 10 22:25:10 volumio volumio[1258]: ---------------------------- MPD announces system playlist update Jan 10 22:25:10 volumio volumio[1258]: info: Ignoring MPD Status Update Jan 10 22:25:10 volumio volumio[1258]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/218110042" took 1 milliseconds Jan 10 22:25:10 volumio volumio[1258]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 10 22:25:10 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand play Jan 10 22:25:10 volumio volumio[1258]: info: ------------------------------ 2ms Jan 10 22:25:10 volumio volumio[1258]: STREAMING PROXY: Handling url /?data=qobuz://song/218110042 Jan 10 22:25:10 volumio volumio[1258]: info: sendMpdCommand play took 2 milliseconds Jan 10 22:25:10 volumio volumio[1258]: info: Executing endpoint getStreamUrlqobuz Jan 10 22:25:10 volumio volumio[1258]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jan 10 22:25:11 volumio volumio[1258]: info: getStreamUrl took 549 milliseconds Jan 10 22:25:11 volumio volumio[1258]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1672396&eid=218110042&fmt=6&profile=raw&app_id=539451548&cid=2018744&etsp=1736551511&hmac=xOiuSWUrm5ovJSq1jDP1IX5A5TM Jan 10 22:25:11 volumio volumio[1258]: STREAMING PROXY: Response: 200, length: 29998757 Jan 10 22:25:11 volumio volumio[1258]: info: Jan 10 22:25:11 volumio volumio[1258]: ---------------------------- MPD announces state update: player Jan 10 22:25:11 volumio volumio[1258]: info: ControllerMpd::getState Jan 10 22:25:11 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand status Jan 10 22:25:11 volumio volumio[1258]: info: Jan 10 22:25:11 volumio volumio[1258]: ---------------------------- MPD announces state update: player Jan 10 22:25:11 volumio volumio[1258]: info: sendMpdCommand status took 2 milliseconds Jan 10 22:25:11 volumio volumio[1258]: info: ControllerMpd::getState Jan 10 22:25:11 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand status Jan 10 22:25:11 volumio volumio[1258]: verbose: ControllerMpd::parseState Jan 10 22:25:11 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 10 22:25:11 volumio volumio[1258]: info: sendMpdCommand status took 1 milliseconds Jan 10 22:25:11 volumio volumio[1258]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 10 22:25:11 volumio volumio[1258]: verbose: ControllerMpd::parseState Jan 10 22:25:11 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 10 22:25:11 volumio volumio[1258]: verbose: ControllerMpd::parseTrackInfo Jan 10 22:25:11 volumio volumio[1258]: info: ControllerMpd::pushState Jan 10 22:25:11 volumio volumio[1258]: info: CoreCommandRouter::servicePushState Jan 10 22:25:11 volumio volumio[1258]: info: CorePlayQueue::getTrack 1 Jan 10 22:25:11 volumio volumio[1258]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":361,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"218110042","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/218110042","trackType":"qobuz"} Jan 10 22:25:11 volumio volumio[1258]: verbose: CURRENT POSITION 1 Jan 10 22:25:11 volumio volumio[1258]: info: CoreStateMachine::syncState stateService play Jan 10 22:25:11 volumio volumio[1258]: info: CoreStateMachine::syncState currentStatus stop Jan 10 22:25:11 volumio volumio[1258]: info: ------------------------------ 7ms Jan 10 22:25:11 volumio volumio[1258]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 10 22:25:11 volumio volumio[1258]: verbose: ControllerMpd::parseTrackInfo Jan 10 22:25:11 volumio volumio[1258]: info: ControllerMpd::pushState Jan 10 22:25:11 volumio volumio[1258]: info: CoreCommandRouter::servicePushState Jan 10 22:25:11 volumio volumio[1258]: info: CorePlayQueue::getTrack 1 Jan 10 22:25:11 volumio volumio[1258]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":361,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"218110042","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/218110042","trackType":"qobuz"} Jan 10 22:25:11 volumio volumio[1258]: verbose: CURRENT POSITION 1 Jan 10 22:25:11 volumio volumio[1258]: info: CoreStateMachine::syncState stateService play Jan 10 22:25:11 volumio volumio[1258]: info: CoreStateMachine::syncState currentStatus play Jan 10 22:25:11 volumio volumio[1258]: info: Received an update from plugin. extracting info from payload Jan 10 22:25:11 volumio volumio[1258]: info: CoreStateMachine::pushState Jan 10 22:25:11 volumio volumio[1258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 22:25:11 volumio volumio[1258]: info: CoreCommandRouter::volumioPushState Jan 10 22:25:11 volumio volumio[1258]: info: MRS: Pushing multiroomSync output update for this device Jan 10 22:25:11 volumio volumio[1258]: info: MRS: Pushing multiroomSync output Jan 10 22:25:11 volumio volumio[1258]: info: CoreStateMachine::pushState Jan 10 22:25:11 volumio volumio[1258]: info: CoreCommandRouter::volumioPushState Jan 10 22:25:11 volumio volumio[1258]: info: MRS: Pushing multiroomSync output update for this device Jan 10 22:25:11 volumio volumio[1258]: info: MRS: Pushing multiroomSync output Jan 10 22:25:11 volumio volumio[1258]: info: ------------------------------ 40ms Jan 10 22:25:13 volumio volumio[1258]: STREAMING PROXY: Client dropped request, destroying Jan 10 22:25:30 volumio volumio[1258]: info: Preload queue cleared Jan 10 22:25:30 volumio volumio[1258]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::ClearQueue Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::stop Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::stPlaybackTimer Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::updateTrackBlock Jan 10 22:25:30 volumio volumio[1258]: info: CorePlayQueue::getTrackBlock Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::pushState Jan 10 22:25:30 volumio volumio[1258]: info: CorePlayQueue::getTrack 1 Jan 10 22:25:30 volumio volumio[1258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 22:25:30 volumio volumio[1258]: info: CoreCommandRouter::volumioPushState Jan 10 22:25:30 volumio volumio[1258]: info: MRS: Pushing multiroomSync output update for this device Jan 10 22:25:30 volumio volumio[1258]: info: MRS: Pushing multiroomSync output Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::serviceStop Jan 10 22:25:30 volumio volumio[1258]: info: CorePlayQueue::getTrack 1 Jan 10 22:25:30 volumio volumio[1258]: info: CoreCommandRouter::serviceStop Jan 10 22:25:30 volumio volumio[1258]: info: [1736547930964] ControllerQobuz::stop Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 10 22:25:30 volumio volumio[1258]: info: ControllerMpd::stop Jan 10 22:25:30 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand stop Jan 10 22:25:30 volumio volumio[1258]: info: CorePlayQueue::clearPlayQueue Jan 10 22:25:30 volumio volumio[1258]: info: CorePlayQueue::saveQueue Jan 10 22:25:30 volumio volumio[1258]: info: CoreCommandRouter::volumioPushQueue Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::addQueueItems Jan 10 22:25:30 volumio volumio[1258]: info: CorePlayQueue::addQueueItems Jan 10 22:25:30 volumio volumio[1258]: info: Preload queue cleared Jan 10 22:25:30 volumio volumio[1258]: info: Adding Item to queue: qobuz://song/88653499 Jan 10 22:25:30 volumio volumio[1258]: info: Using cached record of: qobuz://song/88653499 Jan 10 22:25:30 volumio volumio[1258]: info: Adding Item to queue: qobuz://song/218110042 Jan 10 22:25:30 volumio volumio[1258]: info: Using cached record of: qobuz://song/218110042 Jan 10 22:25:30 volumio volumio[1258]: info: CoreCommandRouter::volumioPushQueue Jan 10 22:25:30 volumio volumio[1258]: info: CorePlayQueue::saveQueue Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::updateTrackBlock Jan 10 22:25:30 volumio volumio[1258]: info: CorePlayQueue::getTrackBlock Jan 10 22:25:30 volumio volumio[1258]: info: CoreCommandRouter::volumioPlay Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::play index 1 Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::stop Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::play index undefined Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 10 22:25:30 volumio volumio[1258]: info: CorePlayQueue::getTrack 1 Jan 10 22:25:30 volumio volumio[1258]: info: CoreStateMachine::startPlaybackTimer Jan 10 22:25:30 volumio volumio[1258]: info: CorePlayQueue::getTrack 1 Jan 10 22:25:30 volumio volumio[1258]: info: CoreCommandRouter::volumioGetVisibleSources Jan 10 22:25:30 volumio volumio[1258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 10 22:25:30 volumio volumio[1258]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jan 10 22:25:30 volumio volumio[1258]: info: [1736547930972] ControllerQobuz::clearAddPlayTrack Jan 10 22:25:30 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand stop Jan 10 22:25:30 volumio volumio[1258]: info: Jan 10 22:25:30 volumio volumio[1258]: ---------------------------- MPD announces state update: player Jan 10 22:25:30 volumio volumio[1258]: info: sendMpdCommand stop took 15 milliseconds Jan 10 22:25:30 volumio volumio[1258]: info: ControllerMpd::getState Jan 10 22:25:30 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand status Jan 10 22:25:30 volumio volumio[1258]: info: sendMpdCommand stop took 6 milliseconds Jan 10 22:25:30 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand clear Jan 10 22:25:30 volumio volumio[1258]: info: Jan 10 22:25:30 volumio volumio[1258]: ---------------------------- MPD announces system playlist update Jan 10 22:25:30 volumio volumio[1258]: info: Ignoring MPD Status Update Jan 10 22:25:30 volumio volumio[1258]: info: sendMpdCommand status took 1 milliseconds Jan 10 22:25:30 volumio volumio[1258]: info: sendMpdCommand clear took 1 milliseconds Jan 10 22:25:30 volumio volumio[1258]: verbose: ControllerMpd::parseState Jan 10 22:25:30 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 10 22:25:30 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/218110042" Jan 10 22:25:30 volumio volumio[1258]: error: updateQueue error: null Jan 10 22:25:30 volumio volumio[1258]: info: ------------------------------ 2ms Jan 10 22:25:30 volumio volumio[1258]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 10 22:25:30 volumio volumio[1258]: STREAMING PROXY: Handling url /?data=qobuz://song/218110042 Jan 10 22:25:30 volumio volumio[1258]: verbose: ControllerMpd::parseTrackInfo Jan 10 22:25:30 volumio volumio[1258]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jan 10 22:25:30 volumio volumio[1258]: info: ------------------------------ 5ms Jan 10 22:25:30 volumio volumio[1258]: info: Executing endpoint getStreamUrlqobuz Jan 10 22:25:30 volumio volumio[1258]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jan 10 22:25:31 volumio volumio[1258]: info: getStreamUrl took 530 milliseconds Jan 10 22:25:31 volumio volumio[1258]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1672396&eid=218110042&fmt=6&profile=raw&app_id=539451548&cid=2018744&etsp=1736551531&hmac=uJc9zTBg627KIqZGINukD7dHxZA Jan 10 22:25:31 volumio volumio[1258]: STREAMING PROXY: Response: 200, length: 29998757 Jan 10 22:25:31 volumio volumio[1258]: STREAMING PROXY: Client dropped request, destroying Jan 10 22:25:31 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/218110042" Jan 10 22:25:31 volumio volumio[1258]: info: Jan 10 22:25:31 volumio volumio[1258]: ---------------------------- MPD announces system playlist update Jan 10 22:25:31 volumio volumio[1258]: info: Ignoring MPD Status Update Jan 10 22:25:31 volumio volumio[1258]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/218110042" took 1 milliseconds Jan 10 22:25:31 volumio volumio[1258]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 10 22:25:31 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand play Jan 10 22:25:31 volumio volumio[1258]: info: ------------------------------ 2ms Jan 10 22:25:31 volumio volumio[1258]: info: sendMpdCommand play took 2 milliseconds Jan 10 22:25:31 volumio volumio[1258]: STREAMING PROXY: Handling url /?data=qobuz://song/218110042 Jan 10 22:25:31 volumio volumio[1258]: info: Executing endpoint getStreamUrlqobuz Jan 10 22:25:31 volumio volumio[1258]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jan 10 22:25:32 volumio volumio[1258]: info: getStreamUrl took 573 milliseconds Jan 10 22:25:32 volumio volumio[1258]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1672396&eid=218110042&fmt=6&profile=raw&app_id=539451548&cid=2018744&etsp=1736551532&hmac=uVR9UpNjhX1ZKDr0fLoAk1Yg460 Jan 10 22:25:32 volumio volumio[1258]: STREAMING PROXY: Response: 200, length: 29998757 Jan 10 22:25:32 volumio volumio[1258]: info: Jan 10 22:25:32 volumio volumio[1258]: ---------------------------- MPD announces state update: player Jan 10 22:25:32 volumio volumio[1258]: info: ControllerMpd::getState Jan 10 22:25:32 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand status Jan 10 22:25:32 volumio volumio[1258]: info: Jan 10 22:25:32 volumio volumio[1258]: ---------------------------- MPD announces state update: player Jan 10 22:25:32 volumio volumio[1258]: info: sendMpdCommand status took 3 milliseconds Jan 10 22:25:32 volumio volumio[1258]: info: ControllerMpd::getState Jan 10 22:25:32 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand status Jan 10 22:25:32 volumio volumio[1258]: verbose: ControllerMpd::parseState Jan 10 22:25:32 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 10 22:25:32 volumio volumio[1258]: info: sendMpdCommand status took 1 milliseconds Jan 10 22:25:32 volumio volumio[1258]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 10 22:25:32 volumio volumio[1258]: verbose: ControllerMpd::parseState Jan 10 22:25:32 volumio volumio[1258]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 10 22:25:32 volumio volumio[1258]: verbose: ControllerMpd::parseTrackInfo Jan 10 22:25:32 volumio volumio[1258]: info: ControllerMpd::pushState Jan 10 22:25:32 volumio volumio[1258]: info: CoreCommandRouter::servicePushState Jan 10 22:25:32 volumio volumio[1258]: info: CorePlayQueue::getTrack 1 Jan 10 22:25:32 volumio volumio[1258]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":361,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"218110042","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/218110042","trackType":"qobuz"} Jan 10 22:25:32 volumio volumio[1258]: verbose: CURRENT POSITION 1 Jan 10 22:25:32 volumio volumio[1258]: info: CoreStateMachine::syncState stateService play Jan 10 22:25:32 volumio volumio[1258]: info: CoreStateMachine::syncState currentStatus stop Jan 10 22:25:32 volumio volumio[1258]: info: ------------------------------ 7ms Jan 10 22:25:32 volumio volumio[1258]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 10 22:25:32 volumio volumio[1258]: verbose: ControllerMpd::parseTrackInfo Jan 10 22:25:32 volumio volumio[1258]: info: ControllerMpd::pushState Jan 10 22:25:32 volumio volumio[1258]: info: CoreCommandRouter::servicePushState Jan 10 22:25:32 volumio volumio[1258]: info: CorePlayQueue::getTrack 1 Jan 10 22:25:32 volumio volumio[1258]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":361,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"218110042","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/218110042","trackType":"qobuz"} Jan 10 22:25:32 volumio volumio[1258]: verbose: CURRENT POSITION 1 Jan 10 22:25:32 volumio volumio[1258]: info: CoreStateMachine::syncState stateService play Jan 10 22:25:32 volumio volumio[1258]: info: CoreStateMachine::syncState currentStatus play Jan 10 22:25:32 volumio volumio[1258]: info: Received an update from plugin. extracting info from payload Jan 10 22:25:32 volumio volumio[1258]: info: CoreStateMachine::pushState Jan 10 22:25:32 volumio volumio[1258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 22:25:32 volumio volumio[1258]: info: CoreCommandRouter::volumioPushState Jan 10 22:25:32 volumio volumio[1258]: info: MRS: Pushing multiroomSync output update for this device Jan 10 22:25:32 volumio volumio[1258]: info: MRS: Pushing multiroomSync output Jan 10 22:25:32 volumio volumio[1258]: info: CoreStateMachine::pushState Jan 10 22:25:32 volumio volumio[1258]: info: CoreCommandRouter::volumioPushState Jan 10 22:25:32 volumio volumio[1258]: info: MRS: Pushing multiroomSync output update for this device Jan 10 22:25:32 volumio volumio[1258]: info: MRS: Pushing multiroomSync output Jan 10 22:25:32 volumio volumio[1258]: info: ------------------------------ 29ms Jan 10 22:25:34 volumio volumio[1258]: STREAMING PROXY: Client dropped request, destroying Jan 10 22:26:27 volumio wpa_supplicant[850]: wlan0: WPA: Group rekeying completed with cc:ce:1e:80:25:64 [GTK=CCMP] Jan 10 22:26:44 volumio volumio[1258]: info: CoreCommandRouter::executeOnPlugin: qobuz , explodeUri Jan 10 22:26:44 volumio volumio[1258]: https://prod.vlmapi.io/v2/qobuz/explodeUri Jan 10 22:26:45 volumio volumio[1258]: info: explodeUri took 612 milliseconds Jan 10 22:26:45 volumio volumio[1258]: info: Saving Cloud item Simple Song #3“ von David Lang, Geige Jan 10 22:26:45 volumio volumio[1258]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem Jan 10 22:26:45 volumio volumio[1258]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 10 22:26:45 volumio volumio[1258]: Error: Reference.child failed: First argument was an invalid path = "/user_data/ocJtCRBtasTYexfOM9zAs1w4iHr1/myPlaylists/Simple Song #3“ von David Lang, Geige". Paths must be non-empty strings and can't contain ".", "#", "$", "[", or "]" Jan 10 22:26:45 volumio volumio[1258]: at validatePathString (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:1667:15) Jan 10 22:26:45 volumio volumio[1258]: at validateRootPathString (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:1679:5) Jan 10 22:26:45 volumio volumio[1258]: at Reference.child (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:13737:17) Jan 10 22:26:45 volumio volumio[1258]: at Database.ref (/volumio/node_modules/@firebase/database/dist/index.node.cjs.js:15115:48) Jan 10 22:26:45 volumio volumio[1258]: at myVolumio.syncJSONToCloud (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:28817) Jan 10 22:26:45 volumio volumio[1258]: at myVolumio.saveCloudMyPlaylist (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:23840) Jan 10 22:26:45 volumio volumio[1258]: at myVolumio.saveCloudItem (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:18337) Jan 10 22:26:45 volumio volumio[1258]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1097:32) Jan 10 22:26:45 volumio volumio[1258]: at PlaylistManager.saveJSONFile (/volumio/app/playlistManager.js:613:31) Jan 10 22:26:45 volumio volumio[1258]: at /volumio/app/playlistManager.js:588:20 Jan 10 22:26:45 volumio volumio[1258]: at /volumio/node_modules/jsonfile/index.js:46:5 Jan 10 22:26:45 volumio volumio[1258]: at /volumio/node_modules/graceful-fs/graceful-fs.js:123:16 Jan 10 22:26:45 volumio volumio[1258]: at FSReqCallback.readFileAfterClose [as oncomplete] (internal/fs/read_file_context.js:71:3) Jan 10 22:26:45 volumio volumio[1258]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 10 22:26:45 volumio sudo[12571]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-10 22:25 Jan 10 22:26:45 volumio sudo[12571]: 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"