-- Logs begin at Fri 2024-08-23 14:59:11 CEST, end at Tue 2024-08-27 21:00:53 CEST. -- Aug 27 20:59:28 volumio volumio[743]: info: CoreCommandRouter::volumioSeek Aug 27 20:59:28 volumio volumio[743]: info: CoreStateMachine::seek Aug 27 20:59:28 volumio volumio[743]: info: CorePlayQueue::getTrack 38 Aug 27 20:59:28 volumio volumio[743]: info: TRACKBLOCK {"uri":"qobuz://song/202310","service":"qobuz","name":"The Voice Within","title":"The Voice Within","album":"Stripped","type":"track","tracknumber":18,"volumeNumber":1,"albumart":"https://static.qobuz.com/images/covers/22/37/0078636803722_600.jpg","duration":304,"explicit":false,"artist":"Christina Aguilera","artistUri":"qobuz://artist/40570","albumUri":"qobuz://album/0078636803722","audioQuality":"","tagImage":""} Aug 27 20:59:28 volumio volumio[743]: info: CoreStateMachine::startPlaybackTimer Aug 27 20:59:28 volumio volumio[743]: info: CorePlayQueue::getTrack 38 Aug 27 20:59:28 volumio volumio[743]: info: [1724785168629] ControllerQobuz::seek Aug 27 20:59:28 volumio volumio[743]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 27 20:59:28 volumio volumio[743]: info: ControllerMpd::seek Aug 27 20:59:28 volumio volumio[743]: info: CoreStateMachine::pushState Aug 27 20:59:28 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 20:59:28 volumio volumio[743]: info: CoreCommandRouter::volumioPushState Aug 27 20:59:28 volumio volumio[743]: info: MRS: Pushing multiroomSync output update for this device Aug 27 20:59:28 volumio volumio[743]: info: MRS: Pushing multiroomSync output Aug 27 20:59:28 volumio volumio[743]: error: null Aug 27 20:59:28 volumio volumio[743]: info: Aug 27 20:59:28 volumio volumio[743]: ---------------------------- MPD announces state update: player Aug 27 20:59:28 volumio volumio[743]: info: ControllerMpd::getState Aug 27 20:59:28 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand status Aug 27 20:59:28 volumio volumio[743]: info: sendMpdCommand status took 8 milliseconds Aug 27 20:59:28 volumio volumio[743]: verbose: ControllerMpd::parseState Aug 27 20:59:28 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 20:59:28 volumio volumio[743]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 27 20:59:28 volumio volumio[743]: verbose: ControllerMpd::parseTrackInfo Aug 27 20:59:28 volumio volumio[743]: info: ControllerMpd::pushState Aug 27 20:59:28 volumio volumio[743]: info: CoreCommandRouter::servicePushState Aug 27 20:59:28 volumio volumio[743]: info: CorePlayQueue::getTrack 38 Aug 27 20:59:28 volumio volumio[743]: verbose: STATE SERVICE {"status":"play","position":0,"seek":108000,"duration":304,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"890 Kbps","isStreaming":false,"title":"202310","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/202310","trackType":"qobuz"} Aug 27 20:59:28 volumio volumio[743]: verbose: CURRENT POSITION 38 Aug 27 20:59:28 volumio volumio[743]: info: CoreStateMachine::syncState stateService play Aug 27 20:59:28 volumio volumio[743]: info: CoreStateMachine::syncState currentStatus play Aug 27 20:59:28 volumio volumio[743]: info: Received an update from plugin. extracting info from payload Aug 27 20:59:28 volumio volumio[743]: info: CoreStateMachine::pushState Aug 27 20:59:28 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 20:59:28 volumio volumio[743]: info: CoreCommandRouter::volumioPushState Aug 27 20:59:28 volumio volumio[743]: info: MRS: Pushing multiroomSync output update for this device Aug 27 20:59:28 volumio volumio[743]: info: MRS: Pushing multiroomSync output Aug 27 20:59:28 volumio volumio[743]: info: CoreStateMachine::pushState Aug 27 20:59:28 volumio volumio[743]: info: CoreCommandRouter::volumioPushState Aug 27 20:59:28 volumio volumio[743]: info: MRS: Pushing multiroomSync output update for this device Aug 27 20:59:28 volumio volumio[743]: info: MRS: Pushing multiroomSync output Aug 27 20:59:28 volumio volumio[743]: info: ------------------------------ 32ms Aug 27 20:59:37 volumio volumio[743]: info: Preload queue cleared Aug 27 20:59:37 volumio volumio[743]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::ClearQueue Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::stop Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::stPlaybackTimer Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::updateTrackBlock Aug 27 20:59:37 volumio volumio[743]: info: CorePlayQueue::getTrackBlock Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::pushState Aug 27 20:59:37 volumio volumio[743]: info: CorePlayQueue::getTrack 38 Aug 27 20:59:37 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 20:59:37 volumio volumio[743]: info: CoreCommandRouter::volumioPushState Aug 27 20:59:37 volumio volumio[743]: info: MRS: Pushing multiroomSync output update for this device Aug 27 20:59:37 volumio volumio[743]: info: MRS: Pushing multiroomSync output Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::serviceStop Aug 27 20:59:37 volumio volumio[743]: info: CorePlayQueue::getTrack 38 Aug 27 20:59:37 volumio volumio[743]: info: CoreCommandRouter::serviceStop Aug 27 20:59:37 volumio volumio[743]: info: [1724785177962] ControllerQobuz::stop Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 27 20:59:37 volumio volumio[743]: info: ControllerMpd::stop Aug 27 20:59:37 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand stop Aug 27 20:59:37 volumio volumio[743]: info: CorePlayQueue::clearPlayQueue Aug 27 20:59:37 volumio volumio[743]: info: CorePlayQueue::saveQueue Aug 27 20:59:37 volumio volumio[743]: info: CoreCommandRouter::volumioPushQueue Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::addQueueItems Aug 27 20:59:37 volumio volumio[743]: info: CorePlayQueue::addQueueItems Aug 27 20:59:37 volumio volumio[743]: info: Preload queue cleared Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/38000389 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/38000389 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/2930338 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/2930338 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/16908815 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/16908815 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/47097783 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/47097783 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/86700522 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/86700522 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/179825554 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/179825554 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/88032824 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/88032824 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/67153568 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/67153568 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/54650585 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/54650585 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/47097781 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/47097781 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/219514537 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/219514537 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/97471543 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/97471543 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/246154659 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/246154659 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/60933247 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/60933247 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/185348715 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/185348715 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/94209835 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/94209835 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/78614361 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/78614361 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/97471542 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/97471542 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/50702998 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/50702998 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/17386503 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/17386503 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/66586288 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/66586288 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/100724074 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/100724074 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/3561689 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/3561689 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/64462723 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/64462723 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/17795367 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/17795367 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/138834417 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/138834417 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/12296684 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/12296684 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/324627 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/324627 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/82629488 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/82629488 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/182543868 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/182543868 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/11223507 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/11223507 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/141303824 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/141303824 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/3669061 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/3669061 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/52366503 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/52366503 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/8534168 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/8534168 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/54162324 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/54162324 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/4648854 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/4648854 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/144774701 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/144774701 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/202310 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/202310 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/7116 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/7116 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/46813281 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/46813281 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/41420862 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/41420862 Aug 27 20:59:37 volumio volumio[743]: info: Adding Item to queue: qobuz://song/24546499 Aug 27 20:59:37 volumio volumio[743]: info: Using cached record of: qobuz://song/24546499 Aug 27 20:59:37 volumio volumio[743]: info: CoreCommandRouter::volumioPushQueue Aug 27 20:59:37 volumio volumio[743]: info: CorePlayQueue::saveQueue Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::updateTrackBlock Aug 27 20:59:37 volumio volumio[743]: info: CorePlayQueue::getTrackBlock Aug 27 20:59:37 volumio volumio[743]: info: CoreCommandRouter::volumioPlay Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::play index 42 Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::stop Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::play index undefined Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 27 20:59:37 volumio volumio[743]: info: CorePlayQueue::getTrack 42 Aug 27 20:59:37 volumio volumio[743]: info: CoreStateMachine::startPlaybackTimer Aug 27 20:59:37 volumio volumio[743]: info: CorePlayQueue::getTrack 42 Aug 27 20:59:37 volumio volumio[743]: info: CoreCommandRouter::volumioGetVisibleSources Aug 27 20:59:37 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 20:59:37 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 27 20:59:37 volumio volumio[743]: info: [1724785177998] ControllerQobuz::clearAddPlayTrack Aug 27 20:59:37 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand stop Aug 27 20:59:38 volumio volumio[743]: info: Aug 27 20:59:38 volumio volumio[743]: ---------------------------- MPD announces state update: player Aug 27 20:59:38 volumio volumio[743]: info: sendMpdCommand stop took 48 milliseconds Aug 27 20:59:38 volumio volumio[743]: info: ControllerMpd::getState Aug 27 20:59:38 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand status Aug 27 20:59:38 volumio volumio[743]: info: sendMpdCommand stop took 13 milliseconds Aug 27 20:59:38 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand clear Aug 27 20:59:38 volumio volumio[743]: info: Aug 27 20:59:38 volumio volumio[743]: ---------------------------- MPD announces system playlist update Aug 27 20:59:38 volumio volumio[743]: info: Ignoring MPD Status Update Aug 27 20:59:38 volumio volumio[743]: info: sendMpdCommand status took 4 milliseconds Aug 27 20:59:38 volumio volumio[743]: info: sendMpdCommand clear took 3 milliseconds Aug 27 20:59:38 volumio volumio[743]: verbose: ControllerMpd::parseState Aug 27 20:59:38 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 20:59:38 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/24546499" Aug 27 20:59:38 volumio volumio[743]: error: updateQueue error: null Aug 27 20:59:38 volumio volumio[743]: info: ------------------------------ 2ms Aug 27 20:59:38 volumio volumio[743]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 27 20:59:38 volumio volumio[743]: verbose: ControllerMpd::parseTrackInfo Aug 27 20:59:38 volumio volumio[743]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 27 20:59:38 volumio volumio[743]: STREAMING PROXY: Handling url /?data=qobuz://song/24546499 Aug 27 20:59:38 volumio volumio[743]: info: ------------------------------ 8ms Aug 27 20:59:38 volumio volumio[743]: info: Executing endpoint getStreamUrlqobuz Aug 27 20:59:38 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Aug 27 20:59:38 volumio volumio[743]: info: getStreamUrl took 288 milliseconds Aug 27 20:59:38 volumio volumio[743]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2879701&eid=24546499&fmt=6&profile=raw&app_id=539451548&cid=2032965&etsp=1724788778&hmac=LzifPQCqrITXXnqm7uQt_-CRkM0 Aug 27 20:59:38 volumio volumio[743]: STREAMING PROXY: Response: 200, length: 21335549 Aug 27 20:59:38 volumio volumio[743]: STREAMING PROXY: Client dropped request, destroying Aug 27 20:59:38 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/24546499" Aug 27 20:59:38 volumio volumio[743]: info: Aug 27 20:59:38 volumio volumio[743]: ---------------------------- MPD announces system playlist update Aug 27 20:59:38 volumio volumio[743]: info: Ignoring MPD Status Update Aug 27 20:59:38 volumio volumio[743]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/24546499" took 2 milliseconds Aug 27 20:59:38 volumio volumio[743]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 27 20:59:38 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand play Aug 27 20:59:38 volumio volumio[743]: STREAMING PROXY: Handling url /?data=qobuz://song/24546499 Aug 27 20:59:38 volumio volumio[743]: info: ------------------------------ 7ms Aug 27 20:59:38 volumio volumio[743]: info: sendMpdCommand play took 7 milliseconds Aug 27 20:59:38 volumio volumio[743]: info: Executing endpoint getStreamUrlqobuz Aug 27 20:59:38 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Aug 27 20:59:38 volumio volumio[743]: info: getStreamUrl took 307 milliseconds Aug 27 20:59:38 volumio volumio[743]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2879701&eid=24546499&fmt=6&profile=raw&app_id=539451548&cid=2032965&etsp=1724788778&hmac=LzifPQCqrITXXnqm7uQt_-CRkM0 Aug 27 20:59:38 volumio volumio[743]: STREAMING PROXY: Response: 200, length: 21335549 Aug 27 20:59:38 volumio volumio[743]: info: Aug 27 20:59:38 volumio volumio[743]: ---------------------------- MPD announces state update: player Aug 27 20:59:38 volumio volumio[743]: info: ControllerMpd::getState Aug 27 20:59:38 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand status Aug 27 20:59:38 volumio volumio[743]: info: Aug 27 20:59:38 volumio volumio[743]: ---------------------------- MPD announces state update: player Aug 27 20:59:38 volumio volumio[743]: info: sendMpdCommand status took 24 milliseconds Aug 27 20:59:38 volumio volumio[743]: info: ControllerMpd::getState Aug 27 20:59:38 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand status Aug 27 20:59:38 volumio volumio[743]: verbose: ControllerMpd::parseState Aug 27 20:59:38 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 20:59:38 volumio volumio[743]: info: sendMpdCommand status took 3 milliseconds Aug 27 20:59:38 volumio volumio[743]: verbose: ControllerMpd::parseState Aug 27 20:59:38 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 20:59:38 volumio volumio[743]: info: sendMpdCommand playlistinfo took 5 milliseconds Aug 27 20:59:38 volumio volumio[743]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 27 20:59:38 volumio volumio[743]: verbose: ControllerMpd::parseTrackInfo Aug 27 20:59:38 volumio volumio[743]: info: ControllerMpd::pushState Aug 27 20:59:38 volumio volumio[743]: info: CoreCommandRouter::servicePushState Aug 27 20:59:38 volumio volumio[743]: info: CorePlayQueue::getTrack 42 Aug 27 20:59:38 volumio volumio[743]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":193,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"24546499","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/24546499","trackType":"qobuz"} Aug 27 20:59:38 volumio volumio[743]: verbose: CURRENT POSITION 42 Aug 27 20:59:38 volumio volumio[743]: info: CoreStateMachine::syncState stateService play Aug 27 20:59:38 volumio volumio[743]: info: CoreStateMachine::syncState currentStatus stop Aug 27 20:59:38 volumio volumio[743]: info: ControllerMpd::pushState Aug 27 20:59:38 volumio volumio[743]: info: CoreCommandRouter::servicePushState Aug 27 20:59:38 volumio volumio[743]: info: CorePlayQueue::getTrack 42 Aug 27 20:59:38 volumio volumio[743]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1212,"duration":193,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"742 Kbps","isStreaming":false,"title":"24546499","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/24546499","trackType":"qobuz"} Aug 27 20:59:38 volumio volumio[743]: verbose: CURRENT POSITION 42 Aug 27 20:59:38 volumio volumio[743]: info: CoreStateMachine::syncState stateService play Aug 27 20:59:38 volumio volumio[743]: info: CoreStateMachine::syncState currentStatus play Aug 27 20:59:38 volumio volumio[743]: info: Received an update from plugin. extracting info from payload Aug 27 20:59:38 volumio volumio[743]: info: CoreStateMachine::pushState Aug 27 20:59:38 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 20:59:38 volumio volumio[743]: info: CoreCommandRouter::volumioPushState Aug 27 20:59:38 volumio volumio[743]: info: MRS: Pushing multiroomSync output update for this device Aug 27 20:59:38 volumio volumio[743]: info: MRS: Pushing multiroomSync output Aug 27 20:59:38 volumio volumio[743]: info: CoreStateMachine::pushState Aug 27 20:59:38 volumio volumio[743]: info: CoreCommandRouter::volumioPushState Aug 27 20:59:38 volumio volumio[743]: info: MRS: Pushing multiroomSync output update for this device Aug 27 20:59:38 volumio volumio[743]: info: MRS: Pushing multiroomSync output Aug 27 20:59:38 volumio volumio[743]: info: ------------------------------ 52ms Aug 27 20:59:38 volumio volumio[743]: info: ------------------------------ 38ms Aug 27 20:59:39 volumio volumio[743]: STREAMING PROXY: Client dropped request, destroying Aug 27 20:59:41 volumio volumio[743]: info: CoreCommandRouter::volumioSeek Aug 27 20:59:41 volumio volumio[743]: info: CoreStateMachine::seek Aug 27 20:59:41 volumio volumio[743]: info: CorePlayQueue::getTrack 42 Aug 27 20:59:41 volumio volumio[743]: info: TRACKBLOCK {"uri":"qobuz://song/24546499","service":"qobuz","name":"Boys Don't Cry","title":"Boys Don't Cry","album":"Joyride","type":"track","tracknumber":2,"volumeNumber":1,"albumart":"https://static.qobuz.com/images/covers/53/22/0889845002253_600.jpg","duration":193,"explicit":false,"artist":"Jamie Lancaster","artistUri":"qobuz://artist/1089395","albumUri":"qobuz://album/0889845002253","audioQuality":"","tagImage":""} Aug 27 20:59:41 volumio volumio[743]: info: CoreStateMachine::startPlaybackTimer Aug 27 20:59:41 volumio volumio[743]: info: CorePlayQueue::getTrack 42 Aug 27 20:59:41 volumio volumio[743]: info: CoreCommandRouter::volumioGetVisibleSources Aug 27 20:59:41 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 20:59:41 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Aug 27 20:59:41 volumio volumio[743]: info: [1724785181025] ControllerQobuz::seek Aug 27 20:59:41 volumio volumio[743]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 27 20:59:41 volumio volumio[743]: info: ControllerMpd::seek Aug 27 20:59:41 volumio volumio[743]: info: CoreStateMachine::pushState Aug 27 20:59:41 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 20:59:41 volumio volumio[743]: info: CoreCommandRouter::volumioPushState Aug 27 20:59:41 volumio volumio[743]: info: MRS: Pushing multiroomSync output update for this device Aug 27 20:59:41 volumio volumio[743]: info: MRS: Pushing multiroomSync output Aug 27 20:59:41 volumio volumio[743]: error: null Aug 27 20:59:41 volumio volumio[743]: info: Aug 27 20:59:41 volumio volumio[743]: ---------------------------- MPD announces state update: player Aug 27 20:59:41 volumio volumio[743]: info: ControllerMpd::getState Aug 27 20:59:41 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand status Aug 27 20:59:41 volumio volumio[743]: info: sendMpdCommand status took 1 milliseconds Aug 27 20:59:41 volumio volumio[743]: verbose: ControllerMpd::parseState Aug 27 20:59:41 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 20:59:41 volumio volumio[743]: info: sendMpdCommand playlistinfo took 1 milliseconds Aug 27 20:59:41 volumio volumio[743]: verbose: ControllerMpd::parseTrackInfo Aug 27 20:59:41 volumio volumio[743]: info: ControllerMpd::pushState Aug 27 20:59:41 volumio volumio[743]: info: CoreCommandRouter::servicePushState Aug 27 20:59:41 volumio volumio[743]: info: CorePlayQueue::getTrack 42 Aug 27 20:59:41 volumio volumio[743]: verbose: STATE SERVICE {"status":"play","position":0,"seek":36212,"duration":193,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"844 Kbps","isStreaming":false,"title":"24546499","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/24546499","trackType":"qobuz"} Aug 27 20:59:41 volumio volumio[743]: verbose: CURRENT POSITION 42 Aug 27 20:59:41 volumio volumio[743]: info: CoreStateMachine::syncState stateService play Aug 27 20:59:41 volumio volumio[743]: info: CoreStateMachine::syncState currentStatus play Aug 27 20:59:41 volumio volumio[743]: info: Received an update from plugin. extracting info from payload Aug 27 20:59:41 volumio volumio[743]: info: CoreStateMachine::pushState Aug 27 20:59:41 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 20:59:41 volumio volumio[743]: info: CoreCommandRouter::volumioPushState Aug 27 20:59:41 volumio volumio[743]: info: MRS: Pushing multiroomSync output update for this device Aug 27 20:59:41 volumio volumio[743]: info: MRS: Pushing multiroomSync output Aug 27 20:59:41 volumio volumio[743]: info: CoreStateMachine::pushState Aug 27 20:59:41 volumio volumio[743]: info: CoreCommandRouter::volumioPushState Aug 27 20:59:41 volumio volumio[743]: info: MRS: Pushing multiroomSync output update for this device Aug 27 20:59:41 volumio volumio[743]: info: MRS: Pushing multiroomSync output Aug 27 20:59:41 volumio volumio[743]: info: ------------------------------ 23ms Aug 27 20:59:52 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Aug 27 20:59:52 volumio volumio[743]: info: handleBrowseUri took 397 milliseconds Aug 27 20:59:52 volumio volumio[743]: info: Preload queue cleared Aug 27 20:59:52 volumio volumio[743]: info: Preloading song: qobuz://song/77292048 Aug 27 20:59:52 volumio volumio[743]: info: Preloading song: qobuz://song/17726720 Aug 27 20:59:52 volumio volumio[743]: info: Preloading song: qobuz://song/42473572 Aug 27 20:59:52 volumio volumio[743]: info: Preloading song: qobuz://song/21798607 Aug 27 20:59:52 volumio volumio[743]: info: Preloading song: qobuz://song/35927725 Aug 27 20:59:52 volumio volumio[743]: info: Preloading song: qobuz://song/52371130 Aug 27 20:59:52 volumio volumio[743]: info: Exploding uri qobuz://song/77292048 in service qobuz Aug 27 20:59:52 volumio volumio[743]: https://browsing-performer.prod.vlmapi.io/volumio2/qobuz/explodeUri Aug 27 20:59:52 volumio volumio[743]: info: Exploding uri qobuz://song/17726720 in service qobuz Aug 27 20:59:52 volumio volumio[743]: https://browsing-performer.prod.vlmapi.io/volumio2/qobuz/explodeUri Aug 27 20:59:52 volumio volumio[743]: info: Exploding uri qobuz://song/42473572 in service qobuz Aug 27 20:59:52 volumio volumio[743]: https://browsing-performer.prod.vlmapi.io/volumio2/qobuz/explodeUri Aug 27 20:59:52 volumio volumio[743]: info: Exploding uri qobuz://song/21798607 in service qobuz Aug 27 20:59:52 volumio volumio[743]: https://browsing-performer.prod.vlmapi.io/volumio2/qobuz/explodeUri Aug 27 20:59:52 volumio volumio[743]: info: Exploding uri qobuz://song/35927725 in service qobuz Aug 27 20:59:52 volumio volumio[743]: https://browsing-performer.prod.vlmapi.io/volumio2/qobuz/explodeUri Aug 27 20:59:52 volumio volumio[743]: info: Exploding uri qobuz://song/52371130 in service qobuz Aug 27 20:59:52 volumio volumio[743]: https://browsing-performer.prod.vlmapi.io/volumio2/qobuz/explodeUri Aug 27 20:59:52 volumio volumio[743]: info: explodeUri took 277 milliseconds Aug 27 20:59:52 volumio volumio[743]: info: Exploding uri qobuz://song/52371130 in service qobuz Aug 27 20:59:52 volumio volumio[743]: https://browsing-performer.prod.vlmapi.io/volumio2/qobuz/explodeUri Aug 27 20:59:52 volumio volumio[743]: info: Exploding uri qobuz://song/52371130 in service qobuz Aug 27 20:59:52 volumio volumio[743]: https://browsing-performer.prod.vlmapi.io/volumio2/qobuz/explodeUri Aug 27 20:59:52 volumio volumio[743]: info: explodeUri took 338 milliseconds Aug 27 20:59:53 volumio volumio[743]: info: explodeUri took 237 milliseconds Aug 27 20:59:53 volumio volumio[743]: info: explodeUri took 364 milliseconds Aug 27 20:59:53 volumio volumio[743]: info: explodeUri took 322 milliseconds Aug 27 20:59:53 volumio volumio[743]: info: explodeUri took 243 milliseconds Aug 27 20:59:53 volumio volumio[743]: info: explodeUri took 463 milliseconds Aug 27 20:59:53 volumio volumio[743]: info: explodeUri took 322 milliseconds Aug 27 20:59:57 volumio volumio[743]: info: Preload queue cleared Aug 27 20:59:57 volumio volumio[743]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::ClearQueue Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::stop Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::stPlaybackTimer Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::updateTrackBlock Aug 27 20:59:57 volumio volumio[743]: info: CorePlayQueue::getTrackBlock Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::pushState Aug 27 20:59:57 volumio volumio[743]: info: CorePlayQueue::getTrack 42 Aug 27 20:59:57 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 20:59:57 volumio volumio[743]: info: CoreCommandRouter::volumioPushState Aug 27 20:59:57 volumio volumio[743]: info: MRS: Pushing multiroomSync output update for this device Aug 27 20:59:57 volumio volumio[743]: info: MRS: Pushing multiroomSync output Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::serviceStop Aug 27 20:59:57 volumio volumio[743]: info: CorePlayQueue::getTrack 42 Aug 27 20:59:57 volumio volumio[743]: info: CoreCommandRouter::serviceStop Aug 27 20:59:57 volumio volumio[743]: info: [1724785197097] ControllerQobuz::stop Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 27 20:59:57 volumio volumio[743]: info: ControllerMpd::stop Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand stop Aug 27 20:59:57 volumio volumio[743]: info: CorePlayQueue::clearPlayQueue Aug 27 20:59:57 volumio volumio[743]: info: CorePlayQueue::saveQueue Aug 27 20:59:57 volumio volumio[743]: info: CoreCommandRouter::volumioPushQueue Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::addQueueItems Aug 27 20:59:57 volumio volumio[743]: info: CorePlayQueue::addQueueItems Aug 27 20:59:57 volumio volumio[743]: info: Preload queue cleared Aug 27 20:59:57 volumio volumio[743]: info: Adding Item to queue: qobuz://song/77292048 Aug 27 20:59:57 volumio volumio[743]: info: Using cached record of: qobuz://song/77292048 Aug 27 20:59:57 volumio volumio[743]: info: Adding Item to queue: qobuz://song/17726720 Aug 27 20:59:57 volumio volumio[743]: info: Using cached record of: qobuz://song/17726720 Aug 27 20:59:57 volumio volumio[743]: info: Adding Item to queue: qobuz://song/42473572 Aug 27 20:59:57 volumio volumio[743]: info: Using cached record of: qobuz://song/42473572 Aug 27 20:59:57 volumio volumio[743]: info: Adding Item to queue: qobuz://song/124911321 Aug 27 20:59:57 volumio volumio[743]: info: Using cached record of: qobuz://song/124911321 Aug 27 20:59:57 volumio volumio[743]: info: Adding Item to queue: qobuz://song/21798607 Aug 27 20:59:57 volumio volumio[743]: info: Using cached record of: qobuz://song/21798607 Aug 27 20:59:57 volumio volumio[743]: info: Adding Item to queue: qobuz://song/35927725 Aug 27 20:59:57 volumio volumio[743]: info: Using cached record of: qobuz://song/35927725 Aug 27 20:59:57 volumio volumio[743]: info: Adding Item to queue: qobuz://song/52371130 Aug 27 20:59:57 volumio volumio[743]: info: Using cached record of: qobuz://song/52371130 Aug 27 20:59:57 volumio volumio[743]: info: Adding Item to queue: qobuz://song/52371130 Aug 27 20:59:57 volumio volumio[743]: info: Using cached record of: qobuz://song/52371130 Aug 27 20:59:57 volumio volumio[743]: info: Adding Item to queue: qobuz://song/52371130 Aug 27 20:59:57 volumio volumio[743]: info: Using cached record of: qobuz://song/52371130 Aug 27 20:59:57 volumio volumio[743]: info: CoreCommandRouter::volumioPushQueue Aug 27 20:59:57 volumio volumio[743]: info: CorePlayQueue::saveQueue Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::updateTrackBlock Aug 27 20:59:57 volumio volumio[743]: info: CorePlayQueue::getTrackBlock Aug 27 20:59:57 volumio volumio[743]: info: CoreCommandRouter::volumioPlay Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::play index 2 Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::stop Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::play index undefined Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 27 20:59:57 volumio volumio[743]: info: CorePlayQueue::getTrack 2 Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::startPlaybackTimer Aug 27 20:59:57 volumio volumio[743]: info: CorePlayQueue::getTrack 2 Aug 27 20:59:57 volumio volumio[743]: info: [1724785197118] ControllerQobuz::clearAddPlayTrack Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand stop Aug 27 20:59:57 volumio volumio[743]: info: Aug 27 20:59:57 volumio volumio[743]: ---------------------------- MPD announces state update: player Aug 27 20:59:57 volumio volumio[743]: info: sendMpdCommand stop took 33 milliseconds Aug 27 20:59:57 volumio volumio[743]: info: ControllerMpd::getState Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand status Aug 27 20:59:57 volumio volumio[743]: info: sendMpdCommand stop took 15 milliseconds Aug 27 20:59:57 volumio volumio[743]: info: sendMpdCommand status took 2 milliseconds Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand clear Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::parseState Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 20:59:57 volumio volumio[743]: info: Aug 27 20:59:57 volumio volumio[743]: ---------------------------- MPD announces system playlist update Aug 27 20:59:57 volumio volumio[743]: info: Ignoring MPD Status Update Aug 27 20:59:57 volumio volumio[743]: info: sendMpdCommand clear took 2 milliseconds Aug 27 20:59:57 volumio volumio[743]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/42473572" Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::parseTrackInfo Aug 27 20:59:57 volumio volumio[743]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 27 20:59:57 volumio volumio[743]: info: ------------------------------ 6ms Aug 27 20:59:57 volumio volumio[743]: error: updateQueue error: null Aug 27 20:59:57 volumio volumio[743]: info: ------------------------------ 4ms Aug 27 20:59:57 volumio volumio[743]: STREAMING PROXY: Handling url /?data=qobuz://song/42473572 Aug 27 20:59:57 volumio volumio[743]: info: Executing endpoint getStreamUrlqobuz Aug 27 20:59:57 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Aug 27 20:59:57 volumio volumio[743]: info: getStreamUrl took 260 milliseconds Aug 27 20:59:57 volumio volumio[743]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2879701&eid=42473572&fmt=7&profile=raw&app_id=539451548&cid=2032965&etsp=1724788797&hmac=fx6Fqy8LD6juuaJ2TKNUiHhqymA Aug 27 20:59:57 volumio volumio[743]: STREAMING PROXY: Response: 200, length: 49752501 Aug 27 20:59:57 volumio volumio[743]: STREAMING PROXY: Client dropped request, destroying Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/42473572" Aug 27 20:59:57 volumio volumio[743]: info: Aug 27 20:59:57 volumio volumio[743]: ---------------------------- MPD announces system playlist update Aug 27 20:59:57 volumio volumio[743]: info: Ignoring MPD Status Update Aug 27 20:59:57 volumio volumio[743]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/42473572" took 2 milliseconds Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand play Aug 27 20:59:57 volumio volumio[743]: info: ------------------------------ 3ms Aug 27 20:59:57 volumio volumio[743]: info: sendMpdCommand play took 2 milliseconds Aug 27 20:59:57 volumio volumio[743]: STREAMING PROXY: Handling url /?data=qobuz://song/42473572 Aug 27 20:59:57 volumio volumio[743]: info: Executing endpoint getStreamUrlqobuz Aug 27 20:59:57 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Aug 27 20:59:57 volumio volumio[743]: info: getStreamUrl took 266 milliseconds Aug 27 20:59:57 volumio volumio[743]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=2879701&eid=42473572&fmt=7&profile=raw&app_id=539451548&cid=2032965&etsp=1724788797&hmac=fx6Fqy8LD6juuaJ2TKNUiHhqymA Aug 27 20:59:57 volumio volumio[743]: STREAMING PROXY: Response: 200, length: 49752501 Aug 27 20:59:57 volumio volumio[743]: info: Aug 27 20:59:57 volumio volumio[743]: ---------------------------- MPD announces state update: player Aug 27 20:59:57 volumio volumio[743]: info: ControllerMpd::getState Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand status Aug 27 20:59:57 volumio volumio[743]: info: Aug 27 20:59:57 volumio volumio[743]: ---------------------------- MPD announces state update: player Aug 27 20:59:57 volumio volumio[743]: info: sendMpdCommand status took 39 milliseconds Aug 27 20:59:57 volumio volumio[743]: info: ControllerMpd::getState Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand status Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::parseState Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 20:59:57 volumio volumio[743]: info: sendMpdCommand status took 2 milliseconds Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::parseState Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 20:59:57 volumio volumio[743]: info: sendMpdCommand playlistinfo took 3 milliseconds Aug 27 20:59:57 volumio volumio[743]: info: sendMpdCommand playlistinfo took 2 milliseconds Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::parseTrackInfo Aug 27 20:59:57 volumio volumio[743]: verbose: ControllerMpd::parseTrackInfo Aug 27 20:59:57 volumio volumio[743]: info: ControllerMpd::pushState Aug 27 20:59:57 volumio volumio[743]: info: CoreCommandRouter::servicePushState Aug 27 20:59:57 volumio volumio[743]: info: CorePlayQueue::getTrack 2 Aug 27 20:59:57 volumio volumio[743]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":259,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1326 Kbps","isStreaming":false,"title":"42473572","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/42473572","trackType":"qobuz"} Aug 27 20:59:57 volumio volumio[743]: verbose: CURRENT POSITION 2 Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::syncState stateService play Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::syncState currentStatus stop Aug 27 20:59:57 volumio volumio[743]: info: ControllerMpd::pushState Aug 27 20:59:57 volumio volumio[743]: info: CoreCommandRouter::servicePushState Aug 27 20:59:57 volumio volumio[743]: info: CorePlayQueue::getTrack 2 Aug 27 20:59:57 volumio volumio[743]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1144,"duration":259,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1425 Kbps","isStreaming":false,"title":"42473572","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/42473572","trackType":"qobuz"} Aug 27 20:59:57 volumio volumio[743]: verbose: CURRENT POSITION 2 Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::syncState stateService play Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::syncState currentStatus play Aug 27 20:59:57 volumio volumio[743]: info: Received an update from plugin. extracting info from payload Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::pushState Aug 27 20:59:57 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 20:59:57 volumio volumio[743]: info: CoreCommandRouter::volumioPushState Aug 27 20:59:57 volumio volumio[743]: info: MRS: Pushing multiroomSync output update for this device Aug 27 20:59:57 volumio volumio[743]: info: MRS: Pushing multiroomSync output Aug 27 20:59:57 volumio volumio[743]: info: CoreStateMachine::pushState Aug 27 20:59:57 volumio volumio[743]: info: CoreCommandRouter::volumioPushState Aug 27 20:59:57 volumio volumio[743]: info: MRS: Pushing multiroomSync output update for this device Aug 27 20:59:57 volumio volumio[743]: info: MRS: Pushing multiroomSync output Aug 27 20:59:57 volumio volumio[743]: info: ------------------------------ 59ms Aug 27 20:59:57 volumio volumio[743]: info: ------------------------------ 32ms Aug 27 21:00:00 volumio volumio[743]: STREAMING PROXY: Client dropped request, destroying Aug 27 21:00:02 volumio volumio[743]: info: CoreCommandRouter::volumioSeek Aug 27 21:00:02 volumio volumio[743]: info: CoreStateMachine::seek Aug 27 21:00:02 volumio volumio[743]: info: CorePlayQueue::getTrack 2 Aug 27 21:00:02 volumio volumio[743]: info: TRACKBLOCK {"uri":"qobuz://song/42473572","service":"qobuz","name":"El Vito","title":"El Vito","album":"Kind of Spain","type":"track","tracknumber":6,"volumeNumber":1,"albumart":"https://static.qobuz.com/images/covers/21/48/0614427984821_600.jpg","duration":259,"explicit":false,"artist":"Wolfgang Haffner","artistUri":"qobuz://artist/150259","albumUri":"qobuz://album/0614427984821","audioQuality":"","tagImage":""} Aug 27 21:00:02 volumio volumio[743]: info: CoreStateMachine::startPlaybackTimer Aug 27 21:00:02 volumio volumio[743]: info: CorePlayQueue::getTrack 2 Aug 27 21:00:02 volumio volumio[743]: info: [1724785202901] ControllerQobuz::seek Aug 27 21:00:02 volumio volumio[743]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 27 21:00:02 volumio volumio[743]: info: ControllerMpd::seek Aug 27 21:00:02 volumio volumio[743]: info: CoreStateMachine::pushState Aug 27 21:00:02 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 21:00:02 volumio volumio[743]: info: CoreCommandRouter::volumioPushState Aug 27 21:00:02 volumio volumio[743]: info: MRS: Pushing multiroomSync output update for this device Aug 27 21:00:02 volumio volumio[743]: info: MRS: Pushing multiroomSync output Aug 27 21:00:02 volumio volumio[743]: error: null Aug 27 21:00:02 volumio volumio[743]: info: Aug 27 21:00:02 volumio volumio[743]: ---------------------------- MPD announces state update: player Aug 27 21:00:02 volumio volumio[743]: info: ControllerMpd::getState Aug 27 21:00:02 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand status Aug 27 21:00:02 volumio volumio[743]: info: sendMpdCommand status took 7 milliseconds Aug 27 21:00:02 volumio volumio[743]: verbose: ControllerMpd::parseState Aug 27 21:00:02 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 21:00:02 volumio volumio[743]: info: sendMpdCommand playlistinfo took 0 milliseconds Aug 27 21:00:02 volumio volumio[743]: verbose: ControllerMpd::parseTrackInfo Aug 27 21:00:02 volumio volumio[743]: info: ControllerMpd::pushState Aug 27 21:00:02 volumio volumio[743]: info: CoreCommandRouter::servicePushState Aug 27 21:00:02 volumio volumio[743]: info: CorePlayQueue::getTrack 2 Aug 27 21:00:02 volumio volumio[743]: verbose: STATE SERVICE {"status":"play","position":0,"seek":54000,"duration":259,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1513 Kbps","isStreaming":false,"title":"42473572","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/42473572","trackType":"qobuz"} Aug 27 21:00:02 volumio volumio[743]: verbose: CURRENT POSITION 2 Aug 27 21:00:02 volumio volumio[743]: info: CoreStateMachine::syncState stateService play Aug 27 21:00:02 volumio volumio[743]: info: CoreStateMachine::syncState currentStatus play Aug 27 21:00:02 volumio volumio[743]: info: Received an update from plugin. extracting info from payload Aug 27 21:00:02 volumio volumio[743]: info: CoreStateMachine::pushState Aug 27 21:00:02 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 21:00:02 volumio volumio[743]: info: CoreCommandRouter::volumioPushState Aug 27 21:00:02 volumio volumio[743]: info: MRS: Pushing multiroomSync output update for this device Aug 27 21:00:02 volumio volumio[743]: info: MRS: Pushing multiroomSync output Aug 27 21:00:02 volumio volumio[743]: info: CoreStateMachine::pushState Aug 27 21:00:02 volumio volumio[743]: info: CoreCommandRouter::volumioPushState Aug 27 21:00:02 volumio volumio[743]: info: MRS: Pushing multiroomSync output update for this device Aug 27 21:00:02 volumio volumio[743]: info: MRS: Pushing multiroomSync output Aug 27 21:00:02 volumio volumio[743]: info: ------------------------------ 35ms Aug 27 21:00:51 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid Aug 27 21:00:51 volumio volumio[743]: info: Pausing Remote Device: http://192.168.178.53 Aug 27 21:00:51 volumio volumio[743]: info: Aug 27 21:00:51 volumio volumio[743]: ---------------------------- Client requests Volumio pause Aug 27 21:00:51 volumio volumio[743]: info: CoreCommandRouter::volumioPause Aug 27 21:00:51 volumio volumio[743]: info: CoreStateMachine::pause Aug 27 21:00:51 volumio volumio[743]: info: CoreStateMachine::stPlaybackTimer Aug 27 21:00:51 volumio volumio[743]: info: CoreStateMachine::servicePause Aug 27 21:00:51 volumio volumio[743]: info: CorePlayQueue::getTrack 2 Aug 27 21:00:51 volumio volumio[743]: info: CoreCommandRouter::servicePause Aug 27 21:00:51 volumio volumio[743]: info: [1724785251059] ControllerQobuz::pause Aug 27 21:00:51 volumio volumio[743]: info: CoreStateMachine::setConsumeUpdateService mpd Aug 27 21:00:51 volumio volumio[743]: info: ControllerMpd::pause Aug 27 21:00:51 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand pause Aug 27 21:00:51 volumio volumio[743]: info: sendMpdCommand pause took 2 milliseconds Aug 27 21:00:51 volumio volumio[743]: info: Aug 27 21:00:51 volumio volumio[743]: ---------------------------- MPD announces state update: player Aug 27 21:00:51 volumio volumio[743]: info: ControllerMpd::getState Aug 27 21:00:51 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand status Aug 27 21:00:51 volumio volumio[743]: info: Done pausing: Aug 27 21:00:51 volumio volumio[743]: info: sendMpdCommand status took 6 milliseconds Aug 27 21:00:51 volumio volumio[743]: verbose: ControllerMpd::parseState Aug 27 21:00:51 volumio volumio[743]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 27 21:00:51 volumio volumio[743]: info: sendMpdCommand playlistinfo took 4 milliseconds Aug 27 21:00:51 volumio volumio[743]: verbose: ControllerMpd::parseTrackInfo Aug 27 21:00:51 volumio volumio[743]: info: ControllerMpd::pushState Aug 27 21:00:51 volumio volumio[743]: info: CoreCommandRouter::servicePushState Aug 27 21:00:51 volumio volumio[743]: info: CorePlayQueue::getTrack 2 Aug 27 21:00:51 volumio volumio[743]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":103612,"duration":259,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1720 Kbps","isStreaming":false,"title":"42473572","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/42473572","trackType":"qobuz"} Aug 27 21:00:51 volumio volumio[743]: verbose: CURRENT POSITION 2 Aug 27 21:00:51 volumio volumio[743]: info: CoreStateMachine::syncState stateService pause Aug 27 21:00:51 volumio volumio[743]: info: CoreStateMachine::syncState currentStatus pause Aug 27 21:00:51 volumio volumio[743]: info: CoreStateMachine::pushState Aug 27 21:00:51 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 21:00:51 volumio volumio[743]: info: CoreCommandRouter::volumioPushState Aug 27 21:00:51 volumio volumio[743]: info: MRS: Pushing multiroomSync output update for this device Aug 27 21:00:51 volumio volumio[743]: info: MRS: Pushing multiroomSync output Aug 27 21:00:51 volumio volumio[743]: info: CoreStateMachine::stPlaybackTimer Aug 27 21:00:51 volumio volumio[743]: info: ------------------------------ 22ms Aug 27 21:00:53 volumio volumio[743]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Aug 27 21:00:53 volumio volumio[743]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Aug 27 21:00:53 volumio volumio[743]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 21:00:53 volumio volumio[743]: TypeError: Cannot read property 'then' of undefined Aug 27 21:00:53 volumio volumio[743]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Aug 27 21:00:53 volumio volumio[743]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2260:30) Aug 27 21:00:53 volumio volumio[743]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1442:26) Aug 27 21:00:53 volumio volumio[743]: at Socket.emit (events.js:315:20) Aug 27 21:00:53 volumio volumio[743]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Aug 27 21:00:53 volumio volumio[743]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Aug 27 21:00:53 volumio volumio[743]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 21:00:53 volumio sudo[22550]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-27 20:59 Aug 27 21:00:53 volumio sudo[22550]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"