-- Logs begin at Mon 2025-05-12 17:46:50 CEST, end at Mon 2025-05-12 19:22:08 CEST. -- May 12 19:21:00 volumio volumio[1239]: info: CoreCommandRouter::volumioSeek May 12 19:21:00 volumio volumio[1239]: info: CoreStateMachine::seek May 12 19:21:00 volumio volumio[1239]: info: CorePlayQueue::getTrack 33 May 12 19:21:00 volumio volumio[1239]: info: TRACKBLOCK {"album":"Five Years (1969 - 1973)","albumUri":"tidal://album/68729538","albumart":"https://resources.tidal.com/images/146c89fd/3cb8/4a51/9818/c553a3f533a3/640x640.jpg","artist":"David Bowie","artistUri":"tidal://artist/4768","audioQuality":"LOSSLESS","bitdepth":"16 bit","duration":178,"explicit":false,"name":"It Ain't Easy (2012 Remaster)","samplerate":"44.1 KHz","service":"tidal","title":"It Ain't Easy (2012 Remaster)","trackType":"tidal","tracknumber":5,"type":"track","uri":"tidal://song/68729572","volumeNumber":4} May 12 19:21:00 volumio volumio[1239]: info: CoreStateMachine::startPlaybackTimer May 12 19:21:00 volumio volumio[1239]: info: CorePlayQueue::getTrack 33 May 12 19:21:00 volumio volumio[1239]: info: [1747070460134] ControllerTidal::seek May 12 19:21:00 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 19:21:00 volumio volumio[1239]: info: ControllerMpd::seek May 12 19:21:00 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:00 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:00 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:00 volumio volumio[1239]: error: null May 12 19:21:00 volumio volumio[1239]: info: May 12 19:21:00 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:00 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:00 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:00 volumio volumio[1239]: info: sendMpdCommand status took 21 milliseconds May 12 19:21:00 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:00 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:00 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 7 milliseconds May 12 19:21:00 volumio volumio[1239]: verbose: ControllerMpd::parseTrackInfo May 12 19:21:00 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:00 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:00 volumio volumio[1239]: info: CorePlayQueue::getTrack 33 May 12 19:21:00 volumio volumio[1239]: verbose: STATE SERVICE {"status":"play","position":0,"seek":33000,"duration":178,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"738 Kbps","isStreaming":false,"title":"68729572&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/68729572&soundQuality=LOSSLESS","trackType":"tidal"} May 12 19:21:00 volumio volumio[1239]: verbose: CURRENT POSITION 33 May 12 19:21:00 volumio volumio[1239]: info: CoreStateMachine::syncState stateService play May 12 19:21:00 volumio volumio[1239]: info: CoreStateMachine::syncState currentStatus play May 12 19:21:00 volumio volumio[1239]: info: Received an update from plugin. extracting info from payload May 12 19:21:00 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:00 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:00 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:00 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:00 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:00 volumio volumio[1239]: info: ------------------------------ 89ms May 12 19:21:00 volumio volumio[1239]: STREAMING PROXY: Client dropped request, destroying May 12 19:21:01 volumio volumio[1239]: info: CoreCommandRouter::volumioNext May 12 19:21:01 volumio volumio[1239]: info: CoreStateMachine::next May 12 19:21:01 volumio volumio[1239]: info: [1747070461648] ControllerTidal::next May 12 19:21:01 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 19:21:01 volumio volumio[1239]: info: CoreStateMachine::next May 12 19:21:01 volumio volumio[1239]: info: CoreStateMachine::stop May 12 19:21:01 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 19:21:01 volumio volumio[1239]: info: CoreStateMachine::stPlaybackTimer May 12 19:21:01 volumio volumio[1239]: info: CoreStateMachine::updateTrackBlock May 12 19:21:01 volumio volumio[1239]: info: CorePlayQueue::getTrackBlock May 12 19:21:01 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:01 volumio volumio[1239]: info: CorePlayQueue::getTrack 33 May 12 19:21:01 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:01 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:01 volumio volumio[1239]: info: CoreStateMachine::serviceStop May 12 19:21:01 volumio volumio[1239]: info: CorePlayQueue::getTrack 33 May 12 19:21:01 volumio volumio[1239]: info: CoreCommandRouter::serviceStop May 12 19:21:01 volumio volumio[1239]: info: [1747070461655] ControllerTidal::stop May 12 19:21:01 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 19:21:01 volumio volumio[1239]: info: ControllerMpd::stop May 12 19:21:01 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand stop May 12 19:21:01 volumio volumio[1239]: info: May 12 19:21:01 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:01 volumio volumio[1239]: info: sendMpdCommand stop took 19 milliseconds May 12 19:21:01 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:01 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:01 volumio volumio[1239]: info: CoreStateMachine::play index undefined May 12 19:21:01 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 19:21:01 volumio volumio[1239]: info: CorePlayQueue::getTrack 34 May 12 19:21:01 volumio volumio[1239]: info: CoreStateMachine::startPlaybackTimer May 12 19:21:01 volumio volumio[1239]: info: CorePlayQueue::getTrack 34 May 12 19:21:01 volumio volumio[1239]: info: [1747070461680] ControllerTidal::clearAddPlayTrack May 12 19:21:01 volumio volumio[1239]: info: Getting stream with soundQuality LOSSLESS May 12 19:21:01 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand stop May 12 19:21:01 volumio volumio[1239]: info: CoreStateMachine::updateTrackBlock May 12 19:21:01 volumio volumio[1239]: info: CorePlayQueue::getTrackBlock May 12 19:21:01 volumio volumio[1239]: info: sendMpdCommand status took 14 milliseconds May 12 19:21:01 volumio volumio[1239]: info: sendMpdCommand stop took 8 milliseconds May 12 19:21:01 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:01 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:01 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand clear May 12 19:21:01 volumio volumio[1239]: info: May 12 19:21:01 volumio volumio[1239]: ---------------------------- MPD announces system playlist update May 12 19:21:01 volumio volumio[1239]: info: Ignoring MPD Status Update May 12 19:21:01 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 2 milliseconds May 12 19:21:01 volumio volumio[1239]: info: sendMpdCommand clear took 3 milliseconds May 12 19:21:01 volumio volumio[1239]: verbose: ControllerMpd::parseTrackInfo May 12 19:21:01 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/68729573&soundQuality=LOSSLESS" May 12 19:21:01 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:01 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:01 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:01 volumio volumio[1239]: info: CorePlayQueue::getTrack 34 May 12 19:21:01 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:01 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:01 volumio volumio[1239]: info: CorePlayQueue::getTrack 34 May 12 19:21:01 volumio volumio[1239]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 12 19:21:01 volumio volumio[1239]: info: ------------------------------ 55ms May 12 19:21:01 volumio volumio[1239]: error: updateQueue error: null May 12 19:21:01 volumio volumio[1239]: info: May 12 19:21:01 volumio volumio[1239]: ---------------------------- MPD announces system playlist update May 12 19:21:01 volumio volumio[1239]: info: Ignoring MPD Status Update May 12 19:21:01 volumio volumio[1239]: info: ------------------------------ 41ms May 12 19:21:01 volumio volumio[1239]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/68729573&soundQuality=LOSSLESS" took 38 milliseconds May 12 19:21:01 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 19:21:01 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand play May 12 19:21:01 volumio volumio[1239]: STREAMING PROXY: Handling url /?data=tidal://song/68729573&soundQuality=LOSSLESS May 12 19:21:01 volumio volumio[1239]: info: ------------------------------ 8ms May 12 19:21:01 volumio volumio[1239]: info: sendMpdCommand play took 13 milliseconds May 12 19:21:01 volumio volumio[1239]: info: Executing endpoint getStreamUrltidal May 12 19:21:01 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI May 12 19:21:02 volumio volumio[1239]: info: getStreamUrl took 295 milliseconds May 12 19:21:02 volumio volumio[1239]: STREAMING PROXY: Got real url: http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKwgDEic5ZmM5NzhhN2QyMWM5MmJhNWZkM2Q3YzNjMzdlYWVmMl82MS5tcDQ/0.flac?token=1747074061~ZjgxYjg4ZTFmODFiMmJkMzUxZGY3YTNhYjFiNWE3YjBlYWRiY2Y3YQ== May 12 19:21:02 volumio volumio[1239]: STREAMING PROXY: Response: 200, length: 19353667 May 12 19:21:02 volumio volumio[1239]: info: May 12 19:21:02 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:02 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:02 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:02 volumio volumio[1239]: info: May 12 19:21:02 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:02 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:02 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:02 volumio volumio[1239]: info: sendMpdCommand status took 1 milliseconds May 12 19:21:02 volumio volumio[1239]: info: sendMpdCommand status took 1 milliseconds May 12 19:21:02 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:02 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:02 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:02 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:02 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 19:21:02 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 19:21:02 volumio volumio[1239]: verbose: ControllerMpd::parseTrackInfo May 12 19:21:02 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:02 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:02 volumio volumio[1239]: info: CorePlayQueue::getTrack 34 May 12 19:21:02 volumio volumio[1239]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":201,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"68729573&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/68729573&soundQuality=LOSSLESS","trackType":"tidal"} May 12 19:21:02 volumio volumio[1239]: verbose: CURRENT POSITION 34 May 12 19:21:02 volumio volumio[1239]: info: CoreStateMachine::syncState stateService play May 12 19:21:02 volumio volumio[1239]: info: CoreStateMachine::syncState currentStatus stop May 12 19:21:02 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:02 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:02 volumio volumio[1239]: info: CorePlayQueue::getTrack 34 May 12 19:21:02 volumio volumio[1239]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":201,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"68729573&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/68729573&soundQuality=LOSSLESS","trackType":"tidal"} May 12 19:21:02 volumio volumio[1239]: verbose: CURRENT POSITION 34 May 12 19:21:02 volumio volumio[1239]: info: CoreStateMachine::syncState stateService play May 12 19:21:02 volumio volumio[1239]: info: CoreStateMachine::syncState currentStatus play May 12 19:21:02 volumio volumio[1239]: info: Received an update from plugin. extracting info from payload May 12 19:21:02 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:02 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:02 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:02 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:02 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:02 volumio volumio[1239]: info: ------------------------------ 11ms May 12 19:21:02 volumio volumio[1239]: info: ------------------------------ 13ms May 12 19:21:04 volumio volumio[1239]: info: CoreCommandRouter::volumioSeek May 12 19:21:04 volumio volumio[1239]: info: CoreStateMachine::seek May 12 19:21:04 volumio volumio[1239]: info: CorePlayQueue::getTrack 34 May 12 19:21:04 volumio volumio[1239]: info: TRACKBLOCK {"album":"Five Years (1969 - 1973)","albumUri":"tidal://album/68729538","albumart":"https://resources.tidal.com/images/146c89fd/3cb8/4a51/9818/c553a3f533a3/640x640.jpg","artist":"David Bowie","artistUri":"tidal://artist/4768","audioQuality":"LOSSLESS","bitdepth":"16 bit","duration":201,"explicit":false,"name":"Lady Stardust (2012 Remaster)","samplerate":"44.1 KHz","service":"tidal","title":"Lady Stardust (2012 Remaster)","trackType":"tidal","tracknumber":6,"type":"track","uri":"tidal://song/68729573","volumeNumber":4} May 12 19:21:04 volumio volumio[1239]: info: CoreStateMachine::startPlaybackTimer May 12 19:21:04 volumio volumio[1239]: info: CorePlayQueue::getTrack 34 May 12 19:21:04 volumio volumio[1239]: info: [1747070464079] ControllerTidal::seek May 12 19:21:04 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 19:21:04 volumio volumio[1239]: info: ControllerMpd::seek May 12 19:21:04 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:04 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:04 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:04 volumio volumio[1239]: error: null May 12 19:21:04 volumio volumio[1239]: info: May 12 19:21:04 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:04 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:04 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:04 volumio volumio[1239]: info: sendMpdCommand status took 1 milliseconds May 12 19:21:04 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:04 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:04 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 19:21:04 volumio volumio[1239]: verbose: ControllerMpd::parseTrackInfo May 12 19:21:04 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:04 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:04 volumio volumio[1239]: info: CorePlayQueue::getTrack 34 May 12 19:21:04 volumio volumio[1239]: verbose: STATE SERVICE {"status":"play","position":0,"seek":38000,"duration":201,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"521 Kbps","isStreaming":false,"title":"68729573&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/68729573&soundQuality=LOSSLESS","trackType":"tidal"} May 12 19:21:04 volumio volumio[1239]: verbose: CURRENT POSITION 34 May 12 19:21:04 volumio volumio[1239]: info: CoreStateMachine::syncState stateService play May 12 19:21:04 volumio volumio[1239]: info: CoreStateMachine::syncState currentStatus play May 12 19:21:04 volumio volumio[1239]: info: Received an update from plugin. extracting info from payload May 12 19:21:04 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:04 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:04 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:04 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:04 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:04 volumio volumio[1239]: info: ------------------------------ 23ms May 12 19:21:04 volumio volumio[1239]: STREAMING PROXY: Client dropped request, destroying May 12 19:21:05 volumio volumio[1239]: info: Executing endpoint metavolumio May 12 19:21:05 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 19:21:05 volumio volumio[1239]: info: Executing endpoint metavolumio May 12 19:21:05 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 19:21:16 volumio volumio[1239]: info: CoreCommandRouter::volumioSeek May 12 19:21:16 volumio volumio[1239]: info: CoreStateMachine::seek May 12 19:21:16 volumio volumio[1239]: info: CorePlayQueue::getTrack 34 May 12 19:21:16 volumio volumio[1239]: info: TRACKBLOCK {"album":"Five Years (1969 - 1973)","albumUri":"tidal://album/68729538","albumart":"https://resources.tidal.com/images/146c89fd/3cb8/4a51/9818/c553a3f533a3/640x640.jpg","artist":"David Bowie","artistUri":"tidal://artist/4768","audioQuality":"LOSSLESS","bitdepth":"16 bit","duration":201,"explicit":false,"name":"Lady Stardust (2012 Remaster)","samplerate":"44.1 KHz","service":"tidal","title":"Lady Stardust (2012 Remaster)","trackType":"tidal","tracknumber":6,"type":"track","uri":"tidal://song/68729573","volumeNumber":4} May 12 19:21:16 volumio volumio[1239]: info: CoreStateMachine::startPlaybackTimer May 12 19:21:16 volumio volumio[1239]: info: CorePlayQueue::getTrack 34 May 12 19:21:16 volumio volumio[1239]: info: [1747070476195] ControllerTidal::seek May 12 19:21:16 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 19:21:16 volumio volumio[1239]: info: ControllerMpd::seek May 12 19:21:16 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:16 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:16 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:16 volumio volumio[1239]: error: null May 12 19:21:16 volumio volumio[1239]: info: May 12 19:21:16 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:16 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:16 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:16 volumio volumio[1239]: info: sendMpdCommand status took 6 milliseconds May 12 19:21:16 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:16 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:16 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 0 milliseconds May 12 19:21:16 volumio volumio[1239]: verbose: ControllerMpd::parseTrackInfo May 12 19:21:16 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:16 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:16 volumio volumio[1239]: info: CorePlayQueue::getTrack 34 May 12 19:21:16 volumio volumio[1239]: verbose: STATE SERVICE {"status":"play","position":0,"seek":73000,"duration":201,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"898 Kbps","isStreaming":false,"title":"68729573&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/68729573&soundQuality=LOSSLESS","trackType":"tidal"} May 12 19:21:16 volumio volumio[1239]: verbose: CURRENT POSITION 34 May 12 19:21:16 volumio volumio[1239]: info: CoreStateMachine::syncState stateService play May 12 19:21:16 volumio volumio[1239]: info: CoreStateMachine::syncState currentStatus play May 12 19:21:16 volumio volumio[1239]: info: Received an update from plugin. extracting info from payload May 12 19:21:16 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:16 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:16 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:16 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:16 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:16 volumio volumio[1239]: info: ------------------------------ 17ms May 12 19:21:16 volumio volumio[1239]: info: VolumeController::SetAlsaVolume74 May 12 19:21:16 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:16 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:16 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:16 volumio volumio[1239]: info: VolumeController::SetAlsaVolume75 May 12 19:21:16 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:16 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:16 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:16 volumio volumio[1239]: info: VolumeController::SetAlsaVolume76 May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:17 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:17 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:17 volumio volumio[1239]: info: VolumeController::SetAlsaVolume76 May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:17 volumio volumio[1239]: info: VolumeController::SetAlsaVolume77 May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:17 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:17 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:17 volumio volumio[1239]: info: VolumeController::SetAlsaVolume78 May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:17 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:17 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:17 volumio volumio[1239]: info: VolumeController::SetAlsaVolume79 May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:17 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:17 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::volumioNext May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::next May 12 19:21:17 volumio volumio[1239]: info: [1747070477841] ControllerTidal::next May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::next May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::stop May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::stPlaybackTimer May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::updateTrackBlock May 12 19:21:17 volumio volumio[1239]: info: CorePlayQueue::getTrackBlock May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:17 volumio volumio[1239]: info: CorePlayQueue::getTrack 34 May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::serviceStop May 12 19:21:17 volumio volumio[1239]: info: CorePlayQueue::getTrack 34 May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::serviceStop May 12 19:21:17 volumio volumio[1239]: info: [1747070477845] ControllerTidal::stop May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 19:21:17 volumio volumio[1239]: info: ControllerMpd::stop May 12 19:21:17 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand stop May 12 19:21:17 volumio volumio[1239]: info: May 12 19:21:17 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:17 volumio volumio[1239]: info: sendMpdCommand stop took 17 milliseconds May 12 19:21:17 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:17 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::play index undefined May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 19:21:17 volumio volumio[1239]: info: CorePlayQueue::getTrack 35 May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::startPlaybackTimer May 12 19:21:17 volumio volumio[1239]: info: CorePlayQueue::getTrack 35 May 12 19:21:17 volumio volumio[1239]: info: [1747070477864] ControllerTidal::clearAddPlayTrack May 12 19:21:17 volumio volumio[1239]: info: Getting stream with soundQuality LOSSLESS May 12 19:21:17 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand stop May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::updateTrackBlock May 12 19:21:17 volumio volumio[1239]: info: CorePlayQueue::getTrackBlock May 12 19:21:17 volumio volumio[1239]: info: sendMpdCommand status took 4 milliseconds May 12 19:21:17 volumio volumio[1239]: info: sendMpdCommand stop took 2 milliseconds May 12 19:21:17 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:17 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:17 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand clear May 12 19:21:17 volumio volumio[1239]: info: May 12 19:21:17 volumio volumio[1239]: ---------------------------- MPD announces system playlist update May 12 19:21:17 volumio volumio[1239]: info: Ignoring MPD Status Update May 12 19:21:17 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 9 milliseconds May 12 19:21:17 volumio volumio[1239]: info: sendMpdCommand clear took 8 milliseconds May 12 19:21:17 volumio volumio[1239]: verbose: ControllerMpd::parseTrackInfo May 12 19:21:17 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/68729574&soundQuality=LOSSLESS" May 12 19:21:17 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:17 volumio volumio[1239]: info: CorePlayQueue::getTrack 35 May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:17 volumio volumio[1239]: info: CorePlayQueue::getTrack 35 May 12 19:21:17 volumio volumio[1239]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 12 19:21:17 volumio volumio[1239]: info: ------------------------------ 38ms May 12 19:21:17 volumio volumio[1239]: error: updateQueue error: null May 12 19:21:17 volumio volumio[1239]: info: May 12 19:21:17 volumio volumio[1239]: ---------------------------- MPD announces system playlist update May 12 19:21:17 volumio volumio[1239]: info: Ignoring MPD Status Update May 12 19:21:17 volumio volumio[1239]: info: ------------------------------ 26ms May 12 19:21:17 volumio volumio[1239]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/68729574&soundQuality=LOSSLESS" took 24 milliseconds May 12 19:21:17 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 19:21:17 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand play May 12 19:21:17 volumio volumio[1239]: STREAMING PROXY: Handling url /?data=tidal://song/68729574&soundQuality=LOSSLESS May 12 19:21:17 volumio volumio[1239]: info: ------------------------------ 11ms May 12 19:21:17 volumio volumio[1239]: info: sendMpdCommand play took 10 milliseconds May 12 19:21:17 volumio volumio[1239]: info: Executing endpoint getStreamUrltidal May 12 19:21:17 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI May 12 19:21:18 volumio volumio[1239]: info: getStreamUrl took 299 milliseconds May 12 19:21:18 volumio volumio[1239]: STREAMING PROXY: Got real url: http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKwgDEic2NTQyZTQ5ZWVkZmUyYjM2ODVhM2U3YmRlZGM0MjI5YV82MS5tcDQ/0.flac?token=1747074078~ZGRiNjM2YTI3NGU4N2U3YmFiZjNlNzMyMmQ2ZjcyY2Y3NDYzNGQxZQ== May 12 19:21:18 volumio volumio[1239]: STREAMING PROXY: Response: 200, length: 17936597 May 12 19:21:18 volumio volumio[1239]: info: May 12 19:21:18 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:18 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:18 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:18 volumio volumio[1239]: info: May 12 19:21:18 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:18 volumio volumio[1239]: info: sendMpdCommand status took 2 milliseconds May 12 19:21:18 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:18 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:18 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:18 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:18 volumio volumio[1239]: info: sendMpdCommand status took 1 milliseconds May 12 19:21:18 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 19:21:18 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:18 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:18 volumio volumio[1239]: verbose: ControllerMpd::parseTrackInfo May 12 19:21:18 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:18 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:18 volumio volumio[1239]: info: CorePlayQueue::getTrack 35 May 12 19:21:18 volumio volumio[1239]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":168,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"68729574&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/68729574&soundQuality=LOSSLESS","trackType":"tidal"} May 12 19:21:18 volumio volumio[1239]: verbose: CURRENT POSITION 35 May 12 19:21:18 volumio volumio[1239]: info: CoreStateMachine::syncState stateService play May 12 19:21:18 volumio volumio[1239]: info: CoreStateMachine::syncState currentStatus stop May 12 19:21:18 volumio volumio[1239]: info: ------------------------------ 5ms May 12 19:21:18 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 2 milliseconds May 12 19:21:18 volumio volumio[1239]: verbose: ControllerMpd::parseTrackInfo May 12 19:21:18 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:18 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:18 volumio volumio[1239]: info: CorePlayQueue::getTrack 35 May 12 19:21:18 volumio volumio[1239]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":168,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"68729574&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/68729574&soundQuality=LOSSLESS","trackType":"tidal"} May 12 19:21:18 volumio volumio[1239]: verbose: CURRENT POSITION 35 May 12 19:21:18 volumio volumio[1239]: info: CoreStateMachine::syncState stateService play May 12 19:21:18 volumio volumio[1239]: info: CoreStateMachine::syncState currentStatus play May 12 19:21:18 volumio volumio[1239]: info: Received an update from plugin. extracting info from payload May 12 19:21:18 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:18 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:18 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:18 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:18 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:18 volumio volumio[1239]: info: ------------------------------ 12ms May 12 19:21:19 volumio volumio[1239]: info: CoreCommandRouter::volumioNext May 12 19:21:19 volumio volumio[1239]: info: CoreStateMachine::next May 12 19:21:19 volumio volumio[1239]: info: [1747070479719] ControllerTidal::next May 12 19:21:19 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 19:21:19 volumio volumio[1239]: info: CoreStateMachine::next May 12 19:21:19 volumio volumio[1239]: info: CoreStateMachine::stop May 12 19:21:19 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 19:21:19 volumio volumio[1239]: info: CoreStateMachine::stPlaybackTimer May 12 19:21:19 volumio volumio[1239]: info: CoreStateMachine::updateTrackBlock May 12 19:21:19 volumio volumio[1239]: info: CorePlayQueue::getTrackBlock May 12 19:21:19 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:19 volumio volumio[1239]: info: CorePlayQueue::getTrack 35 May 12 19:21:19 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:19 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:19 volumio volumio[1239]: info: CoreStateMachine::serviceStop May 12 19:21:19 volumio volumio[1239]: info: CorePlayQueue::getTrack 35 May 12 19:21:19 volumio volumio[1239]: info: CoreCommandRouter::serviceStop May 12 19:21:19 volumio volumio[1239]: info: [1747070479725] ControllerTidal::stop May 12 19:21:19 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 19:21:19 volumio volumio[1239]: info: ControllerMpd::stop May 12 19:21:19 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand stop May 12 19:21:19 volumio volumio[1239]: STREAMING PROXY: Client dropped request, destroying May 12 19:21:19 volumio volumio[1239]: info: May 12 19:21:19 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:19 volumio volumio[1239]: info: sendMpdCommand stop took 13 milliseconds May 12 19:21:19 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:19 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:19 volumio volumio[1239]: info: CoreStateMachine::play index undefined May 12 19:21:19 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 19:21:19 volumio volumio[1239]: info: CorePlayQueue::getTrack 36 May 12 19:21:19 volumio volumio[1239]: info: CoreStateMachine::startPlaybackTimer May 12 19:21:19 volumio volumio[1239]: info: CorePlayQueue::getTrack 36 May 12 19:21:19 volumio volumio[1239]: info: [1747070479741] ControllerTidal::clearAddPlayTrack May 12 19:21:19 volumio volumio[1239]: info: Getting stream with soundQuality LOSSLESS May 12 19:21:19 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand stop May 12 19:21:19 volumio volumio[1239]: info: CoreStateMachine::updateTrackBlock May 12 19:21:19 volumio volumio[1239]: info: CorePlayQueue::getTrackBlock May 12 19:21:19 volumio volumio[1239]: info: sendMpdCommand status took 3 milliseconds May 12 19:21:19 volumio volumio[1239]: info: sendMpdCommand stop took 1 milliseconds May 12 19:21:19 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:19 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:19 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand clear May 12 19:21:19 volumio volumio[1239]: info: May 12 19:21:19 volumio volumio[1239]: ---------------------------- MPD announces system playlist update May 12 19:21:19 volumio volumio[1239]: info: Ignoring MPD Status Update May 12 19:21:19 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 19:21:19 volumio volumio[1239]: info: sendMpdCommand clear took 1 milliseconds May 12 19:21:19 volumio volumio[1239]: verbose: ControllerMpd::parseTrackInfo May 12 19:21:19 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/68729575&soundQuality=LOSSLESS" May 12 19:21:19 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:19 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:19 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:19 volumio volumio[1239]: info: CorePlayQueue::getTrack 36 May 12 19:21:19 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:19 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:19 volumio volumio[1239]: info: CorePlayQueue::getTrack 36 May 12 19:21:19 volumio volumio[1239]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 12 19:21:19 volumio volumio[1239]: info: ------------------------------ 10ms May 12 19:21:19 volumio volumio[1239]: error: updateQueue error: null May 12 19:21:19 volumio volumio[1239]: info: May 12 19:21:19 volumio volumio[1239]: ---------------------------- MPD announces system playlist update May 12 19:21:19 volumio volumio[1239]: info: Ignoring MPD Status Update May 12 19:21:19 volumio volumio[1239]: info: ------------------------------ 6ms May 12 19:21:19 volumio volumio[1239]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/68729575&soundQuality=LOSSLESS" took 5 milliseconds May 12 19:21:19 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 19:21:19 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand play May 12 19:21:19 volumio volumio[1239]: STREAMING PROXY: Handling url /?data=tidal://song/68729575&soundQuality=LOSSLESS May 12 19:21:19 volumio volumio[1239]: info: ------------------------------ 8ms May 12 19:21:19 volumio volumio[1239]: info: sendMpdCommand play took 8 milliseconds May 12 19:21:19 volumio volumio[1239]: info: Executing endpoint getStreamUrltidal May 12 19:21:19 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI May 12 19:21:20 volumio volumio[1239]: info: getStreamUrl took 801 milliseconds May 12 19:21:20 volumio volumio[1239]: STREAMING PROXY: Got real url: http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKwgDEidiZjI4Y2FlM2Y4ZmFjYzExNmQwYzBkNDFlZWIzM2Y1YV82MS5tcDQ/0.flac?token=1747074080~MzE1NmJkYWNkNzk2YjNjYTQ1NWE1NjdmOGExYTcyMWIyMzJjNjY4Mw== May 12 19:21:20 volumio volumio[1239]: STREAMING PROXY: Response: 200, length: 18780270 May 12 19:21:20 volumio volumio[1239]: info: May 12 19:21:20 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:20 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:20 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:20 volumio volumio[1239]: info: May 12 19:21:20 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:20 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:20 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:20 volumio volumio[1239]: info: sendMpdCommand status took 2 milliseconds May 12 19:21:20 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:20 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:20 volumio volumio[1239]: info: sendMpdCommand status took 2 milliseconds May 12 19:21:20 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 19:21:20 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:20 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:20 volumio volumio[1239]: verbose: ControllerMpd::parseTrackInfo May 12 19:21:20 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:20 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:20 volumio volumio[1239]: info: CorePlayQueue::getTrack 36 May 12 19:21:20 volumio volumio[1239]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":160,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"68729575&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/68729575&soundQuality=LOSSLESS","trackType":"tidal"} May 12 19:21:20 volumio volumio[1239]: verbose: CURRENT POSITION 36 May 12 19:21:20 volumio volumio[1239]: info: CoreStateMachine::syncState stateService play May 12 19:21:20 volumio volumio[1239]: info: CoreStateMachine::syncState currentStatus stop May 12 19:21:20 volumio volumio[1239]: info: ------------------------------ 10ms May 12 19:21:20 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 2 milliseconds May 12 19:21:20 volumio volumio[1239]: verbose: ControllerMpd::parseTrackInfo May 12 19:21:20 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:20 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:20 volumio volumio[1239]: info: CorePlayQueue::getTrack 36 May 12 19:21:20 volumio volumio[1239]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":160,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"68729575&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/68729575&soundQuality=LOSSLESS","trackType":"tidal"} May 12 19:21:20 volumio volumio[1239]: verbose: CURRENT POSITION 36 May 12 19:21:20 volumio volumio[1239]: info: CoreStateMachine::syncState stateService play May 12 19:21:20 volumio volumio[1239]: info: CoreStateMachine::syncState currentStatus play May 12 19:21:20 volumio volumio[1239]: info: Received an update from plugin. extracting info from payload May 12 19:21:20 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:20 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:20 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:20 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:20 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:20 volumio volumio[1239]: info: ------------------------------ 25ms May 12 19:21:22 volumio volumio[1239]: STREAMING PROXY: Client dropped request, destroying May 12 19:21:22 volumio volumio[1239]: info: CoreCommandRouter::volumioNext May 12 19:21:22 volumio volumio[1239]: info: CoreStateMachine::next May 12 19:21:22 volumio volumio[1239]: info: [1747070482704] ControllerTidal::next May 12 19:21:22 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 19:21:22 volumio volumio[1239]: info: CoreStateMachine::next May 12 19:21:22 volumio volumio[1239]: info: CoreStateMachine::stop May 12 19:21:22 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 19:21:22 volumio volumio[1239]: info: CoreStateMachine::stPlaybackTimer May 12 19:21:22 volumio volumio[1239]: info: CoreStateMachine::updateTrackBlock May 12 19:21:22 volumio volumio[1239]: info: CorePlayQueue::getTrackBlock May 12 19:21:22 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:22 volumio volumio[1239]: info: CorePlayQueue::getTrack 36 May 12 19:21:22 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:22 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:22 volumio volumio[1239]: info: CoreStateMachine::serviceStop May 12 19:21:22 volumio volumio[1239]: info: CorePlayQueue::getTrack 36 May 12 19:21:22 volumio volumio[1239]: info: CoreCommandRouter::serviceStop May 12 19:21:22 volumio volumio[1239]: info: [1747070482709] ControllerTidal::stop May 12 19:21:22 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 19:21:22 volumio volumio[1239]: info: ControllerMpd::stop May 12 19:21:22 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand stop May 12 19:21:22 volumio volumio[1239]: info: May 12 19:21:22 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:22 volumio volumio[1239]: info: sendMpdCommand stop took 14 milliseconds May 12 19:21:22 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:22 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:22 volumio volumio[1239]: info: CoreStateMachine::play index undefined May 12 19:21:22 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 19:21:22 volumio volumio[1239]: info: CorePlayQueue::getTrack 37 May 12 19:21:22 volumio volumio[1239]: info: CoreStateMachine::startPlaybackTimer May 12 19:21:22 volumio volumio[1239]: info: CorePlayQueue::getTrack 37 May 12 19:21:22 volumio volumio[1239]: info: [1747070482729] ControllerTidal::clearAddPlayTrack May 12 19:21:22 volumio volumio[1239]: info: Getting stream with soundQuality LOSSLESS May 12 19:21:22 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand stop May 12 19:21:22 volumio volumio[1239]: info: CoreStateMachine::updateTrackBlock May 12 19:21:22 volumio volumio[1239]: info: CorePlayQueue::getTrackBlock May 12 19:21:22 volumio volumio[1239]: info: sendMpdCommand status took 8 milliseconds May 12 19:21:22 volumio volumio[1239]: info: sendMpdCommand stop took 2 milliseconds May 12 19:21:22 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:22 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:22 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand clear May 12 19:21:22 volumio volumio[1239]: info: May 12 19:21:22 volumio volumio[1239]: ---------------------------- MPD announces system playlist update May 12 19:21:22 volumio volumio[1239]: info: Ignoring MPD Status Update May 12 19:21:22 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 3 milliseconds May 12 19:21:22 volumio volumio[1239]: info: sendMpdCommand clear took 3 milliseconds May 12 19:21:22 volumio volumio[1239]: verbose: ControllerMpd::parseTrackInfo May 12 19:21:22 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/68729576&soundQuality=LOSSLESS" May 12 19:21:22 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:22 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:22 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:22 volumio volumio[1239]: info: CorePlayQueue::getTrack 37 May 12 19:21:22 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:22 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:22 volumio volumio[1239]: info: CorePlayQueue::getTrack 37 May 12 19:21:22 volumio volumio[1239]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 12 19:21:22 volumio volumio[1239]: info: ------------------------------ 39ms May 12 19:21:22 volumio volumio[1239]: error: updateQueue error: null May 12 19:21:22 volumio volumio[1239]: info: May 12 19:21:22 volumio volumio[1239]: ---------------------------- MPD announces system playlist update May 12 19:21:22 volumio volumio[1239]: info: Ignoring MPD Status Update May 12 19:21:22 volumio volumio[1239]: info: ------------------------------ 27ms May 12 19:21:22 volumio volumio[1239]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/68729576&soundQuality=LOSSLESS" took 15 milliseconds May 12 19:21:22 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 19:21:22 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand play May 12 19:21:22 volumio volumio[1239]: STREAMING PROXY: Handling url /?data=tidal://song/68729576&soundQuality=LOSSLESS May 12 19:21:22 volumio volumio[1239]: info: ------------------------------ 11ms May 12 19:21:22 volumio volumio[1239]: info: sendMpdCommand play took 10 milliseconds May 12 19:21:22 volumio volumio[1239]: info: Executing endpoint getStreamUrltidal May 12 19:21:22 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI May 12 19:21:23 volumio volumio[1239]: info: getStreamUrl took 307 milliseconds May 12 19:21:23 volumio volumio[1239]: STREAMING PROXY: Got real url: http://sp-pr-fa.audio.tidal.com/mediatracks/CAEaKwgDEic5ZWU5MzQ4ZDMxZTU3ZDE2ZTcwZDg1ZDJlZDAwNzlkMl82MS5tcDQ/0.flac?token=1747074083~Y2JlYjI0ZGRhNDc2NmZmYWQzYjk2YjU3ZDRlNDQzZjExMWM0NTQxMw== May 12 19:21:23 volumio volumio[1239]: STREAMING PROXY: Response: 200, length: 21288712 May 12 19:21:23 volumio volumio[1239]: info: May 12 19:21:23 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:23 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:23 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:23 volumio volumio[1239]: info: May 12 19:21:23 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:23 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:23 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:23 volumio volumio[1239]: info: sendMpdCommand status took 2 milliseconds May 12 19:21:23 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:23 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:23 volumio volumio[1239]: info: sendMpdCommand status took 2 milliseconds May 12 19:21:23 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 19:21:23 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:23 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:23 volumio volumio[1239]: verbose: ControllerMpd::parseTrackInfo May 12 19:21:23 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:23 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:23 volumio volumio[1239]: info: CorePlayQueue::getTrack 37 May 12 19:21:23 volumio volumio[1239]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":194,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"68729576&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/68729576&soundQuality=LOSSLESS","trackType":"tidal"} May 12 19:21:23 volumio volumio[1239]: verbose: CURRENT POSITION 37 May 12 19:21:23 volumio volumio[1239]: info: CoreStateMachine::syncState stateService play May 12 19:21:23 volumio volumio[1239]: info: CoreStateMachine::syncState currentStatus stop May 12 19:21:23 volumio volumio[1239]: info: ------------------------------ 9ms May 12 19:21:23 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 4 milliseconds May 12 19:21:23 volumio volumio[1239]: verbose: ControllerMpd::parseTrackInfo May 12 19:21:23 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:23 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:23 volumio volumio[1239]: info: CorePlayQueue::getTrack 37 May 12 19:21:23 volumio volumio[1239]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":194,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"68729576&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/68729576&soundQuality=LOSSLESS","trackType":"tidal"} May 12 19:21:23 volumio volumio[1239]: verbose: CURRENT POSITION 37 May 12 19:21:23 volumio volumio[1239]: info: CoreStateMachine::syncState stateService play May 12 19:21:23 volumio volumio[1239]: info: CoreStateMachine::syncState currentStatus play May 12 19:21:23 volumio volumio[1239]: info: Received an update from plugin. extracting info from payload May 12 19:21:23 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:23 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:23 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:23 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:23 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:23 volumio volumio[1239]: info: ------------------------------ 49ms May 12 19:21:24 volumio volumio[1239]: info: CoreCommandRouter::volumioSeek May 12 19:21:24 volumio volumio[1239]: info: CoreStateMachine::seek May 12 19:21:24 volumio volumio[1239]: info: CorePlayQueue::getTrack 37 May 12 19:21:24 volumio volumio[1239]: info: TRACKBLOCK {"album":"Five Years (1969 - 1973)","albumUri":"tidal://album/68729538","albumart":"https://resources.tidal.com/images/146c89fd/3cb8/4a51/9818/c553a3f533a3/640x640.jpg","artist":"David Bowie","artistUri":"tidal://artist/4768","audioQuality":"LOSSLESS","bitdepth":"16 bit","duration":194,"explicit":false,"name":"Ziggy Stardust (2012 Remaster)","samplerate":"44.1 KHz","service":"tidal","title":"Ziggy Stardust (2012 Remaster)","trackType":"tidal","tracknumber":9,"type":"track","uri":"tidal://song/68729576","volumeNumber":4} May 12 19:21:24 volumio volumio[1239]: info: CoreStateMachine::startPlaybackTimer May 12 19:21:24 volumio volumio[1239]: info: CorePlayQueue::getTrack 37 May 12 19:21:24 volumio volumio[1239]: info: [1747070484886] ControllerTidal::seek May 12 19:21:24 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 19:21:24 volumio volumio[1239]: info: ControllerMpd::seek May 12 19:21:24 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:24 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:24 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:24 volumio volumio[1239]: error: null May 12 19:21:24 volumio volumio[1239]: info: May 12 19:21:24 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:24 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:24 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:24 volumio volumio[1239]: info: sendMpdCommand status took 1 milliseconds May 12 19:21:24 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:24 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:24 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 1 milliseconds May 12 19:21:24 volumio volumio[1239]: verbose: ControllerMpd::parseTrackInfo May 12 19:21:24 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:24 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:24 volumio volumio[1239]: info: CorePlayQueue::getTrack 37 May 12 19:21:24 volumio volumio[1239]: verbose: STATE SERVICE {"status":"play","position":0,"seek":51000,"duration":194,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"684 Kbps","isStreaming":false,"title":"68729576&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/68729576&soundQuality=LOSSLESS","trackType":"tidal"} May 12 19:21:24 volumio volumio[1239]: verbose: CURRENT POSITION 37 May 12 19:21:24 volumio volumio[1239]: info: CoreStateMachine::syncState stateService play May 12 19:21:24 volumio volumio[1239]: info: CoreStateMachine::syncState currentStatus play May 12 19:21:24 volumio volumio[1239]: info: Received an update from plugin. extracting info from payload May 12 19:21:24 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:24 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:24 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:24 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:24 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:24 volumio volumio[1239]: info: ------------------------------ 28ms May 12 19:21:25 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 12 19:21:25 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 12 19:21:25 volumio volumio[1239]: info: Discovery: Getting this device information May 12 19:21:25 volumio volumio[1239]: info: CoreCommandRouter::volumioGetState May 12 19:21:25 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 12 19:21:25 volumio volumio[1239]: STREAMING PROXY: Client dropped request, destroying May 12 19:21:27 volumio volumio[1239]: info: CoreCommandRouter::volumioSeek May 12 19:21:27 volumio volumio[1239]: info: CoreStateMachine::seek May 12 19:21:27 volumio volumio[1239]: info: CorePlayQueue::getTrack 37 May 12 19:21:27 volumio volumio[1239]: info: TRACKBLOCK {"album":"Five Years (1969 - 1973)","albumUri":"tidal://album/68729538","albumart":"https://resources.tidal.com/images/146c89fd/3cb8/4a51/9818/c553a3f533a3/640x640.jpg","artist":"David Bowie","artistUri":"tidal://artist/4768","audioQuality":"LOSSLESS","bitdepth":"16 bit","duration":194,"explicit":false,"name":"Ziggy Stardust (2012 Remaster)","samplerate":"44.1 KHz","service":"tidal","title":"Ziggy Stardust (2012 Remaster)","trackType":"tidal","tracknumber":9,"type":"track","uri":"tidal://song/68729576","volumeNumber":4} May 12 19:21:27 volumio volumio[1239]: info: CoreStateMachine::startPlaybackTimer May 12 19:21:27 volumio volumio[1239]: info: CorePlayQueue::getTrack 37 May 12 19:21:27 volumio volumio[1239]: info: [1747070487210] ControllerTidal::seek May 12 19:21:27 volumio volumio[1239]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 19:21:27 volumio volumio[1239]: info: ControllerMpd::seek May 12 19:21:27 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:27 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:27 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:27 volumio volumio[1239]: error: null May 12 19:21:27 volumio volumio[1239]: info: May 12 19:21:27 volumio volumio[1239]: ---------------------------- MPD announces state update: player May 12 19:21:27 volumio volumio[1239]: info: ControllerMpd::getState May 12 19:21:27 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand status May 12 19:21:27 volumio volumio[1239]: info: sendMpdCommand status took 3 milliseconds May 12 19:21:27 volumio volumio[1239]: verbose: ControllerMpd::parseState May 12 19:21:27 volumio volumio[1239]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 19:21:27 volumio volumio[1239]: info: sendMpdCommand playlistinfo took 0 milliseconds May 12 19:21:27 volumio volumio[1239]: verbose: ControllerMpd::parseTrackInfo May 12 19:21:27 volumio volumio[1239]: info: ControllerMpd::pushState May 12 19:21:27 volumio volumio[1239]: info: CoreCommandRouter::servicePushState May 12 19:21:27 volumio volumio[1239]: info: CorePlayQueue::getTrack 37 May 12 19:21:27 volumio volumio[1239]: verbose: STATE SERVICE {"status":"play","position":0,"seek":72000,"duration":194,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"827 Kbps","isStreaming":false,"title":"68729576&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/68729576&soundQuality=LOSSLESS","trackType":"tidal"} May 12 19:21:27 volumio volumio[1239]: verbose: CURRENT POSITION 37 May 12 19:21:27 volumio volumio[1239]: info: CoreStateMachine::syncState stateService play May 12 19:21:27 volumio volumio[1239]: info: CoreStateMachine::syncState currentStatus play May 12 19:21:27 volumio volumio[1239]: info: Received an update from plugin. extracting info from payload May 12 19:21:27 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:27 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:27 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:27 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:27 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:27 volumio volumio[1239]: info: ------------------------------ 20ms May 12 19:21:28 volumio volumio[1239]: info: VolumeController::SetAlsaVolume78 May 12 19:21:28 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:28 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:28 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:28 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:28 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:28 volumio volumio[1239]: info: VolumeController::SetAlsaVolume77 May 12 19:21:28 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:28 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:28 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:28 volumio volumio[1239]: info: VolumeController::SetAlsaVolume76 May 12 19:21:28 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:28 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:28 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:28 volumio volumio[1239]: info: VolumeController::SetAlsaVolume75 May 12 19:21:28 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:28 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:28 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:29 volumio volumio[1239]: info: VolumeController::SetAlsaVolume75 May 12 19:21:29 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:29 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:29 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:29 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:29 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:29 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:29 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:29 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:29 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:29 volumio volumio[1239]: info: VolumeController::SetAlsaVolume76 May 12 19:21:29 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:29 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:29 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:30 volumio volumio[1239]: info: VolumeController::SetAlsaVolume77 May 12 19:21:30 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:30 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:30 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:30 volumio volumio[1239]: info: VolumeController::SetAlsaVolume78 May 12 19:21:30 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:30 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:30 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:32 volumio volumio[1239]: info: Adding tidal://song/68729576 to favourites with specific tidal method May 12 19:21:34 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: tidal , explodeUri May 12 19:21:35 volumio volumio[1239]: info: explodeTIDALUri took 287 milliseconds May 12 19:21:35 volumio volumio[1239]: info: Saving Cloud item Jakość May 12 19:21:35 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem May 12 19:21:35 volumio volumio[1239]: info: Pushing Favourites {"uri":"tidal://song/68729576","favourite":false} May 12 19:21:35 volumio volumio[1239]: info: Listing playlists May 12 19:21:35 volumio volumio[1239]: info: VolumeController::SetAlsaVolume79 May 12 19:21:35 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:35 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:35 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:35 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:35 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:36 volumio volumio[1239]: info: VolumeController::SetAlsaVolume80 May 12 19:21:36 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:36 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:36 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:36 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:36 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:36 volumio volumio[1239]: info: VolumeController::SetAlsaVolume81 May 12 19:21:36 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:36 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:36 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:36 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:36 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:36 volumio volumio[1239]: info: VolumeController::SetAlsaVolume82 May 12 19:21:36 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:36 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:36 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:37 volumio volumio[1239]: info: VolumeController::SetAlsaVolume83 May 12 19:21:37 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:37 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:37 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:38 volumio volumio[1239]: info: VolumeController::SetAlsaVolume84 May 12 19:21:38 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:38 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:38 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:38 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:38 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:39 volumio volumio[1239]: info: VolumeController::SetAlsaVolume85 May 12 19:21:39 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:39 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:39 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:39 volumio volumio[1239]: info: VolumeController::SetAlsaVolume86 May 12 19:21:39 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:39 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:39 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:41 volumio volumio[1239]: info: VolumeController::SetAlsaVolume85 May 12 19:21:41 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:41 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:41 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:44 volumio volumio[1239]: info: VolumeController::SetAlsaVolume84 May 12 19:21:44 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:44 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:44 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:44 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:44 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:45 volumio volumio[1239]: info: VolumeController::SetAlsaVolume83 May 12 19:21:45 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:45 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:45 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:45 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:45 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:45 volumio volumio[1239]: info: VolumeController::SetAlsaVolume82 May 12 19:21:45 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:45 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:45 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:45 volumio volumio[1239]: info: VolumeController::SetAlsaVolume81 May 12 19:21:45 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:45 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:45 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:45 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:45 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:45 volumio volumio[1239]: info: VolumeController::SetAlsaVolume81 May 12 19:21:45 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:45 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:45 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:45 volumio volumio[1239]: info: VolumeController::SetAlsaVolume80 May 12 19:21:45 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:45 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:45 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:45 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:45 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:46 volumio volumio[1239]: info: VolumeController::SetAlsaVolume79 May 12 19:21:46 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:46 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:46 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:46 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:46 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:46 volumio volumio[1239]: info: VolumeController::SetAlsaVolume78 May 12 19:21:46 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:46 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:46 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:46 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:46 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:46 volumio volumio[1239]: info: VolumeController::SetAlsaVolume77 May 12 19:21:46 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:46 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:46 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:46 volumio volumio[1239]: info: VolumeController::SetAlsaVolume76 May 12 19:21:46 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:46 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:46 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:46 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:46 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:46 volumio volumio[1239]: info: VolumeController::SetAlsaVolume77 May 12 19:21:47 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:47 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:47 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:47 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:47 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:47 volumio volumio[1239]: info: VolumeController::SetAlsaVolume78 May 12 19:21:47 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:47 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:47 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:48 volumio volumio[1239]: info: VolumeController::SetAlsaVolume79 May 12 19:21:48 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:48 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:48 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:48 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:48 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:48 volumio volumio[1239]: info: VolumeController::SetAlsaVolume80 May 12 19:21:48 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:48 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:48 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:48 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:48 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:48 volumio volumio[1239]: info: VolumeController::SetAlsaVolume81 May 12 19:21:48 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:48 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:48 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:50 volumio volumio[1239]: info: VolumeController::SetAlsaVolume82 May 12 19:21:50 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:50 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:50 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:50 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:50 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:50 volumio volumio[1239]: info: VolumeController::SetAlsaVolume83 May 12 19:21:50 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:50 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:50 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:50 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:50 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:51 volumio volumio[1239]: info: VolumeController::SetAlsaVolume84 May 12 19:21:51 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:51 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:51 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:52 volumio volumio[1239]: info: VolumeController::SetAlsaVolume83 May 12 19:21:52 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:52 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:52 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:52 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:52 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:52 volumio volumio[1239]: info: VolumeController::SetAlsaVolume82 May 12 19:21:52 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:52 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:52 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:52 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:52 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:53 volumio volumio[1239]: info: VolumeController::SetAlsaVolume81 May 12 19:21:53 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:53 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:53 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:53 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:53 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:53 volumio volumio[1239]: info: VolumeController::SetAlsaVolume80 May 12 19:21:53 volumio volumio[1239]: info: CoreStateMachine::pushState May 12 19:21:53 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 19:21:53 volumio volumio[1239]: info: CoreCommandRouter::volumioPushState May 12 19:21:53 volumio volumio[1239]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 12 19:21:53 volumio volumio[1239]: xcb_connection_has_error() returned true May 12 19:21:53 volumio volumio[1239]: info: Executing endpoint metavolumio May 12 19:21:53 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 19:21:53 volumio volumio[1239]: info: Executing endpoint metavolumio May 12 19:21:53 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 19:21:55 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 12 19:21:55 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 12 19:21:55 volumio volumio[1239]: info: Discovery: Getting this device information May 12 19:21:55 volumio volumio[1239]: info: CoreCommandRouter::volumioGetState May 12 19:21:55 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 12 19:21:56 volumio volumio[1239]: info: Preload queue cleared May 12 19:21:56 volumio volumio[1239]: info: Preloading song: mnt/USB/Elements/Elton John - Discography/01. Studio albums/1975 - Captain Fantastic and the Brown Dirt Cowboy/Elton John - Captain Fantastic and the Brown Dirt Cowboy.flac May 12 19:21:56 volumio volumio[1239]: info: Exploding uri mnt/USB/Elements/Elton John - Discography/01. Studio albums/1975 - Captain Fantastic and the Brown Dirt Cowboy/Elton John - Captain Fantastic and the Brown Dirt Cowboy.flac in service mpd May 12 19:21:56 volumio volumio[1239]: error: scanFolder - failure to stat '/mnt/USB/Elements/Elton John - Discography/01. Studio albums/1975 - Captain Fantastic and the Brown Dirt Cowboy/Elton John - Captain Fantastic and the Brown Dirt Cowboy.flac' May 12 19:22:01 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 12 19:22:01 volumio volumio[1239]: info: Preload queue cleared May 12 19:22:02 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 12 19:22:03 volumio volumio[1239]: info: Preload queue cleared May 12 19:22:05 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 12 19:22:05 volumio volumio[1239]: info: Preload queue cleared May 12 19:22:07 volumio volumio[1239]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 12 19:22:07 volumio volumio[1239]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 12 19:22:07 volumio volumio[1239]: TypeError: Cannot read property 'length' of undefined May 12 19:22:07 volumio volumio[1239]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 May 12 19:22:07 volumio volumio[1239]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 May 12 19:22:07 volumio volumio[1239]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) May 12 19:22:07 volumio volumio[1239]: at Parser.emit (events.js:400:28) May 12 19:22:07 volumio volumio[1239]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) May 12 19:22:07 volumio volumio[1239]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) May 12 19:22:07 volumio volumio[1239]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) May 12 19:22:07 volumio volumio[1239]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) May 12 19:22:07 volumio volumio[1239]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) May 12 19:22:07 volumio volumio[1239]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) May 12 19:22:07 volumio volumio[1239]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) May 12 19:22:07 volumio volumio[1239]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) May 12 19:22:07 volumio volumio[1239]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) May 12 19:22:07 volumio volumio[1239]: at IncomingMessage.emit (events.js:412:35) May 12 19:22:07 volumio volumio[1239]: at endReadableNT (internal/streams/readable.js:1333:12) May 12 19:22:07 volumio volumio[1239]: at processTicksAndRejections (internal/process/task_queues.js:82:21) May 12 19:22:07 volumio volumio[1239]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 12 19:22:08 volumio sudo[32518]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-12 19:21 May 12 19:22:08 volumio sudo[32518]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 09:53:51 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="53825f995260683aee752aed6b29f24e"