-- Logs begin at Mon 2026-02-09 19:14:10 CET, end at Mon 2026-02-09 19:25:43 CET. -- Feb 09 19:24:08 volumio volumio[900]: Searching all installed plugins Feb 09 19:24:08 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 19:24:08 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: , search Feb 09 19:24:08 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: mpd , search Feb 09 19:24:08 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Feb 09 19:24:08 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Feb 09 19:24:08 volumio volumio[900]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Feb 09 19:24:08 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: webradio , search Feb 09 19:24:08 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 09 19:24:08 volumio volumio[900]: info: searchTIDALUri took 369 milliseconds Feb 09 19:24:08 volumio volumio[900]: info: search took 370 milliseconds Feb 09 19:24:08 volumio volumio[900]: info: All search sources collected, pushing search results Feb 09 19:24:25 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:25 volumio volumio[900]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 09 19:24:25 volumio volumio[900]: info: CoreStateMachine::ClearQueue Feb 09 19:24:25 volumio volumio[900]: info: CoreStateMachine::stop Feb 09 19:24:25 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:24:25 volumio volumio[900]: info: CoreStateMachine::stPlaybackTimer Feb 09 19:24:25 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:25 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:25 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:25 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:25 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:25 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:25 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:25 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:25 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:25 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:25 volumio volumio[900]: info: CoreStateMachine::serviceStop Feb 09 19:24:25 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:25 volumio volumio[900]: info: CoreCommandRouter::serviceStop Feb 09 19:24:25 volumio volumio[900]: info: ControllerMpd::stop Feb 09 19:24:25 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand stop Feb 09 19:24:25 volumio volumio[900]: info: CorePlayQueue::clearPlayQueue Feb 09 19:24:25 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:25 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:25 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:25 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:25 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:25 volumio volumio[900]: info: Adding Item to queue: tidal://song/29280257 Feb 09 19:24:25 volumio volumio[900]: info: Exploding uri tidal://song/29280257 in service tidal Feb 09 19:24:25 volumio volumio[900]: info: Feb 09 19:24:25 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:24:25 volumio volumio[900]: info: sendMpdCommand stop took 19 milliseconds Feb 09 19:24:25 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:24:25 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:24:25 volumio volumio[900]: info: sendMpdCommand status took 1 milliseconds Feb 09 19:24:25 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:24:25 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:24:25 volumio volumio[900]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 09 19:24:25 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:24:25 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:24:25 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:24:25 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:25 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:25 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:25 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:25 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:25 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:25 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:25 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:25 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:25 volumio volumio[900]: 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":"Song Of The Wind","artist":"Santana","album":"Caravanserai","uri":"NAS/NAS/00 Audiofilskie/Mobile Fidelity Sound Lab/Santana - Caravanserai (1972) [MFSL 2011] (FLAC 24-88.2)/05 - Song Of The Wind.flac","trackType":"flac"} Feb 09 19:24:25 volumio volumio[900]: verbose: CURRENT POSITION 0 Feb 09 19:24:25 volumio volumio[900]: info: CoreStateMachine::syncState stateService stop Feb 09 19:24:25 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus stop Feb 09 19:24:25 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:25 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:25 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:25 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:25 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:25 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:25 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:25 volumio volumio[900]: info: No code Feb 09 19:24:25 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:25 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:25 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:25 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:25 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:25 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:25 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:25 volumio volumio[900]: info: ------------------------------ 35ms Feb 09 19:24:26 volumio volumio[900]: info: explodeTIDALUri took 284 milliseconds Feb 09 19:24:26 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:26 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:26 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:26 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:26 volumio volumio[900]: info: CoreCommandRouter::volumioPlay Feb 09 19:24:26 volumio volumio[900]: info: CoreStateMachine::play index 0 Feb 09 19:24:26 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:24:26 volumio volumio[900]: info: CoreStateMachine::stop Feb 09 19:24:26 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:24:26 volumio volumio[900]: info: CoreStateMachine::play index undefined Feb 09 19:24:26 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:24:26 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:26 volumio volumio[900]: info: CoreStateMachine::startPlaybackTimer Feb 09 19:24:26 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:26 volumio volumio[900]: info: CoreCommandRouter::volumioGetVisibleSources Feb 09 19:24:26 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 19:24:26 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 09 19:24:26 volumio volumio[900]: info: METAVOLUMIO: Retrieving similar tracks from metavolumio Feb 09 19:24:26 volumio volumio[900]: info: [1770661466092] ControllerTidal::clearAddPlayTrack Feb 09 19:24:26 volumio volumio[900]: info: Getting stream with soundQuality HI_RES Feb 09 19:24:26 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand stop Feb 09 19:24:26 volumio volumio[900]: info: sendMpdCommand stop took 4 milliseconds Feb 09 19:24:26 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand clear Feb 09 19:24:26 volumio volumio[900]: info: Feb 09 19:24:26 volumio volumio[900]: ---------------------------- MPD announces system playlist update Feb 09 19:24:26 volumio volumio[900]: info: Ignoring MPD Status Update Feb 09 19:24:26 volumio volumio[900]: info: sendMpdCommand clear took 1 milliseconds Feb 09 19:24:26 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/29280257&soundQuality=HI_RES" Feb 09 19:24:26 volumio volumio[900]: error: updateQueue error: null Feb 09 19:24:26 volumio volumio[900]: info: Feb 09 19:24:26 volumio volumio[900]: ---------------------------- MPD announces system playlist update Feb 09 19:24:26 volumio volumio[900]: info: Ignoring MPD Status Update Feb 09 19:24:26 volumio volumio[900]: info: ------------------------------ 3ms Feb 09 19:24:26 volumio volumio[900]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/29280257&soundQuality=HI_RES" took 2 milliseconds Feb 09 19:24:26 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:24:26 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand play Feb 09 19:24:26 volumio volumio[900]: info: ------------------------------ 3ms Feb 09 19:24:26 volumio volumio[900]: info: sendMpdCommand play took 2 milliseconds Feb 09 19:24:26 volumio volumio[900]: STREAMING PROXY: Handling url /?data=tidal://song/29280257&soundQuality=HI_RES Feb 09 19:24:26 volumio volumio[900]: info: Executing endpoint getStreamUrltidal Feb 09 19:24:26 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 09 19:24:26 volumio volumio[900]: info: getStreamUrl took 404 milliseconds Feb 09 19:24:26 volumio volumio[900]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEic5YmIyNDEyYjc4ZDI2ZjU4ZDU2ZmMxZjZlYTk4ZmUxYl82MS5tcDQ/0.flac?token=1770665066~YzEyYWYzMmExNjA1ODc2MWE0NmMyMTA3ZmNkNDk2NzYyZjE1ODczMw== Feb 09 19:24:26 volumio volumio[900]: STREAMING PROXY: Response: 200, length: 33740799 Feb 09 19:24:26 volumio volumio[900]: info: Feb 09 19:24:26 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:24:26 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:24:26 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:24:26 volumio volumio[900]: info: Feb 09 19:24:26 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:24:26 volumio volumio[900]: info: sendMpdCommand status took 62 milliseconds Feb 09 19:24:26 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:24:26 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:24:26 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:24:26 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:24:26 volumio volumio[900]: info: sendMpdCommand status took 3 milliseconds Feb 09 19:24:26 volumio volumio[900]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 09 19:24:26 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:24:26 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:24:26 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:24:26 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:24:26 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:24:26 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:26 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":306,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"29280257&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/29280257&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:24:26 volumio volumio[900]: verbose: CURRENT POSITION 0 Feb 09 19:24:26 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:24:26 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus stop Feb 09 19:24:26 volumio volumio[900]: info: ------------------------------ 69ms Feb 09 19:24:26 volumio volumio[900]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 09 19:24:26 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:24:26 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:24:26 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:24:26 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:26 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":306,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"29280257&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/29280257&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:24:26 volumio volumio[900]: verbose: CURRENT POSITION 0 Feb 09 19:24:26 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:24:26 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus play Feb 09 19:24:26 volumio volumio[900]: info: Received an update from plugin. extracting info from payload Feb 09 19:24:26 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:26 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:26 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:26 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:26 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:26 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:26 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:26 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:26 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:26 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:26 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:26 volumio volumio[900]: info: ------------------------------ 35ms Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:27 volumio volumio[900]: info: Adding Item to queue: tidal://song/29280710 Feb 09 19:24:27 volumio volumio[900]: info: Exploding uri tidal://song/29280710 in service tidal Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: mpd , search Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:27 volumio volumio[900]: info: Adding Item to queue: tidal://song/37667957 Feb 09 19:24:27 volumio volumio[900]: info: Exploding uri tidal://song/37667957 in service tidal Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: mpd , search Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:27 volumio volumio[900]: info: Adding Item to queue: tidal://song/33915157 Feb 09 19:24:27 volumio volumio[900]: info: Using cached record of: tidal://song/33915157 Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:27 volumio volumio[900]: info: Adding Item to queue: tidal://song/144718 Feb 09 19:24:27 volumio volumio[900]: info: Using cached record of: tidal://song/144718 Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:27 volumio volumio[900]: info: Adding Item to queue: tidal://song/4917690 Feb 09 19:24:27 volumio volumio[900]: info: Using cached record of: tidal://song/4917690 Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:27 volumio volumio[900]: info: Adding Item to queue: tidal://song/29280686 Feb 09 19:24:27 volumio volumio[900]: info: Exploding uri tidal://song/29280686 in service tidal Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: mpd , search Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: mpd , search Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:27 volumio volumio[900]: info: Adding Item to queue: tidal://song/1578062 Feb 09 19:24:27 volumio volumio[900]: info: Exploding uri tidal://song/1578062 in service tidal Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:27 volumio volumio[900]: info: Adding Item to queue: tidal://song/3268247 Feb 09 19:24:27 volumio volumio[900]: info: Exploding uri tidal://song/3268247 in service tidal Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:27 volumio volumio[900]: info: Adding Item to queue: tidal://song/132384664 Feb 09 19:24:27 volumio volumio[900]: info: Using cached record of: tidal://song/132384664 Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:27 volumio volumio[900]: info: Adding Item to queue: tidal://song/622357 Feb 09 19:24:27 volumio volumio[900]: info: Exploding uri tidal://song/622357 in service tidal Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:27 volumio volumio[900]: info: Adding Item to queue: tidal://song/658169 Feb 09 19:24:27 volumio volumio[900]: info: Exploding uri tidal://song/658169 in service tidal Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:27 volumio volumio[900]: info: Adding Item to queue: tidal://song/33915155 Feb 09 19:24:27 volumio volumio[900]: info: Exploding uri tidal://song/33915155 in service tidal Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: mpd , search Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:27 volumio volumio[900]: info: Adding Item to queue: tidal://song/34433751 Feb 09 19:24:27 volumio volumio[900]: info: Exploding uri tidal://song/34433751 in service tidal Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: mpd , search Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 09 19:24:27 volumio volumio[900]: info: All cached search sources collected Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:27 volumio volumio[900]: info: Adding Item to queue: tidal://song/208770799 Feb 09 19:24:27 volumio volumio[900]: info: Using cached record of: tidal://song/208770799 Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:27 volumio volumio[900]: info: explodeTIDALUri took 605 milliseconds Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:27 volumio volumio[900]: info: searchTIDALUri took 667 milliseconds Feb 09 19:24:27 volumio volumio[900]: info: search took 667 milliseconds Feb 09 19:24:27 volumio volumio[900]: info: All search sources collected, pushing search results Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:27 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:27 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:27 volumio volumio[900]: info: Adding Item to queue: tidal://song/13303096 Feb 09 19:24:27 volumio volumio[900]: info: Exploding uri tidal://song/13303096 in service tidal Feb 09 19:24:29 volumio volumio[900]: info: explodeTIDALUri took 2632 milliseconds Feb 09 19:24:29 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:29 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:29 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:29 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:31 volumio volumio[900]: STREAMING PROXY: Client dropped request, destroying Feb 09 19:24:31 volumio volumio[900]: info: searchTIDALUri took 4391 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: search took 4392 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: All search sources collected, pushing search results Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:31 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:31 volumio volumio[900]: info: Adding Item to queue: tidal://song/68952541 Feb 09 19:24:31 volumio volumio[900]: info: Exploding uri tidal://song/68952541 in service tidal Feb 09 19:24:31 volumio volumio[900]: info: explodeTIDALUri took 3543 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: explodeTIDALUri took 4458 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: explodeTIDALUri took 4459 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: explodeTIDALUri took 4491 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: explodeTIDALUri took 4433 milliseconds Feb 09 19:24:31 volumio volumio[900]: error: TIDAL Browse Error: failed to get track: got 404: {"status":404,"subStatus":2001,"userMessage":"Track [34433751] not found"} Feb 09 19:24:31 volumio volumio[900]: error: Commandrouter: Cannot explode uri tidal://song/34433751 from service tidal: failed to get track: got 404: {"status":404,"subStatus":2001,"userMessage":"Track [34433751] not found"} Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: explodeTIDALUri took 4469 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: explodeTIDALUri took 4458 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: explodeTIDALUri took 4461 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: searchTIDALUri took 4518 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: search took 4519 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: All search sources collected, pushing search results Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:31 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:31 volumio volumio[900]: info: Adding Item to queue: music-library/NAS/NAS/00 Audiofilskie/Mobile Fidelity Sound Lab/Foreigner - Double Vision (1978) [MFSL SACD 2011] (FLAC 24-88.2)/07 - TRAMONTANE.flac Feb 09 19:24:31 volumio volumio[900]: info: Exploding uri music-library/NAS/NAS/00 Audiofilskie/Mobile Fidelity Sound Lab/Foreigner - Double Vision (1978) [MFSL SACD 2011] (FLAC 24-88.2)/07 - TRAMONTANE.flac in service mpd Feb 09 19:24:31 volumio volumio[900]: info: searchTIDALUri took 4495 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: search took 4495 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: All search sources collected, pushing search results Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:31 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:31 volumio volumio[900]: info: Adding Item to queue: tidal://song/3120681 Feb 09 19:24:31 volumio volumio[900]: info: Exploding uri tidal://song/3120681 in service tidal Feb 09 19:24:31 volumio volumio[900]: info: searchTIDALUri took 4557 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: search took 4557 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: All search sources collected, pushing search results Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioGetQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::getQueue Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::getQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioAddQueueItems Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::addQueueItems Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::addQueueItems Feb 09 19:24:31 volumio volumio[900]: info: Preload queue cleared Feb 09 19:24:31 volumio volumio[900]: info: Adding Item to queue: tidal://song/47791124 Feb 09 19:24:31 volumio volumio[900]: info: Exploding uri tidal://song/47791124 in service tidal Feb 09 19:24:31 volumio volumio[900]: info: searchTIDALUri took 4512 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: search took 4513 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: All search sources collected, pushing search results Feb 09 19:24:31 volumio volumio[900]: info: METAVOLUMIO: Infinity Playback added 19 Tracks to queue Feb 09 19:24:31 volumio volumio[900]: info: ALBUMART /albumart?cacheid=720&web=FOREIGNER/DOUBLE%20VISION/extralarge&path=%2Fmnt%2FNAS%2FNAS%2F00%20Audiofilskie%2FMobile%20Fidelity%20Sound%20Lab%2FForeigner%20-%20Double%20Vision%20(1978)%20%5BMFSL%20SACD%202011%5D%20(FLAC%2024-88.2)%2F07%20-%20TRAMONTANE.flac&metadata=false Feb 09 19:24:31 volumio volumio[900]: info: URI /mnt/NAS/NAS/00 Audiofilskie/Mobile Fidelity Sound Lab/Foreigner - Double Vision (1978) [MFSL SACD 2011] (FLAC 24-88.2)/07 - TRAMONTANE.flac Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: explodeTIDALUri took 285 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: explodeTIDALUri took 309 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: explodeTIDALUri took 314 milliseconds Feb 09 19:24:31 volumio volumio[900]: info: CoreCommandRouter::volumioPushQueue Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::saveQueue Feb 09 19:24:31 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:31 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:32 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , explodeUri Feb 09 19:24:33 volumio volumio[900]: info: explodeTIDALUri took 173 milliseconds Feb 09 19:24:33 volumio volumio[900]: info: Saving Cloud item Gitarowe melodie Feb 09 19:24:33 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem Feb 09 19:24:33 volumio volumio[900]: info: Pushing Favourites {"uri":"tidal://song/29280257","favourite":false} Feb 09 19:24:33 volumio volumio[900]: info: Listing playlists Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::volumioNext Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::next Feb 09 19:24:36 volumio volumio[900]: info: [1770661476207] ControllerTidal::next Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::next Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::stop Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::stPlaybackTimer Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:36 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:36 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:36 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:36 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:36 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::serviceStop Feb 09 19:24:36 volumio volumio[900]: info: CorePlayQueue::getTrack 0 Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::serviceStop Feb 09 19:24:36 volumio volumio[900]: info: [1770661476214] ControllerTidal::stop Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:24:36 volumio volumio[900]: info: ControllerMpd::stop Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand stop Feb 09 19:24:36 volumio volumio[900]: info: Feb 09 19:24:36 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:24:36 volumio volumio[900]: info: sendMpdCommand stop took 11 milliseconds Feb 09 19:24:36 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::play index undefined Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:24:36 volumio volumio[900]: info: CorePlayQueue::getTrack 1 Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::startPlaybackTimer Feb 09 19:24:36 volumio volumio[900]: info: CorePlayQueue::getTrack 1 Feb 09 19:24:36 volumio volumio[900]: info: [1770661476228] ControllerTidal::clearAddPlayTrack Feb 09 19:24:36 volumio volumio[900]: info: Getting stream with soundQuality HI_RES Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand stop Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:36 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:36 volumio volumio[900]: info: sendMpdCommand status took 2 milliseconds Feb 09 19:24:36 volumio volumio[900]: info: sendMpdCommand stop took 1 milliseconds Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand clear Feb 09 19:24:36 volumio volumio[900]: info: Feb 09 19:24:36 volumio volumio[900]: ---------------------------- MPD announces system playlist update Feb 09 19:24:36 volumio volumio[900]: info: Ignoring MPD Status Update Feb 09 19:24:36 volumio volumio[900]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 09 19:24:36 volumio volumio[900]: info: sendMpdCommand clear took 1 milliseconds Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/33915157&soundQuality=HI_RES" Feb 09 19:24:36 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:36 volumio volumio[900]: info: CorePlayQueue::getTrack 1 Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:36 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:36 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:36 volumio volumio[900]: info: CorePlayQueue::getTrack 1 Feb 09 19:24:36 volumio volumio[900]: info: CorePlayQueue::getTrack 1 Feb 09 19:24:36 volumio volumio[900]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Feb 09 19:24:36 volumio volumio[900]: info: ------------------------------ 22ms Feb 09 19:24:36 volumio volumio[900]: error: updateQueue error: null Feb 09 19:24:36 volumio volumio[900]: info: Feb 09 19:24:36 volumio volumio[900]: ---------------------------- MPD announces system playlist update Feb 09 19:24:36 volumio volumio[900]: info: Ignoring MPD Status Update Feb 09 19:24:36 volumio volumio[900]: info: ------------------------------ 18ms Feb 09 19:24:36 volumio volumio[900]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/33915157&soundQuality=HI_RES" took 18 milliseconds Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand play Feb 09 19:24:36 volumio volumio[900]: STREAMING PROXY: Handling url /?data=tidal://song/33915157&soundQuality=HI_RES Feb 09 19:24:36 volumio volumio[900]: info: ------------------------------ 7ms Feb 09 19:24:36 volumio volumio[900]: info: sendMpdCommand play took 6 milliseconds Feb 09 19:24:36 volumio volumio[900]: info: Executing endpoint getStreamUrltidal Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 09 19:24:36 volumio volumio[900]: info: getStreamUrl took 318 milliseconds Feb 09 19:24:36 volumio volumio[900]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidiMDYyOTNiMDY3ZDVmZmE3OWJmNGRmODBkZTdmZDAzZV82Mi5tcDQ/0.flac?token=1770665076~ZWRlNWY1NDg1MmRkYjQ0YTg1MjQ3Yzg3YjljOWU3NzE5NDFjYTY1ZQ== Feb 09 19:24:36 volumio volumio[900]: STREAMING PROXY: Response: 200, length: 228041785 Feb 09 19:24:36 volumio volumio[900]: info: Feb 09 19:24:36 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:24:36 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:24:36 volumio volumio[900]: info: Feb 09 19:24:36 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:24:36 volumio volumio[900]: info: sendMpdCommand status took 4 milliseconds Feb 09 19:24:36 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:24:36 volumio volumio[900]: info: sendMpdCommand status took 2 milliseconds Feb 09 19:24:36 volumio volumio[900]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:24:36 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:24:36 volumio volumio[900]: info: CorePlayQueue::getTrack 1 Feb 09 19:24:36 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":295,"samplerate":"176.4 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"33915157&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/33915157&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:24:36 volumio volumio[900]: verbose: CURRENT POSITION 1 Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus stop Feb 09 19:24:36 volumio volumio[900]: info: ------------------------------ 9ms Feb 09 19:24:36 volumio volumio[900]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 09 19:24:36 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:24:36 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:24:36 volumio volumio[900]: info: CorePlayQueue::getTrack 1 Feb 09 19:24:36 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":295,"samplerate":"176.4 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"33915157&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/33915157&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:24:36 volumio volumio[900]: verbose: CURRENT POSITION 1 Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus play Feb 09 19:24:36 volumio volumio[900]: info: Received an update from plugin. extracting info from payload Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:36 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:36 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:36 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:36 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:36 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:36 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:36 volumio volumio[900]: info: ------------------------------ 34ms Feb 09 19:24:39 volumio volumio[900]: info: CoreCommandRouter::volumioSeek Feb 09 19:24:39 volumio volumio[900]: info: CoreStateMachine::seek Feb 09 19:24:39 volumio volumio[900]: info: CorePlayQueue::getTrack 1 Feb 09 19:24:39 volumio volumio[900]: info: TRACKBLOCK {"album":"Blow By Blow","albumUri":"tidal://album/33915149","albumart":"https://resources.tidal.com/images/a8e7f52f/62c8/4ea6/8999/74158dee4a34/640x640.jpg","artist":"Jeff Beck","artistUri":"tidal://artist/1021","audioQuality":"LOSSLESS","bitdepth":"16 bit","duration":295,"explicit":false,"name":"Freeway Jam","samplerate":"44.1 KHz","service":"tidal","title":"Freeway Jam","trackType":"tidal","tracknumber":8,"type":"track","uri":"tidal://song/33915157","volumeNumber":1} Feb 09 19:24:39 volumio volumio[900]: info: CoreStateMachine::startPlaybackTimer Feb 09 19:24:39 volumio volumio[900]: info: CorePlayQueue::getTrack 1 Feb 09 19:24:39 volumio volumio[900]: info: [1770661479179] ControllerTidal::seek Feb 09 19:24:39 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:24:39 volumio volumio[900]: info: ControllerMpd::seek Feb 09 19:24:39 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:39 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:39 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:39 volumio volumio[900]: STREAMING PROXY: Client dropped request, destroying Feb 09 19:24:39 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:39 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:39 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:39 volumio volumio[900]: STREAMING PROXY: Handling url /?data=tidal://song/33915157&soundQuality=HI_RES Feb 09 19:24:39 volumio volumio[900]: info: Executing endpoint getStreamUrltidal Feb 09 19:24:39 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 09 19:24:39 volumio volumio[900]: info: getStreamUrl took 271 milliseconds Feb 09 19:24:39 volumio volumio[900]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidiMDYyOTNiMDY3ZDVmZmE3OWJmNGRmODBkZTdmZDAzZV82Mi5tcDQ/0.flac?token=1770665076~ZWRlNWY1NDg1MmRkYjQ0YTg1MjQ3Yzg3YjljOWU3NzE5NDFjYTY1ZQ== Feb 09 19:24:39 volumio volumio[900]: STREAMING PROXY: Got range request: bytes=46763353- Feb 09 19:24:39 volumio volumio[900]: STREAMING PROXY: Response: 206, length: 181278432 Feb 09 19:24:39 volumio volumio[900]: error: null Feb 09 19:24:39 volumio volumio[900]: info: Feb 09 19:24:39 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:24:39 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:24:39 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:24:39 volumio volumio[900]: info: sendMpdCommand status took 1 milliseconds Feb 09 19:24:39 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:24:39 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:24:39 volumio volumio[900]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 09 19:24:39 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:24:39 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:24:39 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:24:39 volumio volumio[900]: info: CorePlayQueue::getTrack 1 Feb 09 19:24:39 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":61000,"duration":295,"samplerate":"176.4 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"6121 Kbps","isStreaming":false,"title":"33915157&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/33915157&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:24:39 volumio volumio[900]: verbose: CURRENT POSITION 1 Feb 09 19:24:39 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:24:39 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus play Feb 09 19:24:39 volumio volumio[900]: info: Received an update from plugin. extracting info from payload Feb 09 19:24:39 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:39 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:39 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:39 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:39 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:39 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:39 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:39 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:39 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:39 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:39 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:39 volumio volumio[900]: info: ------------------------------ 26ms Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::volumioNext Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::next Feb 09 19:24:42 volumio volumio[900]: info: [1770661482055] ControllerTidal::next Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::next Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::stop Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::stPlaybackTimer Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:42 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:42 volumio volumio[900]: info: CorePlayQueue::getTrack 1 Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:42 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:42 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:42 volumio volumio[900]: info: CorePlayQueue::getTrack 1 Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::serviceStop Feb 09 19:24:42 volumio volumio[900]: info: CorePlayQueue::getTrack 1 Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::serviceStop Feb 09 19:24:42 volumio volumio[900]: info: [1770661482061] ControllerTidal::stop Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:24:42 volumio volumio[900]: info: ControllerMpd::stop Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand stop Feb 09 19:24:42 volumio volumio[900]: STREAMING PROXY: Client dropped request, destroying Feb 09 19:24:42 volumio volumio[900]: info: Feb 09 19:24:42 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:24:42 volumio volumio[900]: info: sendMpdCommand stop took 15 milliseconds Feb 09 19:24:42 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::play index undefined Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:24:42 volumio volumio[900]: info: CorePlayQueue::getTrack 2 Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::startPlaybackTimer Feb 09 19:24:42 volumio volumio[900]: info: CorePlayQueue::getTrack 2 Feb 09 19:24:42 volumio volumio[900]: info: [1770661482089] ControllerTidal::clearAddPlayTrack Feb 09 19:24:42 volumio volumio[900]: info: Getting stream with soundQuality HI_RES Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand stop Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:42 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:42 volumio volumio[900]: info: sendMpdCommand status took 13 milliseconds Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:24:42 volumio volumio[900]: info: sendMpdCommand stop took 3 milliseconds Feb 09 19:24:42 volumio volumio[900]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand clear Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:24:42 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:42 volumio volumio[900]: info: CorePlayQueue::getTrack 2 Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:42 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:42 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:42 volumio volumio[900]: info: CorePlayQueue::getTrack 2 Feb 09 19:24:42 volumio volumio[900]: info: CorePlayQueue::getTrack 2 Feb 09 19:24:42 volumio volumio[900]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Feb 09 19:24:42 volumio volumio[900]: info: ------------------------------ 33ms Feb 09 19:24:42 volumio volumio[900]: info: Feb 09 19:24:42 volumio volumio[900]: ---------------------------- MPD announces system playlist update Feb 09 19:24:42 volumio volumio[900]: info: Ignoring MPD Status Update Feb 09 19:24:42 volumio volumio[900]: info: sendMpdCommand clear took 19 milliseconds Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/144718&soundQuality=HI_RES" Feb 09 19:24:42 volumio volumio[900]: error: updateQueue error: null Feb 09 19:24:42 volumio volumio[900]: info: Feb 09 19:24:42 volumio volumio[900]: ---------------------------- MPD announces system playlist update Feb 09 19:24:42 volumio volumio[900]: info: Ignoring MPD Status Update Feb 09 19:24:42 volumio volumio[900]: info: ------------------------------ 7ms Feb 09 19:24:42 volumio volumio[900]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/144718&soundQuality=HI_RES" took 6 milliseconds Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand play Feb 09 19:24:42 volumio volumio[900]: STREAMING PROXY: Handling url /?data=tidal://song/144718&soundQuality=HI_RES Feb 09 19:24:42 volumio volumio[900]: info: ------------------------------ 4ms Feb 09 19:24:42 volumio volumio[900]: info: sendMpdCommand play took 3 milliseconds Feb 09 19:24:42 volumio volumio[900]: info: Executing endpoint getStreamUrltidal Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 09 19:24:42 volumio volumio[900]: info: getStreamUrl took 276 milliseconds Feb 09 19:24:42 volumio volumio[900]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidmMDliZjIwNjQ3NDE1N2I4NmVhNTkwM2IyYTVjZjdlM182MS5tcDQ/0.flac?token=1770665082~M2UyMGEyMzE3OWExZjY1Yzk3ZjYxZDI5MzcxMzkxODE5YjZmZDhlZA== Feb 09 19:24:42 volumio volumio[900]: STREAMING PROXY: Response: 200, length: 36832361 Feb 09 19:24:42 volumio volumio[900]: info: Feb 09 19:24:42 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:24:42 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:24:42 volumio volumio[900]: info: Feb 09 19:24:42 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:24:42 volumio volumio[900]: info: sendMpdCommand status took 4 milliseconds Feb 09 19:24:42 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:24:42 volumio volumio[900]: info: sendMpdCommand status took 2 milliseconds Feb 09 19:24:42 volumio volumio[900]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:24:42 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:24:42 volumio volumio[900]: info: CorePlayQueue::getTrack 2 Feb 09 19:24:42 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":354,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"144718&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/144718&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:24:42 volumio volumio[900]: verbose: CURRENT POSITION 2 Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus stop Feb 09 19:24:42 volumio volumio[900]: info: ------------------------------ 9ms Feb 09 19:24:42 volumio volumio[900]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 09 19:24:42 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:24:42 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:24:42 volumio volumio[900]: info: CorePlayQueue::getTrack 2 Feb 09 19:24:42 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":354,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"144718&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/144718&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:24:42 volumio volumio[900]: verbose: CURRENT POSITION 2 Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus play Feb 09 19:24:42 volumio volumio[900]: info: Received an update from plugin. extracting info from payload Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:42 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:42 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:42 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:42 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:42 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:42 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:42 volumio volumio[900]: info: ------------------------------ 25ms Feb 09 19:24:45 volumio volumio[900]: info: CoreCommandRouter::volumioSeek Feb 09 19:24:45 volumio volumio[900]: info: CoreStateMachine::seek Feb 09 19:24:45 volumio volumio[900]: info: CorePlayQueue::getTrack 2 Feb 09 19:24:45 volumio volumio[900]: info: TRACKBLOCK {"album":"Wild Frontier","albumUri":"tidal://album/144714","albumart":"https://resources.tidal.com/images/0c89a6c0/642e/43e2/a9cc/9ad1ac996528/640x640.jpg","artist":"Gary Moore","artistUri":"tidal://artist/10243","audioQuality":"LOSSLESS","bitdepth":"16 bit","duration":354,"explicit":false,"name":"The Loner","samplerate":"44.1 KHz","service":"tidal","title":"The Loner","trackType":"tidal","tracknumber":4,"type":"track","uri":"tidal://song/144718","volumeNumber":1} Feb 09 19:24:45 volumio volumio[900]: info: CoreStateMachine::startPlaybackTimer Feb 09 19:24:45 volumio volumio[900]: info: CorePlayQueue::getTrack 2 Feb 09 19:24:45 volumio volumio[900]: info: [1770661485109] ControllerTidal::seek Feb 09 19:24:45 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:24:45 volumio volumio[900]: info: ControllerMpd::seek Feb 09 19:24:45 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:45 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:45 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:45 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:45 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:45 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:45 volumio volumio[900]: error: null Feb 09 19:24:45 volumio volumio[900]: info: Feb 09 19:24:45 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:24:45 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:24:45 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:24:45 volumio volumio[900]: info: sendMpdCommand status took 6 milliseconds Feb 09 19:24:45 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:24:45 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:24:45 volumio volumio[900]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 09 19:24:45 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:24:45 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:24:45 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:24:45 volumio volumio[900]: info: CorePlayQueue::getTrack 2 Feb 09 19:24:45 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":81098,"duration":354,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"747 Kbps","isStreaming":false,"title":"144718&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/144718&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:24:45 volumio volumio[900]: verbose: CURRENT POSITION 2 Feb 09 19:24:45 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:24:45 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus play Feb 09 19:24:45 volumio volumio[900]: info: Received an update from plugin. extracting info from payload Feb 09 19:24:45 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:45 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:45 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:45 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:45 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:45 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:45 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:45 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:45 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:45 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:45 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:45 volumio volumio[900]: info: ------------------------------ 40ms Feb 09 19:24:46 volumio volumio[900]: info: CoreCommandRouter::volumioSeek Feb 09 19:24:46 volumio volumio[900]: info: CoreStateMachine::seek Feb 09 19:24:46 volumio volumio[900]: info: CorePlayQueue::getTrack 2 Feb 09 19:24:46 volumio volumio[900]: info: TRACKBLOCK {"album":"Wild Frontier","albumUri":"tidal://album/144714","albumart":"https://resources.tidal.com/images/0c89a6c0/642e/43e2/a9cc/9ad1ac996528/640x640.jpg","artist":"Gary Moore","artistUri":"tidal://artist/10243","audioQuality":"LOSSLESS","bitdepth":"16 bit","duration":354,"explicit":false,"name":"The Loner","samplerate":"44.1 KHz","service":"tidal","title":"The Loner","trackType":"tidal","tracknumber":4,"type":"track","uri":"tidal://song/144718","volumeNumber":1} Feb 09 19:24:46 volumio volumio[900]: info: CoreStateMachine::startPlaybackTimer Feb 09 19:24:46 volumio volumio[900]: info: CorePlayQueue::getTrack 2 Feb 09 19:24:46 volumio volumio[900]: info: [1770661486676] ControllerTidal::seek Feb 09 19:24:46 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:24:46 volumio volumio[900]: info: ControllerMpd::seek Feb 09 19:24:46 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:46 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:46 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:46 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:46 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:46 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:46 volumio volumio[900]: error: null Feb 09 19:24:46 volumio volumio[900]: info: Feb 09 19:24:46 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:24:46 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:24:46 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:24:46 volumio volumio[900]: info: sendMpdCommand status took 5 milliseconds Feb 09 19:24:46 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:24:46 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:24:46 volumio volumio[900]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 09 19:24:46 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:24:46 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:24:46 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:24:46 volumio volumio[900]: info: CorePlayQueue::getTrack 2 Feb 09 19:24:46 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":144098,"duration":354,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"795 Kbps","isStreaming":false,"title":"144718&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/144718&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:24:46 volumio volumio[900]: verbose: CURRENT POSITION 2 Feb 09 19:24:46 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:24:46 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus play Feb 09 19:24:46 volumio volumio[900]: info: Received an update from plugin. extracting info from payload Feb 09 19:24:46 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:46 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:46 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:46 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:46 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:46 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:46 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:46 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:46 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:46 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:46 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:46 volumio volumio[900]: info: ------------------------------ 45ms Feb 09 19:24:47 volumio volumio[900]: STREAMING PROXY: Client dropped request, destroying Feb 09 19:24:50 volumio volumio[900]: info: CoreCommandRouter::volumioNext Feb 09 19:24:50 volumio volumio[900]: info: CoreStateMachine::next Feb 09 19:24:50 volumio volumio[900]: info: [1770661490745] ControllerTidal::next Feb 09 19:24:50 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:24:50 volumio volumio[900]: info: CoreStateMachine::next Feb 09 19:24:50 volumio volumio[900]: info: CoreStateMachine::stop Feb 09 19:24:50 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:24:50 volumio volumio[900]: info: CoreStateMachine::stPlaybackTimer Feb 09 19:24:50 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:50 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:50 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:50 volumio volumio[900]: info: CorePlayQueue::getTrack 2 Feb 09 19:24:50 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:50 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:50 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:50 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:50 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:50 volumio volumio[900]: info: CorePlayQueue::getTrack 2 Feb 09 19:24:50 volumio volumio[900]: info: CoreStateMachine::serviceStop Feb 09 19:24:50 volumio volumio[900]: info: CorePlayQueue::getTrack 2 Feb 09 19:24:50 volumio volumio[900]: info: CoreCommandRouter::serviceStop Feb 09 19:24:50 volumio volumio[900]: info: [1770661490752] ControllerTidal::stop Feb 09 19:24:50 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:24:50 volumio volumio[900]: info: ControllerMpd::stop Feb 09 19:24:50 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand stop Feb 09 19:24:50 volumio volumio[900]: info: Feb 09 19:24:50 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:24:50 volumio volumio[900]: info: sendMpdCommand stop took 12 milliseconds Feb 09 19:24:50 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:24:50 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:24:50 volumio volumio[900]: info: CoreStateMachine::play index undefined Feb 09 19:24:50 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:24:50 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:24:50 volumio volumio[900]: info: CoreStateMachine::startPlaybackTimer Feb 09 19:24:50 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:24:50 volumio volumio[900]: info: [1770661490765] ControllerTidal::clearAddPlayTrack Feb 09 19:24:50 volumio volumio[900]: info: Getting stream with soundQuality HI_RES Feb 09 19:24:50 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand stop Feb 09 19:24:50 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:24:50 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:24:50 volumio volumio[900]: info: sendMpdCommand status took 2 milliseconds Feb 09 19:24:50 volumio volumio[900]: info: sendMpdCommand stop took 1 milliseconds Feb 09 19:24:50 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:24:50 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:24:50 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand clear Feb 09 19:24:50 volumio volumio[900]: info: Feb 09 19:24:50 volumio volumio[900]: ---------------------------- MPD announces system playlist update Feb 09 19:24:50 volumio volumio[900]: info: Ignoring MPD Status Update Feb 09 19:24:50 volumio volumio[900]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 09 19:24:50 volumio volumio[900]: info: sendMpdCommand clear took 1 milliseconds Feb 09 19:24:50 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:24:50 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/4917690&soundQuality=HI_RES" Feb 09 19:24:50 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:24:50 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:24:50 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:50 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:24:50 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:50 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:50 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:50 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:50 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:50 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:24:50 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:24:50 volumio volumio[900]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Feb 09 19:24:50 volumio volumio[900]: info: ------------------------------ 19ms Feb 09 19:24:50 volumio volumio[900]: error: updateQueue error: null Feb 09 19:24:50 volumio volumio[900]: info: Feb 09 19:24:50 volumio volumio[900]: ---------------------------- MPD announces system playlist update Feb 09 19:24:50 volumio volumio[900]: info: Ignoring MPD Status Update Feb 09 19:24:50 volumio volumio[900]: info: ------------------------------ 16ms Feb 09 19:24:50 volumio volumio[900]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/4917690&soundQuality=HI_RES" took 15 milliseconds Feb 09 19:24:50 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:24:50 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand play Feb 09 19:24:50 volumio volumio[900]: STREAMING PROXY: Handling url /?data=tidal://song/4917690&soundQuality=HI_RES Feb 09 19:24:50 volumio volumio[900]: info: ------------------------------ 6ms Feb 09 19:24:50 volumio volumio[900]: info: sendMpdCommand play took 5 milliseconds Feb 09 19:24:50 volumio volumio[900]: info: Executing endpoint getStreamUrltidal Feb 09 19:24:50 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 09 19:24:51 volumio volumio[900]: info: getStreamUrl took 313 milliseconds Feb 09 19:24:51 volumio volumio[900]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidlODkyM2M1YjAyNzlhZWQ5MGQyZjFhOTE5OTY3Nzc4MV82MS5tcDQ/0.flac?token=1770665091~MDRhMjZhODAwNDU3ZjFkODVkNmEzMjQ5Mjg5ZjU0ZjcwOWZhNzI5YQ== Feb 09 19:24:51 volumio volumio[900]: STREAMING PROXY: Response: 200, length: 36147770 Feb 09 19:24:51 volumio volumio[900]: info: Feb 09 19:24:51 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:24:51 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:24:51 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:24:51 volumio volumio[900]: info: Feb 09 19:24:51 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:24:51 volumio volumio[900]: info: sendMpdCommand status took 2 milliseconds Feb 09 19:24:51 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:24:51 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:24:51 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:24:51 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:24:51 volumio volumio[900]: info: sendMpdCommand status took 2 milliseconds Feb 09 19:24:51 volumio volumio[900]: info: sendMpdCommand playlistinfo took 9 milliseconds Feb 09 19:24:51 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:24:51 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:24:51 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:24:51 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:24:51 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:24:51 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:24:51 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":357,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"4917690&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/4917690&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:24:51 volumio volumio[900]: verbose: CURRENT POSITION 3 Feb 09 19:24:51 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:24:51 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus stop Feb 09 19:24:51 volumio volumio[900]: info: ------------------------------ 18ms Feb 09 19:24:51 volumio volumio[900]: info: sendMpdCommand playlistinfo took 5 milliseconds Feb 09 19:24:51 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:24:51 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:24:51 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:24:51 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:24:51 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":357,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"4917690&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/4917690&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:24:51 volumio volumio[900]: verbose: CURRENT POSITION 3 Feb 09 19:24:51 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:24:51 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus play Feb 09 19:24:51 volumio volumio[900]: info: Received an update from plugin. extracting info from payload Feb 09 19:24:51 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:51 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:51 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:51 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:51 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:51 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:51 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:51 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:51 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:51 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:51 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:51 volumio volumio[900]: info: ------------------------------ 48ms Feb 09 19:24:56 volumio volumio[900]: STREAMING PROXY: Client dropped request, destroying Feb 09 19:24:56 volumio volumio[900]: info: CoreCommandRouter::volumioSeek Feb 09 19:24:56 volumio volumio[900]: info: CoreStateMachine::seek Feb 09 19:24:56 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:24:56 volumio volumio[900]: info: TRACKBLOCK {"album":"The Essential Santana","albumUri":"tidal://album/4917660","albumart":"https://resources.tidal.com/images/96110cbf/09be/451f/8b6e/3265ef329eb3/640x640.jpg","artist":"Carlos Santana","artistUri":"tidal://artist/33572129","audioQuality":"LOSSLESS","bitdepth":"16 bit","duration":357,"explicit":false,"name":"Blues for Salvador","samplerate":"44.1 KHz","service":"tidal","title":"Blues for Salvador","trackType":"tidal","tracknumber":15,"type":"track","uri":"tidal://song/4917690","volumeNumber":2} Feb 09 19:24:56 volumio volumio[900]: info: CoreStateMachine::startPlaybackTimer Feb 09 19:24:56 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:24:56 volumio volumio[900]: info: [1770661496811] ControllerTidal::seek Feb 09 19:24:56 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:24:56 volumio volumio[900]: info: ControllerMpd::seek Feb 09 19:24:56 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:56 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:56 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:56 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:56 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:56 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:56 volumio volumio[900]: error: null Feb 09 19:24:56 volumio volumio[900]: info: Feb 09 19:24:56 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:24:56 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:24:56 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:24:56 volumio volumio[900]: info: sendMpdCommand status took 8 milliseconds Feb 09 19:24:56 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:24:56 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:24:56 volumio volumio[900]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 09 19:24:56 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:24:56 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:24:56 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:24:56 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:24:56 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":86098,"duration":357,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"870 Kbps","isStreaming":false,"title":"4917690&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/4917690&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:24:56 volumio volumio[900]: verbose: CURRENT POSITION 3 Feb 09 19:24:56 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:24:56 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus play Feb 09 19:24:56 volumio volumio[900]: info: Received an update from plugin. extracting info from payload Feb 09 19:24:56 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:56 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:24:56 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:56 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:56 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:56 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:56 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:24:56 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:24:56 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:24:56 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:24:56 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:24:56 volumio volumio[900]: info: ------------------------------ 32ms Feb 09 19:25:08 volumio volumio[900]: info: CoreCommandRouter::volumioSeek Feb 09 19:25:08 volumio volumio[900]: info: CoreStateMachine::seek Feb 09 19:25:08 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:25:08 volumio volumio[900]: info: TRACKBLOCK {"album":"The Essential Santana","albumUri":"tidal://album/4917660","albumart":"https://resources.tidal.com/images/96110cbf/09be/451f/8b6e/3265ef329eb3/640x640.jpg","artist":"Carlos Santana","artistUri":"tidal://artist/33572129","audioQuality":"LOSSLESS","bitdepth":"16 bit","duration":357,"explicit":false,"name":"Blues for Salvador","samplerate":"44.1 KHz","service":"tidal","title":"Blues for Salvador","trackType":"tidal","tracknumber":15,"type":"track","uri":"tidal://song/4917690","volumeNumber":2} Feb 09 19:25:08 volumio volumio[900]: info: CoreStateMachine::startPlaybackTimer Feb 09 19:25:08 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:25:08 volumio volumio[900]: info: [1770661508101] ControllerTidal::seek Feb 09 19:25:08 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:25:08 volumio volumio[900]: info: ControllerMpd::seek Feb 09 19:25:08 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:08 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:08 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:08 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:08 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:08 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:08 volumio volumio[900]: error: null Feb 09 19:25:08 volumio volumio[900]: info: Feb 09 19:25:08 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:25:08 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:25:08 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:25:08 volumio volumio[900]: info: sendMpdCommand status took 4 milliseconds Feb 09 19:25:08 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:25:08 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:25:08 volumio volumio[900]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 09 19:25:08 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:25:08 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:25:08 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:25:08 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:25:08 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":156098,"duration":357,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"891 Kbps","isStreaming":false,"title":"4917690&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/4917690&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:25:08 volumio volumio[900]: verbose: CURRENT POSITION 3 Feb 09 19:25:08 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:25:08 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus play Feb 09 19:25:08 volumio volumio[900]: info: Received an update from plugin. extracting info from payload Feb 09 19:25:08 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:08 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:08 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:08 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:08 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:08 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:08 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:08 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:08 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:08 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:08 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:08 volumio volumio[900]: info: ------------------------------ 38ms Feb 09 19:25:10 volumio volumio[900]: info: CoreCommandRouter::volumioSeek Feb 09 19:25:10 volumio volumio[900]: info: CoreStateMachine::seek Feb 09 19:25:10 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:25:10 volumio volumio[900]: info: TRACKBLOCK {"album":"The Essential Santana","albumUri":"tidal://album/4917660","albumart":"https://resources.tidal.com/images/96110cbf/09be/451f/8b6e/3265ef329eb3/640x640.jpg","artist":"Carlos Santana","artistUri":"tidal://artist/33572129","audioQuality":"LOSSLESS","bitdepth":"16 bit","duration":357,"explicit":false,"name":"Blues for Salvador","samplerate":"44.1 KHz","service":"tidal","title":"Blues for Salvador","trackType":"tidal","tracknumber":15,"type":"track","uri":"tidal://song/4917690","volumeNumber":2} Feb 09 19:25:10 volumio volumio[900]: info: CoreStateMachine::startPlaybackTimer Feb 09 19:25:10 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:25:10 volumio volumio[900]: info: [1770661510234] ControllerTidal::seek Feb 09 19:25:10 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:25:10 volumio volumio[900]: info: ControllerMpd::seek Feb 09 19:25:10 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:10 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:10 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:10 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:10 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:10 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:10 volumio volumio[900]: error: null Feb 09 19:25:10 volumio volumio[900]: info: Feb 09 19:25:10 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:25:10 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:25:10 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:25:10 volumio volumio[900]: info: sendMpdCommand status took 6 milliseconds Feb 09 19:25:10 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:25:10 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:25:10 volumio volumio[900]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 09 19:25:10 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:25:10 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:25:10 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:25:10 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:25:10 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":257098,"duration":357,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"768 Kbps","isStreaming":false,"title":"4917690&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/4917690&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:25:10 volumio volumio[900]: verbose: CURRENT POSITION 3 Feb 09 19:25:10 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:25:10 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus play Feb 09 19:25:10 volumio volumio[900]: info: Received an update from plugin. extracting info from payload Feb 09 19:25:10 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:10 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:10 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:10 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:10 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:10 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:10 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:10 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:10 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:10 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:10 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:10 volumio volumio[900]: info: ------------------------------ 31ms Feb 09 19:25:13 volumio volumio[900]: info: CoreCommandRouter::volumioNext Feb 09 19:25:13 volumio volumio[900]: info: CoreStateMachine::next Feb 09 19:25:13 volumio volumio[900]: info: [1770661513914] ControllerTidal::next Feb 09 19:25:13 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:25:13 volumio volumio[900]: info: CoreStateMachine::next Feb 09 19:25:13 volumio volumio[900]: info: CoreStateMachine::stop Feb 09 19:25:13 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:25:13 volumio volumio[900]: info: CoreStateMachine::stPlaybackTimer Feb 09 19:25:13 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:25:13 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:25:13 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:13 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:25:13 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:13 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:13 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:13 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:13 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:13 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:25:13 volumio volumio[900]: info: CoreStateMachine::serviceStop Feb 09 19:25:13 volumio volumio[900]: info: CorePlayQueue::getTrack 3 Feb 09 19:25:13 volumio volumio[900]: info: CoreCommandRouter::serviceStop Feb 09 19:25:13 volumio volumio[900]: info: [1770661513921] ControllerTidal::stop Feb 09 19:25:13 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:25:13 volumio volumio[900]: info: ControllerMpd::stop Feb 09 19:25:13 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand stop Feb 09 19:25:13 volumio volumio[900]: info: Feb 09 19:25:13 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:25:13 volumio volumio[900]: info: sendMpdCommand stop took 15 milliseconds Feb 09 19:25:13 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:25:13 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:25:13 volumio volumio[900]: info: CoreStateMachine::play index undefined Feb 09 19:25:13 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:25:13 volumio volumio[900]: info: CorePlayQueue::getTrack 4 Feb 09 19:25:13 volumio volumio[900]: info: CoreStateMachine::startPlaybackTimer Feb 09 19:25:13 volumio volumio[900]: info: CorePlayQueue::getTrack 4 Feb 09 19:25:13 volumio volumio[900]: info: [1770661513937] ControllerTidal::clearAddPlayTrack Feb 09 19:25:13 volumio volumio[900]: info: Getting stream with soundQuality HI_RES Feb 09 19:25:13 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand stop Feb 09 19:25:13 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:25:13 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:25:13 volumio volumio[900]: info: sendMpdCommand status took 3 milliseconds Feb 09 19:25:13 volumio volumio[900]: info: sendMpdCommand stop took 1 milliseconds Feb 09 19:25:13 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:25:13 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:25:13 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand clear Feb 09 19:25:13 volumio volumio[900]: info: Feb 09 19:25:13 volumio volumio[900]: ---------------------------- MPD announces system playlist update Feb 09 19:25:13 volumio volumio[900]: info: Ignoring MPD Status Update Feb 09 19:25:13 volumio volumio[900]: info: sendMpdCommand playlistinfo took 6 milliseconds Feb 09 19:25:13 volumio volumio[900]: info: sendMpdCommand clear took 6 milliseconds Feb 09 19:25:13 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:25:13 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/132384664&soundQuality=HI_RES" Feb 09 19:25:13 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:25:13 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:25:13 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:13 volumio volumio[900]: info: CorePlayQueue::getTrack 4 Feb 09 19:25:13 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:13 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:13 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:13 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:13 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:13 volumio volumio[900]: info: CorePlayQueue::getTrack 4 Feb 09 19:25:13 volumio volumio[900]: info: CorePlayQueue::getTrack 4 Feb 09 19:25:13 volumio volumio[900]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Feb 09 19:25:13 volumio volumio[900]: info: ------------------------------ 25ms Feb 09 19:25:13 volumio volumio[900]: error: updateQueue error: null Feb 09 19:25:13 volumio volumio[900]: info: Feb 09 19:25:13 volumio volumio[900]: ---------------------------- MPD announces system playlist update Feb 09 19:25:13 volumio volumio[900]: info: Ignoring MPD Status Update Feb 09 19:25:13 volumio volumio[900]: info: ------------------------------ 17ms Feb 09 19:25:13 volumio volumio[900]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/132384664&soundQuality=HI_RES" took 16 milliseconds Feb 09 19:25:13 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:25:13 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand play Feb 09 19:25:13 volumio volumio[900]: STREAMING PROXY: Handling url /?data=tidal://song/132384664&soundQuality=HI_RES Feb 09 19:25:13 volumio volumio[900]: info: ------------------------------ 6ms Feb 09 19:25:13 volumio volumio[900]: info: sendMpdCommand play took 6 milliseconds Feb 09 19:25:13 volumio volumio[900]: info: Executing endpoint getStreamUrltidal Feb 09 19:25:13 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 09 19:25:14 volumio volumio[900]: info: getStreamUrl took 654 milliseconds Feb 09 19:25:14 volumio volumio[900]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicwYTEzMjY0Y2Y1MTdiNGQ1YTI1YmI3ZTI5Y2IxY2E1Zl82MS5tcDQ/0.flac?token=1770665114~NGQ4ZTI1YmQzYzQ4MzkxYWJlMjMxZDEzZDc2N2JhYzRkY2RmNjQ2Mg== Feb 09 19:25:14 volumio volumio[900]: STREAMING PROXY: Response: 200, length: 54864415 Feb 09 19:25:14 volumio volumio[900]: info: Feb 09 19:25:14 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:25:14 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:25:14 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:25:14 volumio volumio[900]: info: sendMpdCommand status took 1 milliseconds Feb 09 19:25:14 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:25:14 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:25:15 volumio volumio[900]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 09 19:25:15 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:25:15 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:25:15 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:25:15 volumio volumio[900]: info: CorePlayQueue::getTrack 4 Feb 09 19:25:15 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":453,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"132384664&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/132384664&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:25:15 volumio volumio[900]: verbose: CURRENT POSITION 4 Feb 09 19:25:15 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:25:15 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus stop Feb 09 19:25:15 volumio volumio[900]: info: ------------------------------ 3ms Feb 09 19:25:16 volumio volumio[900]: info: CoreCommandRouter::volumioSeek Feb 09 19:25:16 volumio volumio[900]: info: CoreStateMachine::seek Feb 09 19:25:16 volumio volumio[900]: info: CorePlayQueue::getTrack 4 Feb 09 19:25:16 volumio volumio[900]: info: TRACKBLOCK {"album":"Trouble No More: 50th Anniversary Collection","albumUri":"tidal://album/132384589","albumart":"https://resources.tidal.com/images/12040f4f/8d5c/4093/8017/cea7b55575b8/640x640.jpg","artist":"The Allman Brothers Band","artistUri":"tidal://artist/3981","audioQuality":"LOSSLESS","bitdepth":"16 bit","duration":453,"explicit":false,"name":"Pegasus","samplerate":"44.1 KHz","service":"tidal","title":"Pegasus","trackType":"tidal","tracknumber":8,"type":"track","uri":"tidal://song/132384664","volumeNumber":3} Feb 09 19:25:16 volumio volumio[900]: info: CoreStateMachine::startPlaybackTimer Feb 09 19:25:16 volumio volumio[900]: info: CorePlayQueue::getTrack 4 Feb 09 19:25:16 volumio volumio[900]: info: [1770661516402] ControllerTidal::seek Feb 09 19:25:16 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:25:16 volumio volumio[900]: info: ControllerMpd::seek Feb 09 19:25:16 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:16 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:16 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:16 volumio volumio[900]: STREAMING PROXY: Client dropped request, destroying Feb 09 19:25:16 volumio volumio[900]: STREAMING PROXY: Handling url /?data=tidal://song/132384664&soundQuality=HI_RES Feb 09 19:25:16 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:16 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:16 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:16 volumio volumio[900]: info: Executing endpoint getStreamUrltidal Feb 09 19:25:16 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 09 19:25:17 volumio volumio[900]: info: getStreamUrl took 645 milliseconds Feb 09 19:25:17 volumio volumio[900]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicwYTEzMjY0Y2Y1MTdiNGQ1YTI1YmI3ZTI5Y2IxY2E1Zl82MS5tcDQ/0.flac?token=1770665114~NGQ4ZTI1YmQzYzQ4MzkxYWJlMjMxZDEzZDc2N2JhYzRkY2RmNjQ2Mg== Feb 09 19:25:17 volumio volumio[900]: STREAMING PROXY: Got range request: bytes=14461788- Feb 09 19:25:17 volumio volumio[900]: STREAMING PROXY: Response: 206, length: 40402627 Feb 09 19:25:17 volumio volumio[900]: STREAMING PROXY: Client dropped request, destroying Feb 09 19:25:17 volumio volumio[900]: STREAMING PROXY: Handling url /?data=tidal://song/132384664&soundQuality=HI_RES Feb 09 19:25:17 volumio volumio[900]: info: Executing endpoint getStreamUrltidal Feb 09 19:25:17 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 09 19:25:17 volumio volumio[900]: info: getStreamUrl took 326 milliseconds Feb 09 19:25:17 volumio volumio[900]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicwYTEzMjY0Y2Y1MTdiNGQ1YTI1YmI3ZTI5Y2IxY2E1Zl82MS5tcDQ/0.flac?token=1770665114~NGQ4ZTI1YmQzYzQ4MzkxYWJlMjMxZDEzZDc2N2JhYzRkY2RmNjQ2Mg== Feb 09 19:25:17 volumio volumio[900]: STREAMING PROXY: Got range request: bytes=14454674- Feb 09 19:25:17 volumio volumio[900]: STREAMING PROXY: Response: 206, length: 40409741 Feb 09 19:25:17 volumio volumio[900]: STREAMING PROXY: Client dropped request, destroying Feb 09 19:25:17 volumio volumio[900]: error: null Feb 09 19:25:17 volumio volumio[900]: info: Feb 09 19:25:17 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:25:17 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:25:17 volumio volumio[900]: STREAMING PROXY: Handling url /?data=tidal://song/132384664&soundQuality=HI_RES Feb 09 19:25:17 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:25:17 volumio volumio[900]: info: sendMpdCommand status took 1 milliseconds Feb 09 19:25:17 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:25:17 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:25:17 volumio volumio[900]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 09 19:25:17 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:25:17 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:25:17 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:25:17 volumio volumio[900]: info: CorePlayQueue::getTrack 4 Feb 09 19:25:17 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":121000,"duration":453,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"869 Kbps","isStreaming":false,"title":"132384664&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/132384664&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:25:17 volumio volumio[900]: verbose: CURRENT POSITION 4 Feb 09 19:25:17 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:25:17 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus play Feb 09 19:25:17 volumio volumio[900]: info: Received an update from plugin. extracting info from payload Feb 09 19:25:17 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:17 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:17 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:17 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:17 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:17 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:17 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:17 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:17 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:17 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:17 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:17 volumio volumio[900]: info: ------------------------------ 28ms Feb 09 19:25:17 volumio volumio[900]: info: Executing endpoint getStreamUrltidal Feb 09 19:25:17 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 09 19:25:18 volumio volumio[900]: info: getStreamUrl took 283 milliseconds Feb 09 19:25:18 volumio volumio[900]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicwYTEzMjY0Y2Y1MTdiNGQ1YTI1YmI3ZTI5Y2IxY2E1Zl82MS5tcDQ/0.flac?token=1770665114~NGQ4ZTI1YmQzYzQ4MzkxYWJlMjMxZDEzZDc2N2JhYzRkY2RmNjQ2Mg== Feb 09 19:25:18 volumio volumio[900]: STREAMING PROXY: Got range request: bytes=4729344- Feb 09 19:25:18 volumio volumio[900]: STREAMING PROXY: Response: 206, length: 50135071 Feb 09 19:25:18 volumio volumio[900]: STREAMING PROXY: Client dropped request, destroying Feb 09 19:25:18 volumio volumio[900]: STREAMING PROXY: Handling url /?data=tidal://song/132384664&soundQuality=HI_RES Feb 09 19:25:18 volumio volumio[900]: info: Executing endpoint getStreamUrltidal Feb 09 19:25:18 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 09 19:25:18 volumio volumio[900]: info: getStreamUrl took 288 milliseconds Feb 09 19:25:18 volumio volumio[900]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicwYTEzMjY0Y2Y1MTdiNGQ1YTI1YmI3ZTI5Y2IxY2E1Zl82MS5tcDQ/0.flac?token=1770665114~NGQ4ZTI1YmQzYzQ4MzkxYWJlMjMxZDEzZDc2N2JhYzRkY2RmNjQ2Mg== Feb 09 19:25:18 volumio volumio[900]: STREAMING PROXY: Got range request: bytes=14485264- Feb 09 19:25:18 volumio volumio[900]: STREAMING PROXY: Response: 206, length: 40379151 Feb 09 19:25:20 volumio volumio[900]: info: CoreCommandRouter::volumioNext Feb 09 19:25:20 volumio volumio[900]: info: CoreStateMachine::next Feb 09 19:25:20 volumio volumio[900]: info: [1770661520869] ControllerTidal::next Feb 09 19:25:20 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:25:20 volumio volumio[900]: info: CoreStateMachine::next Feb 09 19:25:20 volumio volumio[900]: info: CoreStateMachine::stop Feb 09 19:25:20 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:25:20 volumio volumio[900]: info: CoreStateMachine::stPlaybackTimer Feb 09 19:25:20 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:25:20 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:25:20 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:20 volumio volumio[900]: info: CorePlayQueue::getTrack 4 Feb 09 19:25:20 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:20 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:20 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:20 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:20 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:20 volumio volumio[900]: info: CorePlayQueue::getTrack 4 Feb 09 19:25:20 volumio volumio[900]: info: CoreStateMachine::serviceStop Feb 09 19:25:20 volumio volumio[900]: info: CorePlayQueue::getTrack 4 Feb 09 19:25:20 volumio volumio[900]: info: CoreCommandRouter::serviceStop Feb 09 19:25:20 volumio volumio[900]: info: [1770661520875] ControllerTidal::stop Feb 09 19:25:20 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:25:20 volumio volumio[900]: info: ControllerMpd::stop Feb 09 19:25:20 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand stop Feb 09 19:25:20 volumio volumio[900]: STREAMING PROXY: Client dropped request, destroying Feb 09 19:25:20 volumio volumio[900]: info: Feb 09 19:25:20 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:25:20 volumio volumio[900]: info: sendMpdCommand stop took 14 milliseconds Feb 09 19:25:20 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:25:20 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:25:20 volumio volumio[900]: info: CoreStateMachine::play index undefined Feb 09 19:25:20 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:25:20 volumio volumio[900]: info: CorePlayQueue::getTrack 5 Feb 09 19:25:20 volumio volumio[900]: info: CoreStateMachine::startPlaybackTimer Feb 09 19:25:20 volumio volumio[900]: info: CorePlayQueue::getTrack 5 Feb 09 19:25:20 volumio volumio[900]: info: [1770661520891] ControllerTidal::clearAddPlayTrack Feb 09 19:25:20 volumio volumio[900]: info: Getting stream with soundQuality HI_RES Feb 09 19:25:20 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand stop Feb 09 19:25:20 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:25:20 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:25:20 volumio volumio[900]: info: sendMpdCommand status took 2 milliseconds Feb 09 19:25:20 volumio volumio[900]: info: sendMpdCommand stop took 1 milliseconds Feb 09 19:25:20 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:25:20 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:25:20 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand clear Feb 09 19:25:20 volumio volumio[900]: info: Feb 09 19:25:20 volumio volumio[900]: ---------------------------- MPD announces system playlist update Feb 09 19:25:20 volumio volumio[900]: info: Ignoring MPD Status Update Feb 09 19:25:20 volumio volumio[900]: info: sendMpdCommand playlistinfo took 3 milliseconds Feb 09 19:25:20 volumio volumio[900]: info: sendMpdCommand clear took 3 milliseconds Feb 09 19:25:20 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:25:20 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/208770799&soundQuality=HI_RES" Feb 09 19:25:20 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:25:20 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:25:20 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:20 volumio volumio[900]: info: CorePlayQueue::getTrack 5 Feb 09 19:25:20 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:20 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:20 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:20 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:20 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:20 volumio volumio[900]: info: CorePlayQueue::getTrack 5 Feb 09 19:25:20 volumio volumio[900]: info: CorePlayQueue::getTrack 5 Feb 09 19:25:20 volumio volumio[900]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Feb 09 19:25:20 volumio volumio[900]: info: ------------------------------ 19ms Feb 09 19:25:20 volumio volumio[900]: error: updateQueue error: null Feb 09 19:25:20 volumio volumio[900]: info: Feb 09 19:25:20 volumio volumio[900]: ---------------------------- MPD announces system playlist update Feb 09 19:25:20 volumio volumio[900]: info: Ignoring MPD Status Update Feb 09 19:25:20 volumio volumio[900]: info: ------------------------------ 16ms Feb 09 19:25:20 volumio volumio[900]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/208770799&soundQuality=HI_RES" took 14 milliseconds Feb 09 19:25:20 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:25:20 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand play Feb 09 19:25:20 volumio volumio[900]: STREAMING PROXY: Handling url /?data=tidal://song/208770799&soundQuality=HI_RES Feb 09 19:25:20 volumio volumio[900]: info: ------------------------------ 6ms Feb 09 19:25:20 volumio volumio[900]: info: sendMpdCommand play took 6 milliseconds Feb 09 19:25:20 volumio volumio[900]: info: Executing endpoint getStreamUrltidal Feb 09 19:25:20 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 09 19:25:21 volumio volumio[900]: info: getStreamUrl took 357 milliseconds Feb 09 19:25:21 volumio volumio[900]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidiOWYyNDdlOTk1NDg0MTA0NGVmN2Y5ZWZmOTI1NDg2MF82MS5tcDQ/0.flac?token=1770665121~ODljN2QwYzJhNTc2ZTkxYzcyYWQ4MWY1MDBjODc4OWQ4ZTNjMjZlMQ== Feb 09 19:25:21 volumio volumio[900]: STREAMING PROXY: Response: 200, length: 37364329 Feb 09 19:25:21 volumio volumio[900]: info: Feb 09 19:25:21 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:25:21 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:25:21 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:25:21 volumio volumio[900]: info: Feb 09 19:25:21 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:25:21 volumio volumio[900]: info: sendMpdCommand status took 1 milliseconds Feb 09 19:25:21 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:25:21 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:25:21 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:25:21 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:25:21 volumio volumio[900]: info: sendMpdCommand status took 1 milliseconds Feb 09 19:25:21 volumio volumio[900]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 09 19:25:21 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:25:21 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:25:21 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:25:21 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:25:21 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:25:21 volumio volumio[900]: info: CorePlayQueue::getTrack 5 Feb 09 19:25:21 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":364,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"208770799&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/208770799&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:25:21 volumio volumio[900]: verbose: CURRENT POSITION 5 Feb 09 19:25:21 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:25:21 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus stop Feb 09 19:25:21 volumio volumio[900]: info: ------------------------------ 6ms Feb 09 19:25:21 volumio volumio[900]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 09 19:25:21 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:25:21 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:25:21 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:25:21 volumio volumio[900]: info: CorePlayQueue::getTrack 5 Feb 09 19:25:21 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":364,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"208770799&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/208770799&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:25:21 volumio volumio[900]: verbose: CURRENT POSITION 5 Feb 09 19:25:21 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:25:21 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus play Feb 09 19:25:21 volumio volumio[900]: info: Received an update from plugin. extracting info from payload Feb 09 19:25:21 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:21 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:21 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:21 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:21 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:21 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:21 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:21 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:21 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:21 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:21 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:21 volumio volumio[900]: info: ------------------------------ 27ms Feb 09 19:25:25 volumio volumio[900]: info: CoreCommandRouter::volumioSeek Feb 09 19:25:25 volumio volumio[900]: info: CoreStateMachine::seek Feb 09 19:25:25 volumio volumio[900]: info: CorePlayQueue::getTrack 5 Feb 09 19:25:25 volumio volumio[900]: info: TRACKBLOCK {"album":"ALIVE in Amsterdam (Live)","albumUri":"tidal://album/208770785","albumart":"https://resources.tidal.com/images/db59648b/760f/4298/9d28/a586db9d110d/640x640.jpg","artist":"Walter Trout","artistUri":"tidal://artist/3603309","audioQuality":"LOSSLESS","bitdepth":"16 bit","duration":364,"explicit":false,"name":"Marie's Mood","samplerate":"44.1 KHz","service":"tidal","title":"Marie's Mood","trackType":"tidal","tracknumber":4,"type":"track","uri":"tidal://song/208770799","volumeNumber":2} Feb 09 19:25:25 volumio volumio[900]: info: CoreStateMachine::startPlaybackTimer Feb 09 19:25:25 volumio volumio[900]: info: CorePlayQueue::getTrack 5 Feb 09 19:25:25 volumio volumio[900]: info: [1770661525572] ControllerTidal::seek Feb 09 19:25:25 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:25:25 volumio volumio[900]: info: ControllerMpd::seek Feb 09 19:25:25 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:25 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:25 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:25 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:25 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:25 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:25 volumio volumio[900]: error: null Feb 09 19:25:25 volumio volumio[900]: info: Feb 09 19:25:25 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:25:25 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:25:25 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:25:25 volumio volumio[900]: info: sendMpdCommand status took 4 milliseconds Feb 09 19:25:25 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:25:25 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:25:25 volumio volumio[900]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 09 19:25:25 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:25:25 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:25:25 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:25:25 volumio volumio[900]: info: CorePlayQueue::getTrack 5 Feb 09 19:25:25 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":105098,"duration":364,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"697 Kbps","isStreaming":false,"title":"208770799&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/208770799&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:25:25 volumio volumio[900]: verbose: CURRENT POSITION 5 Feb 09 19:25:25 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:25:25 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus play Feb 09 19:25:25 volumio volumio[900]: info: Received an update from plugin. extracting info from payload Feb 09 19:25:25 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:25 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:25 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:25 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:25 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:25 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:25 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:25 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:25 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:25 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:25 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:25 volumio volumio[900]: info: ------------------------------ 29ms Feb 09 19:25:26 volumio volumio[900]: STREAMING PROXY: Client dropped request, destroying Feb 09 19:25:27 volumio volumio[900]: info: CoreCommandRouter::volumioNext Feb 09 19:25:27 volumio volumio[900]: info: CoreStateMachine::next Feb 09 19:25:27 volumio volumio[900]: info: [1770661527850] ControllerTidal::next Feb 09 19:25:27 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:25:27 volumio volumio[900]: info: CoreStateMachine::next Feb 09 19:25:27 volumio volumio[900]: info: CoreStateMachine::stop Feb 09 19:25:27 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:25:27 volumio volumio[900]: info: CoreStateMachine::stPlaybackTimer Feb 09 19:25:27 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:25:27 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:25:27 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:27 volumio volumio[900]: info: CorePlayQueue::getTrack 5 Feb 09 19:25:27 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:27 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:27 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:27 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:27 volumio volumio[900]: info: CorePlayQueue::getTrack 5 Feb 09 19:25:27 volumio volumio[900]: info: CoreStateMachine::serviceStop Feb 09 19:25:27 volumio volumio[900]: info: CorePlayQueue::getTrack 5 Feb 09 19:25:27 volumio volumio[900]: info: CoreCommandRouter::serviceStop Feb 09 19:25:27 volumio volumio[900]: info: [1770661527856] ControllerTidal::stop Feb 09 19:25:27 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:25:27 volumio volumio[900]: info: ControllerMpd::stop Feb 09 19:25:27 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand stop Feb 09 19:25:27 volumio volumio[900]: info: Feb 09 19:25:27 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:25:27 volumio volumio[900]: info: sendMpdCommand stop took 17 milliseconds Feb 09 19:25:27 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:25:27 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:25:27 volumio volumio[900]: info: CoreStateMachine::play index undefined Feb 09 19:25:27 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 09 19:25:27 volumio volumio[900]: info: CorePlayQueue::getTrack 6 Feb 09 19:25:27 volumio volumio[900]: info: CoreStateMachine::startPlaybackTimer Feb 09 19:25:27 volumio volumio[900]: info: CorePlayQueue::getTrack 6 Feb 09 19:25:27 volumio volumio[900]: info: [1770661527874] ControllerTidal::clearAddPlayTrack Feb 09 19:25:27 volumio volumio[900]: info: Getting stream with soundQuality HI_RES Feb 09 19:25:27 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand stop Feb 09 19:25:27 volumio volumio[900]: info: CoreStateMachine::updateTrackBlock Feb 09 19:25:27 volumio volumio[900]: info: CorePlayQueue::getTrackBlock Feb 09 19:25:27 volumio volumio[900]: info: sendMpdCommand status took 2 milliseconds Feb 09 19:25:27 volumio volumio[900]: info: sendMpdCommand stop took 1 milliseconds Feb 09 19:25:27 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:25:27 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:25:27 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand clear Feb 09 19:25:27 volumio volumio[900]: info: Feb 09 19:25:27 volumio volumio[900]: ---------------------------- MPD announces system playlist update Feb 09 19:25:27 volumio volumio[900]: info: Ignoring MPD Status Update Feb 09 19:25:27 volumio volumio[900]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 09 19:25:27 volumio volumio[900]: info: sendMpdCommand clear took 0 milliseconds Feb 09 19:25:27 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:25:27 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/29280710&soundQuality=HI_RES" Feb 09 19:25:27 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:25:27 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:25:27 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:27 volumio volumio[900]: info: CorePlayQueue::getTrack 6 Feb 09 19:25:27 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:27 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:27 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:27 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:27 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:27 volumio volumio[900]: info: CorePlayQueue::getTrack 6 Feb 09 19:25:27 volumio volumio[900]: info: CorePlayQueue::getTrack 6 Feb 09 19:25:27 volumio volumio[900]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Feb 09 19:25:27 volumio volumio[900]: info: ------------------------------ 16ms Feb 09 19:25:27 volumio volumio[900]: error: updateQueue error: null Feb 09 19:25:27 volumio volumio[900]: info: Feb 09 19:25:27 volumio volumio[900]: ---------------------------- MPD announces system playlist update Feb 09 19:25:27 volumio volumio[900]: info: Ignoring MPD Status Update Feb 09 19:25:27 volumio volumio[900]: info: ------------------------------ 14ms Feb 09 19:25:27 volumio volumio[900]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/29280710&soundQuality=HI_RES" took 13 milliseconds Feb 09 19:25:27 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:25:27 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand play Feb 09 19:25:27 volumio volumio[900]: STREAMING PROXY: Handling url /?data=tidal://song/29280710&soundQuality=HI_RES Feb 09 19:25:27 volumio volumio[900]: info: ------------------------------ 5ms Feb 09 19:25:27 volumio volumio[900]: info: sendMpdCommand play took 5 milliseconds Feb 09 19:25:27 volumio volumio[900]: info: Executing endpoint getStreamUrltidal Feb 09 19:25:27 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 09 19:25:28 volumio volumio[900]: info: getStreamUrl took 299 milliseconds Feb 09 19:25:28 volumio volumio[900]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidlNjMyYThhNWNlZjcxNjcxZGFjNTZjMDZhNTZkNTdkMl82Mi5tcDQ/0.flac?token=1770665128~NzA2MThlNWY5ZTc0MmYzODhjZWFjZjIwNzE4M2ZjN2RhNDkyYTM0ZA== Feb 09 19:25:28 volumio volumio[900]: STREAMING PROXY: Response: 200, length: 87834547 Feb 09 19:25:28 volumio volumio[900]: info: Feb 09 19:25:28 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:25:28 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:25:28 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:25:28 volumio volumio[900]: info: sendMpdCommand status took 4 milliseconds Feb 09 19:25:28 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:25:28 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:25:28 volumio volumio[900]: info: Feb 09 19:25:28 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:25:28 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:25:28 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:25:28 volumio volumio[900]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 09 19:25:28 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:25:28 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:25:28 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:25:28 volumio volumio[900]: info: CorePlayQueue::getTrack 6 Feb 09 19:25:28 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":248,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"29280710&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/29280710&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:25:28 volumio volumio[900]: verbose: CURRENT POSITION 6 Feb 09 19:25:28 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:25:28 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus stop Feb 09 19:25:28 volumio volumio[900]: info: ------------------------------ 7ms Feb 09 19:25:28 volumio volumio[900]: info: sendMpdCommand status took 2 milliseconds Feb 09 19:25:28 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:25:28 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:25:28 volumio volumio[900]: info: sendMpdCommand playlistinfo took 1 milliseconds Feb 09 19:25:28 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:25:28 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:25:28 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:25:28 volumio volumio[900]: info: CorePlayQueue::getTrack 6 Feb 09 19:25:28 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":248,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"29280710&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/29280710&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:25:28 volumio volumio[900]: verbose: CURRENT POSITION 6 Feb 09 19:25:28 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:25:28 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus play Feb 09 19:25:28 volumio volumio[900]: info: Received an update from plugin. extracting info from payload Feb 09 19:25:28 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:28 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:28 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:28 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:28 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:28 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:28 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:28 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:28 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:28 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:28 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:28 volumio volumio[900]: info: ------------------------------ 27ms Feb 09 19:25:30 volumio volumio[900]: info: CoreCommandRouter::volumioSeek Feb 09 19:25:30 volumio volumio[900]: info: CoreStateMachine::seek Feb 09 19:25:30 volumio volumio[900]: info: CorePlayQueue::getTrack 6 Feb 09 19:25:30 volumio volumio[900]: info: TRACKBLOCK {"album":"Moonflower","albumUri":"tidal://album/29280699","albumart":"https://resources.tidal.com/images/8659c5f2/29a1/4122/829a/06dd848324ff/640x640.jpg","artist":"Santana","artistUri":"tidal://artist/74","audioQuality":"LOSSLESS","bitdepth":"16 bit","duration":248,"explicit":false,"name":"She's Not There","samplerate":"44.1 KHz","service":"tidal","title":"She's Not There","trackType":"tidal","tracknumber":1,"type":"track","uri":"tidal://song/29280710","volumeNumber":2} Feb 09 19:25:30 volumio volumio[900]: info: CoreStateMachine::startPlaybackTimer Feb 09 19:25:30 volumio volumio[900]: info: CorePlayQueue::getTrack 6 Feb 09 19:25:30 volumio volumio[900]: info: [1770661530430] ControllerTidal::seek Feb 09 19:25:30 volumio volumio[900]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 09 19:25:30 volumio volumio[900]: info: ControllerMpd::seek Feb 09 19:25:30 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:30 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:30 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:30 volumio volumio[900]: STREAMING PROXY: Client dropped request, destroying Feb 09 19:25:30 volumio volumio[900]: STREAMING PROXY: Handling url /?data=tidal://song/29280710&soundQuality=HI_RES Feb 09 19:25:30 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:30 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:30 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:30 volumio volumio[900]: info: Executing endpoint getStreamUrltidal Feb 09 19:25:30 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 09 19:25:31 volumio volumio[900]: info: getStreamUrl took 894 milliseconds Feb 09 19:25:31 volumio volumio[900]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidlNjMyYThhNWNlZjcxNjcxZGFjNTZjMDZhNTZkNTdkMl82Mi5tcDQ/0.flac?token=1770665128~NzA2MThlNWY5ZTc0MmYzODhjZWFjZjIwNzE4M2ZjN2RhNDkyYTM0ZA== Feb 09 19:25:31 volumio volumio[900]: STREAMING PROXY: Got range request: bytes=26892745- Feb 09 19:25:31 volumio volumio[900]: STREAMING PROXY: Response: 206, length: 60941802 Feb 09 19:25:31 volumio volumio[900]: error: null Feb 09 19:25:31 volumio volumio[900]: info: Feb 09 19:25:31 volumio volumio[900]: ---------------------------- MPD announces state update: player Feb 09 19:25:31 volumio volumio[900]: info: ControllerMpd::getState Feb 09 19:25:31 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand status Feb 09 19:25:31 volumio volumio[900]: info: sendMpdCommand status took 0 milliseconds Feb 09 19:25:31 volumio volumio[900]: verbose: ControllerMpd::parseState Feb 09 19:25:31 volumio volumio[900]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 09 19:25:31 volumio volumio[900]: info: sendMpdCommand playlistinfo took 0 milliseconds Feb 09 19:25:31 volumio volumio[900]: verbose: ControllerMpd::parseTrackInfo Feb 09 19:25:31 volumio volumio[900]: info: ControllerMpd::pushState Feb 09 19:25:31 volumio volumio[900]: info: CoreCommandRouter::servicePushState Feb 09 19:25:31 volumio volumio[900]: info: CorePlayQueue::getTrack 6 Feb 09 19:25:31 volumio volumio[900]: verbose: STATE SERVICE {"status":"play","position":0,"seek":78000,"duration":248,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2494 Kbps","isStreaming":false,"title":"29280710&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/29280710&soundQuality=HI_RES","trackType":"tidal"} Feb 09 19:25:31 volumio volumio[900]: verbose: CURRENT POSITION 6 Feb 09 19:25:31 volumio volumio[900]: info: CoreStateMachine::syncState stateService play Feb 09 19:25:31 volumio volumio[900]: info: CoreStateMachine::syncState currentStatus play Feb 09 19:25:31 volumio volumio[900]: info: Received an update from plugin. extracting info from payload Feb 09 19:25:31 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:31 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 09 19:25:31 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:31 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:31 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:31 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:31 volumio volumio[900]: info: CoreStateMachine::pushState Feb 09 19:25:31 volumio volumio[900]: info: CoreCommandRouter::volumioPushState Feb 09 19:25:31 volumio volumio[900]: info: MRS: Pushing multiroomSync output update for this device Feb 09 19:25:31 volumio volumio[900]: info: MRS: Pushing multiroomSync output Feb 09 19:25:31 volumio volumio[900]: info: CoreCommandRouter::volumioGetState Feb 09 19:25:31 volumio volumio[900]: info: ------------------------------ 23ms Feb 09 19:25:39 volumio volumio[900]: STREAMING PROXY: Client dropped request, destroying Feb 09 19:25:39 volumio volumio[900]: STREAMING PROXY: Handling url /?data=tidal://song/29280710&soundQuality=HI_RES Feb 09 19:25:39 volumio volumio[900]: info: Executing endpoint getStreamUrltidal Feb 09 19:25:39 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Feb 09 19:25:39 volumio volumio[900]: info: getStreamUrl took 344 milliseconds Feb 09 19:25:39 volumio volumio[900]: STREAMING PROXY: Got real url: http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEidlNjMyYThhNWNlZjcxNjcxZGFjNTZjMDZhNTZkNTdkMl82Mi5tcDQ/0.flac?token=1770665128~NzA2MThlNWY5ZTc0MmYzODhjZWFjZjIwNzE4M2ZjN2RhNDkyYTM0ZA== Feb 09 19:25:39 volumio volumio[900]: STREAMING PROXY: Got range request: bytes=15592145- Feb 09 19:25:39 volumio volumio[900]: STREAMING PROXY: Response: 206, length: 72242402 Feb 09 19:25:41 volumio volumio[900]: STREAMING PROXY: Client dropped request, destroying Feb 09 19:25:43 volumio volumio[900]: Searching all installed plugins Feb 09 19:25:43 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 09 19:25:43 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: , search Feb 09 19:25:43 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: mpd , search Feb 09 19:25:43 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Feb 09 19:25:43 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Feb 09 19:25:43 volumio volumio[900]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Feb 09 19:25:43 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: webradio , search Feb 09 19:25:43 volumio volumio[900]: info: CoreCommandRouter::executeOnPlugin: tidal , search Feb 09 19:25:43 volumio volumio[900]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 19:25:43 volumio volumio[900]: Error: connect ETIMEDOUT 146.75.122.53:443 Feb 09 19:25:43 volumio volumio[900]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Feb 09 19:25:43 volumio volumio[900]: errno: -110, Feb 09 19:25:43 volumio volumio[900]: code: 'ETIMEDOUT', Feb 09 19:25:43 volumio volumio[900]: syscall: 'connect', Feb 09 19:25:43 volumio volumio[900]: address: '146.75.122.53', Feb 09 19:25:43 volumio volumio[900]: port: 443 Feb 09 19:25:43 volumio volumio[900]: } Feb 09 19:25:43 volumio volumio[900]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 09 19:25:43 volumio sudo[2972]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-09 19:24 Feb 09 19:25:43 volumio sudo[2972]: 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="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 05:43:24 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="15d0241b0cd805792809f3ddf4a0fc4e"