Dec 21 00:50:07 volumio volumio[1200]: info: Preload queue cleared Dec 21 00:50:07 volumio volumio[1200]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 21 00:50:07 volumio volumio[1200]: info: CoreStateMachine::ClearQueue Dec 21 00:50:07 volumio volumio[1200]: info: CoreStateMachine::stop Dec 21 00:50:07 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 00:50:07 volumio volumio[1200]: info: CoreStateMachine::stPlaybackTimer Dec 21 00:50:07 volumio volumio[1200]: info: CoreStateMachine::updateTrackBlock Dec 21 00:50:07 volumio volumio[1200]: info: CorePlayQueue::getTrackBlock Dec 21 00:50:07 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:07 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:07 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 00:50:07 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:07 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:07 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:07 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:07 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:07 volumio volumio[1200]: info: CoreStateMachine::serviceStop Dec 21 00:50:07 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:07 volumio volumio[1200]: info: CoreCommandRouter::serviceStop Dec 21 00:50:07 volumio volumio[1200]: info: [1766289007987] ControllerTidal::stop Dec 21 00:50:07 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 21 00:50:07 volumio volumio[1200]: info: ControllerMpd::stop Dec 21 00:50:07 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand stop Dec 21 00:50:07 volumio volumio[1200]: info: CorePlayQueue::clearPlayQueue Dec 21 00:50:07 volumio volumio[1200]: info: CorePlayQueue::saveQueue Dec 21 00:50:07 volumio volumio[1200]: info: CoreCommandRouter::volumioPushQueue Dec 21 00:50:07 volumio volumio[1200]: info: CoreStateMachine::addQueueItems Dec 21 00:50:07 volumio volumio[1200]: info: CorePlayQueue::addQueueItems Dec 21 00:50:07 volumio volumio[1200]: info: Preload queue cleared Dec 21 00:50:07 volumio volumio[1200]: info: Adding Item to queue: tidal://song/55391440 Dec 21 00:50:07 volumio volumio[1200]: info: Using cached record of: tidal://song/55391440 Dec 21 00:50:07 volumio volumio[1200]: info: Adding Item to queue: tidal://song/55391441 Dec 21 00:50:07 volumio volumio[1200]: info: Using cached record of: tidal://song/55391441 Dec 21 00:50:07 volumio volumio[1200]: info: CoreCommandRouter::volumioPushQueue Dec 21 00:50:07 volumio volumio[1200]: info: CorePlayQueue::saveQueue Dec 21 00:50:07 volumio volumio[1200]: info: CoreStateMachine::updateTrackBlock Dec 21 00:50:07 volumio volumio[1200]: info: CorePlayQueue::getTrackBlock Dec 21 00:50:07 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:07 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Dec 21 00:50:07 volumio volumio[1200]: info: CoreCommandRouter::volumioPlay Dec 21 00:50:07 volumio volumio[1200]: info: CoreStateMachine::play index 1 Dec 21 00:50:07 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 00:50:07 volumio volumio[1200]: info: CoreStateMachine::addQueueItems Dec 21 00:50:07 volumio volumio[1200]: info: CorePlayQueue::addQueueItems Dec 21 00:50:07 volumio volumio[1200]: info: Preload queue cleared Dec 21 00:50:07 volumio volumio[1200]: info: Adding Item to queue: tidal://song/55391442 Dec 21 00:50:07 volumio volumio[1200]: info: Using cached record of: tidal://song/55391442 Dec 21 00:50:08 volumio volumio[1200]: info: Adding Item to queue: tidal://song/55391443 Dec 21 00:50:08 volumio volumio[1200]: info: Using cached record of: tidal://song/55391443 Dec 21 00:50:08 volumio volumio[1200]: info: Adding Item to queue: tidal://song/55391444 Dec 21 00:50:08 volumio volumio[1200]: info: Using cached record of: tidal://song/55391444 Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::stop Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioPushQueue Dec 21 00:50:08 volumio volumio[1200]: info: CorePlayQueue::saveQueue Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::play index undefined Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::updateTrackBlock Dec 21 00:50:08 volumio volumio[1200]: info: CorePlayQueue::getTrackBlock Dec 21 00:50:08 volumio volumio[1200]: info: CorePlayQueue::getTrack 1 Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::startPlaybackTimer Dec 21 00:50:08 volumio volumio[1200]: info: CorePlayQueue::getTrack 1 Dec 21 00:50:08 volumio volumio[1200]: info: [1766289008006] ControllerTidal::clearAddPlayTrack Dec 21 00:50:08 volumio volumio[1200]: info: Getting stream with soundQuality HI_RES Dec 21 00:50:08 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:08 volumio volumio[1200]: info: Dec 21 00:50:08 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand stop took 47 milliseconds Dec 21 00:50:08 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:08 volumio volumio[1200]: info: Dec 21 00:50:08 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:08 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand status took 3 milliseconds Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand status took 2 milliseconds Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:08 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:08 volumio volumio[1200]: info: CorePlayQueue::getTrack 1 Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:08 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:08 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:08 volumio volumio[1200]: info: CorePlayQueue::getTrack 1 Dec 21 00:50:08 volumio volumio[1200]: info: CorePlayQueue::getTrack 1 Dec 21 00:50:08 volumio volumio[1200]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Dec 21 00:50:08 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:08 volumio volumio[1200]: info: CorePlayQueue::getTrack 1 Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:08 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:08 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:08 volumio volumio[1200]: info: CorePlayQueue::getTrack 1 Dec 21 00:50:08 volumio volumio[1200]: info: CorePlayQueue::getTrack 1 Dec 21 00:50:08 volumio volumio[1200]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Dec 21 00:50:08 volumio volumio[1200]: info: ------------------------------ 25ms Dec 21 00:50:08 volumio volumio[1200]: info: ------------------------------ 25ms Dec 21 00:50:08 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:08 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:08 volumio volumio[1200]: info: getStreamUrl took 545 milliseconds Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand stop Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand stop took 2 milliseconds Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand clear Dec 21 00:50:08 volumio volumio[1200]: info: Dec 21 00:50:08 volumio volumio[1200]: ---------------------------- MPD announces system playlist update Dec 21 00:50:08 volumio volumio[1200]: info: Ignoring MPD Status Update Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand clear took 2 milliseconds Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ4MGE2NmUxOGE5NTRhOGFkODMyNGI4Y2RmMzM4ZWU3NS5tcDQ/0.flac?token=1766292608~NzYxOTY1YWM3YTYyZGIwZjAyZWRiY2E0MTY3ZmVmMWI5MGJjMjg4Ng==" Dec 21 00:50:08 volumio volumio[1200]: info: Dec 21 00:50:08 volumio volumio[1200]: ---------------------------- MPD announces system playlist update Dec 21 00:50:08 volumio volumio[1200]: info: Ignoring MPD Status Update Dec 21 00:50:08 volumio volumio[1200]: error: updateQueue error: null Dec 21 00:50:08 volumio volumio[1200]: info: Dec 21 00:50:08 volumio volumio[1200]: ---------------------------- MPD announces system playlist update Dec 21 00:50:08 volumio volumio[1200]: info: Ignoring MPD Status Update Dec 21 00:50:08 volumio volumio[1200]: info: ------------------------------ 7ms Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ4MGE2NmUxOGE5NTRhOGFkODMyNGI4Y2RmMzM4ZWU3NS5tcDQ/0.flac?token=1766292608~NzYxOTY1YWM3YTYyZGIwZjAyZWRiY2E0MTY3ZmVmMWI5MGJjMjg4Ng==" took 6 milliseconds Dec 21 00:50:08 volumio volumio[1200]: info: ------------------------------ 5ms Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand play Dec 21 00:50:08 volumio volumio[1200]: info: Dec 21 00:50:08 volumio volumio[1200]: ---------------------------- MPD announces system playlist update Dec 21 00:50:08 volumio volumio[1200]: info: Ignoring MPD Status Update Dec 21 00:50:08 volumio volumio[1200]: info: ------------------------------ 7ms Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand play took 4 milliseconds Dec 21 00:50:08 volumio volumio[1200]: info: ------------------------------ 3ms Dec 21 00:50:08 volumio volumio[1200]: info: Dec 21 00:50:08 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:08 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:08 volumio volumio[1200]: info: Dec 21 00:50:08 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:08 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:08 volumio volumio[1200]: info: FusionDsp - ---- read samplerate, raw: 192000,S32_LE,2,32 Dec 21 00:50:08 volumio volumio[1200]: info: FusionDsp - ---- read samplerate from file: 192000 Dec 21 00:50:08 volumio volumio[1200]: info: FusionDsp - If filter freq >samplerate/2 then disable it Dec 21 00:50:08 volumio volumio[1200]: info: FusionDsp - crossfeed bauer Dec 21 00:50:08 volumio volumio[1200]: info: Dec 21 00:50:08 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand status took 24 milliseconds Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand status took 24 milliseconds Dec 21 00:50:08 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:08 volumio volumio[1200]: info: Dec 21 00:50:08 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:08 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand status took 5 milliseconds Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 5 milliseconds Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 5 milliseconds Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:08 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:08 volumio volumio[1200]: info: CorePlayQueue::getTrack 1 Dec 21 00:50:08 volumio volumio[1200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":1025,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1766292608~NzYxOTY1YWM3YTYyZGIwZjAyZWRiY2E0MTY3ZmVmMWI5MGJjMjg4Ng==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ4MGE2NmUxOGE5NTRhOGFkODMyNGI4Y2RmMzM4ZWU3NS5tcDQ/0.flac?token=1766292608~NzYxOTY1YWM3YTYyZGIwZjAyZWRiY2E0MTY3ZmVmMWI5MGJjMjg4Ng==","trackType":"tidal"} Dec 21 00:50:08 volumio volumio[1200]: verbose: CURRENT POSITION 1 Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::syncState stateService play Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus stop Dec 21 00:50:08 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:08 volumio volumio[1200]: info: CorePlayQueue::getTrack 1 Dec 21 00:50:08 volumio volumio[1200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":1025,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1766292608~NzYxOTY1YWM3YTYyZGIwZjAyZWRiY2E0MTY3ZmVmMWI5MGJjMjg4Ng==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ4MGE2NmUxOGE5NTRhOGFkODMyNGI4Y2RmMzM4ZWU3NS5tcDQ/0.flac?token=1766292608~NzYxOTY1YWM3YTYyZGIwZjAyZWRiY2E0MTY3ZmVmMWI5MGJjMjg4Ng==","trackType":"tidal"} Dec 21 00:50:08 volumio volumio[1200]: verbose: CURRENT POSITION 1 Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::syncState stateService play Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus play Dec 21 00:50:08 volumio volumio[1200]: info: Received an update from plugin. extracting info from payload Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:08 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:08 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:08 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:08 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:08 volumio volumio[1200]: info: ------------------------------ 49ms Dec 21 00:50:08 volumio volumio[1200]: info: ------------------------------ 56ms Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand status took 30 milliseconds Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 28 milliseconds Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:08 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:08 volumio volumio[1200]: info: CorePlayQueue::getTrack 1 Dec 21 00:50:08 volumio volumio[1200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":1025,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1766292608~NzYxOTY1YWM3YTYyZGIwZjAyZWRiY2E0MTY3ZmVmMWI5MGJjMjg4Ng==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ4MGE2NmUxOGE5NTRhOGFkODMyNGI4Y2RmMzM4ZWU3NS5tcDQ/0.flac?token=1766292608~NzYxOTY1YWM3YTYyZGIwZjAyZWRiY2E0MTY3ZmVmMWI5MGJjMjg4Ng==","trackType":"tidal"} Dec 21 00:50:08 volumio volumio[1200]: verbose: CURRENT POSITION 1 Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::syncState stateService play Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus play Dec 21 00:50:08 volumio volumio[1200]: info: Received an update from plugin. extracting info from payload Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:08 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:08 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:08 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:08 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:08 volumio volumio[1200]: info: ------------------------------ 74ms Dec 21 00:50:08 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:08 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:08 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:08 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:08 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 108 milliseconds Dec 21 00:50:08 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:08 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:08 volumio volumio[1200]: info: CorePlayQueue::getTrack 1 Dec 21 00:50:08 volumio volumio[1200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":1025,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1766292608~NzYxOTY1YWM3YTYyZGIwZjAyZWRiY2E0MTY3ZmVmMWI5MGJjMjg4Ng==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQ4MGE2NmUxOGE5NTRhOGFkODMyNGI4Y2RmMzM4ZWU3NS5tcDQ/0.flac?token=1766292608~NzYxOTY1YWM3YTYyZGIwZjAyZWRiY2E0MTY3ZmVmMWI5MGJjMjg4Ng==","trackType":"tidal"} Dec 21 00:50:08 volumio volumio[1200]: verbose: CURRENT POSITION 1 Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::syncState stateService play Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus play Dec 21 00:50:08 volumio volumio[1200]: info: Received an update from plugin. extracting info from payload Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:08 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:08 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:08 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:08 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:08 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:08 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:08 volumio volumio[1200]: info: ------------------------------ 155ms Dec 21 00:50:08 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:08 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:11 volumio volumio[1200]: info: Preload queue cleared Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::ClearQueue Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::stop Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::stPlaybackTimer Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::updateTrackBlock Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrackBlock Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 1 Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 1 Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::serviceStop Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 1 Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::serviceStop Dec 21 00:50:11 volumio volumio[1200]: info: [1766289011424] ControllerTidal::stop Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 21 00:50:11 volumio volumio[1200]: info: ControllerMpd::stop Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand stop Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::clearPlayQueue Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::saveQueue Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushQueue Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::addQueueItems Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::addQueueItems Dec 21 00:50:11 volumio volumio[1200]: info: Preload queue cleared Dec 21 00:50:11 volumio volumio[1200]: info: Adding Item to queue: tidal://song/55391440 Dec 21 00:50:11 volumio volumio[1200]: info: Using cached record of: tidal://song/55391440 Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushQueue Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::saveQueue Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::updateTrackBlock Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrackBlock Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPlay Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::play index 0 Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::addQueueItems Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::addQueueItems Dec 21 00:50:11 volumio volumio[1200]: info: Preload queue cleared Dec 21 00:50:11 volumio volumio[1200]: info: Adding Item to queue: tidal://song/55391441 Dec 21 00:50:11 volumio volumio[1200]: info: Using cached record of: tidal://song/55391441 Dec 21 00:50:11 volumio volumio[1200]: info: Adding Item to queue: tidal://song/55391442 Dec 21 00:50:11 volumio volumio[1200]: info: Using cached record of: tidal://song/55391442 Dec 21 00:50:11 volumio volumio[1200]: info: Adding Item to queue: tidal://song/55391443 Dec 21 00:50:11 volumio volumio[1200]: info: Using cached record of: tidal://song/55391443 Dec 21 00:50:11 volumio volumio[1200]: info: Adding Item to queue: tidal://song/55391444 Dec 21 00:50:11 volumio volumio[1200]: info: Using cached record of: tidal://song/55391444 Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::stop Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushQueue Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::saveQueue Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::play index undefined Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::updateTrackBlock Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrackBlock Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::startPlaybackTimer Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:11 volumio volumio[1200]: info: [1766289011454] ControllerTidal::clearAddPlayTrack Dec 21 00:50:11 volumio volumio[1200]: info: Getting stream with soundQuality HI_RES Dec 21 00:50:11 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:11 volumio volumio[1200]: info: Dec 21 00:50:11 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand stop took 50 milliseconds Dec 21 00:50:11 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:11 volumio volumio[1200]: info: Dec 21 00:50:11 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:11 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand status took 4 milliseconds Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand status took 2 milliseconds Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 4 milliseconds Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 4 milliseconds Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:11 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:11 volumio volumio[1200]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Dec 21 00:50:11 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:11 volumio volumio[1200]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Dec 21 00:50:11 volumio volumio[1200]: info: ------------------------------ 29ms Dec 21 00:50:11 volumio volumio[1200]: info: ------------------------------ 28ms Dec 21 00:50:11 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:11 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:11 volumio volumio[1200]: info: getStreamUrl took 198 milliseconds Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand stop Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand stop took 1 milliseconds Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand clear Dec 21 00:50:11 volumio volumio[1200]: info: Dec 21 00:50:11 volumio volumio[1200]: ---------------------------- MPD announces system playlist update Dec 21 00:50:11 volumio volumio[1200]: info: Ignoring MPD Status Update Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand clear took 2 milliseconds Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzZTYyNTBjYmVlZTZkZmUzYjFhY2RlZmM2NTRiNDFiNC5tcDQ/0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==" Dec 21 00:50:11 volumio volumio[1200]: info: Dec 21 00:50:11 volumio volumio[1200]: ---------------------------- MPD announces system playlist update Dec 21 00:50:11 volumio volumio[1200]: info: Ignoring MPD Status Update Dec 21 00:50:11 volumio volumio[1200]: error: updateQueue error: null Dec 21 00:50:11 volumio volumio[1200]: info: Dec 21 00:50:11 volumio volumio[1200]: ---------------------------- MPD announces system playlist update Dec 21 00:50:11 volumio volumio[1200]: info: Ignoring MPD Status Update Dec 21 00:50:11 volumio volumio[1200]: info: ------------------------------ 4ms Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzZTYyNTBjYmVlZTZkZmUzYjFhY2RlZmM2NTRiNDFiNC5tcDQ/0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==" took 3 milliseconds Dec 21 00:50:11 volumio volumio[1200]: info: ------------------------------ 2ms Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand play Dec 21 00:50:11 volumio volumio[1200]: info: Dec 21 00:50:11 volumio volumio[1200]: ---------------------------- MPD announces system playlist update Dec 21 00:50:11 volumio volumio[1200]: info: Ignoring MPD Status Update Dec 21 00:50:11 volumio volumio[1200]: info: ------------------------------ 4ms Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand play took 3 milliseconds Dec 21 00:50:11 volumio volumio[1200]: info: ------------------------------ 3ms Dec 21 00:50:11 volumio volumio[1200]: info: Dec 21 00:50:11 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:11 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:11 volumio volumio[1200]: info: Dec 21 00:50:11 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:11 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:11 volumio volumio[1200]: info: Dec 21 00:50:11 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:11 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:11 volumio volumio[1200]: info: Dec 21 00:50:11 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand status took 6 milliseconds Dec 21 00:50:11 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:11 volumio volumio[1200]: info: FusionDsp - ---- read samplerate, raw: 192000,S32_LE,2,32 Dec 21 00:50:11 volumio volumio[1200]: info: FusionDsp - ---- read samplerate from file: 192000 Dec 21 00:50:11 volumio volumio[1200]: info: FusionDsp - If filter freq >samplerate/2 then disable it Dec 21 00:50:11 volumio volumio[1200]: info: FusionDsp - crossfeed bauer Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand status took 13 milliseconds Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand status took 13 milliseconds Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand status took 10 milliseconds Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand status took 10 milliseconds Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 11 milliseconds Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:11 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:11 volumio volumio[1200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":85,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzZTYyNTBjYmVlZTZkZmUzYjFhY2RlZmM2NTRiNDFiNC5tcDQ/0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","trackType":"tidal"} Dec 21 00:50:11 volumio volumio[1200]: verbose: CURRENT POSITION 0 Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::syncState stateService play Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus stop Dec 21 00:50:11 volumio volumio[1200]: info: ------------------------------ 22ms Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 5 milliseconds Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 5 milliseconds Dec 21 00:50:11 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 5 milliseconds Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:11 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:11 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:11 volumio volumio[1200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":85,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzZTYyNTBjYmVlZTZkZmUzYjFhY2RlZmM2NTRiNDFiNC5tcDQ/0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","trackType":"tidal"} Dec 21 00:50:11 volumio volumio[1200]: verbose: CURRENT POSITION 0 Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::syncState stateService play Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus play Dec 21 00:50:11 volumio volumio[1200]: info: Received an update from plugin. extracting info from payload Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:11 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:11 volumio volumio[1200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":85,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzZTYyNTBjYmVlZTZkZmUzYjFhY2RlZmM2NTRiNDFiNC5tcDQ/0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","trackType":"tidal"} Dec 21 00:50:11 volumio volumio[1200]: verbose: CURRENT POSITION 0 Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::syncState stateService play Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus play Dec 21 00:50:11 volumio volumio[1200]: info: Received an update from plugin. extracting info from payload Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:11 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:11 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:11 volumio volumio[1200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":85,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzZTYyNTBjYmVlZTZkZmUzYjFhY2RlZmM2NTRiNDFiNC5tcDQ/0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","trackType":"tidal"} Dec 21 00:50:11 volumio volumio[1200]: verbose: CURRENT POSITION 0 Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::syncState stateService play Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus play Dec 21 00:50:11 volumio volumio[1200]: info: Received an update from plugin. extracting info from payload Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:11 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:11 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:11 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:11 volumio volumio[1200]: info: ------------------------------ 74ms Dec 21 00:50:11 volumio volumio[1200]: info: ------------------------------ 73ms Dec 21 00:50:11 volumio volumio[1200]: info: ------------------------------ 73ms Dec 21 00:50:11 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:11 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:11 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:11 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:11 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:11 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:15 volumio volumio[1200]: info: CoreCommandRouter::volumioPause Dec 21 00:50:15 volumio volumio[1200]: info: CoreStateMachine::pause Dec 21 00:50:15 volumio volumio[1200]: info: CoreStateMachine::stPlaybackTimer Dec 21 00:50:15 volumio volumio[1200]: info: CoreStateMachine::servicePause Dec 21 00:50:15 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:15 volumio volumio[1200]: info: CoreCommandRouter::servicePause Dec 21 00:50:15 volumio volumio[1200]: info: [1766289015315] ControllerTidal::pause Dec 21 00:50:15 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 21 00:50:15 volumio volumio[1200]: info: ControllerMpd::pause Dec 21 00:50:15 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand pause Dec 21 00:50:15 volumio volumio[1200]: info: Dec 21 00:50:15 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:15 volumio volumio[1200]: info: sendMpdCommand pause took 3 milliseconds Dec 21 00:50:15 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:15 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:15 volumio volumio[1200]: info: Dec 21 00:50:15 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:15 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:15 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:15 volumio volumio[1200]: info: sendMpdCommand status took 3 milliseconds Dec 21 00:50:15 volumio volumio[1200]: info: sendMpdCommand status took 1 milliseconds Dec 21 00:50:15 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:15 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:15 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:15 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:15 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 21 00:50:15 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 1 milliseconds Dec 21 00:50:15 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:15 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:15 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:15 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:15 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:15 volumio volumio[1200]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":4621,"duration":85,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"4951 Kbps","isStreaming":false,"title":"0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzZTYyNTBjYmVlZTZkZmUzYjFhY2RlZmM2NTRiNDFiNC5tcDQ/0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","trackType":"tidal"} Dec 21 00:50:15 volumio volumio[1200]: verbose: CURRENT POSITION 0 Dec 21 00:50:15 volumio volumio[1200]: info: CoreStateMachine::syncState stateService pause Dec 21 00:50:15 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus pause Dec 21 00:50:15 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:15 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 00:50:15 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:15 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:15 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:15 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:15 volumio volumio[1200]: info: CoreStateMachine::stPlaybackTimer Dec 21 00:50:15 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:15 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:15 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:15 volumio volumio[1200]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":4621,"duration":85,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"4951 Kbps","isStreaming":false,"title":"0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzZTYyNTBjYmVlZTZkZmUzYjFhY2RlZmM2NTRiNDFiNC5tcDQ/0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","trackType":"tidal"} Dec 21 00:50:15 volumio volumio[1200]: verbose: CURRENT POSITION 0 Dec 21 00:50:15 volumio volumio[1200]: info: CoreStateMachine::syncState stateService pause Dec 21 00:50:15 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus pause Dec 21 00:50:15 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:15 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:15 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:15 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:15 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:15 volumio volumio[1200]: info: CoreStateMachine::stPlaybackTimer Dec 21 00:50:15 volumio volumio[1200]: info: ------------------------------ 25ms Dec 21 00:50:15 volumio volumio[1200]: info: ------------------------------ 23ms Dec 21 00:50:15 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:15 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:18 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:18 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Dec 21 00:50:18 volumio volumio[1200]: info: CoreCommandRouter::volumioPlay Dec 21 00:50:18 volumio volumio[1200]: info: CoreStateMachine::play index undefined Dec 21 00:50:18 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 00:50:18 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:18 volumio volumio[1200]: info: CoreStateMachine::startPlaybackTimer Dec 21 00:50:18 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:18 volumio volumio[1200]: info: [1766289018875] ControllerTidal::resume Dec 21 00:50:18 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 21 00:50:18 volumio volumio[1200]: info: ControllerMpd::resume Dec 21 00:50:18 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand play Dec 21 00:50:18 volumio volumio[1200]: info: FusionDsp - ---- read samplerate, raw: 192000,S32_LE,2,32 Dec 21 00:50:18 volumio volumio[1200]: info: FusionDsp - ---- read samplerate from file: 192000 Dec 21 00:50:18 volumio volumio[1200]: info: FusionDsp - If filter freq >samplerate/2 then disable it Dec 21 00:50:18 volumio volumio[1200]: info: FusionDsp - crossfeed bauer Dec 21 00:50:18 volumio volumio[1200]: info: FusionDsp - ---- read samplerate, raw: 192000,S32_LE,2,32 Dec 21 00:50:18 volumio volumio[1200]: info: FusionDsp - ---- read samplerate from file: 192000 Dec 21 00:50:18 volumio volumio[1200]: info: FusionDsp - If filter freq >samplerate/2 then disable it Dec 21 00:50:18 volumio volumio[1200]: info: FusionDsp - crossfeed bauer Dec 21 00:50:18 volumio volumio[1200]: info: Dec 21 00:50:18 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:18 volumio volumio[1200]: info: sendMpdCommand play took 25 milliseconds Dec 21 00:50:18 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:18 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:18 volumio volumio[1200]: info: Dec 21 00:50:18 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:18 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:18 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:18 volumio volumio[1200]: info: sendMpdCommand status took 4 milliseconds Dec 21 00:50:18 volumio volumio[1200]: info: sendMpdCommand status took 3 milliseconds Dec 21 00:50:18 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:18 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:18 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:18 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:18 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 21 00:50:18 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 21 00:50:18 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:18 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:18 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:18 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:18 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:18 volumio volumio[1200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5802,"duration":85,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"4774 Kbps","isStreaming":false,"title":"0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzZTYyNTBjYmVlZTZkZmUzYjFhY2RlZmM2NTRiNDFiNC5tcDQ/0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","trackType":"tidal"} Dec 21 00:50:18 volumio volumio[1200]: verbose: CURRENT POSITION 0 Dec 21 00:50:18 volumio volumio[1200]: info: CoreStateMachine::syncState stateService play Dec 21 00:50:18 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus pause Dec 21 00:50:18 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:18 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 00:50:18 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:18 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:18 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:18 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:18 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:18 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:18 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:18 volumio volumio[1200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5802,"duration":85,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"4774 Kbps","isStreaming":false,"title":"0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzZTYyNTBjYmVlZTZkZmUzYjFhY2RlZmM2NTRiNDFiNC5tcDQ/0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","trackType":"tidal"} Dec 21 00:50:18 volumio volumio[1200]: verbose: CURRENT POSITION 0 Dec 21 00:50:18 volumio volumio[1200]: info: CoreStateMachine::syncState stateService play Dec 21 00:50:18 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus play Dec 21 00:50:18 volumio volumio[1200]: info: Received an update from plugin. extracting info from payload Dec 21 00:50:18 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:18 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 00:50:18 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:18 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:18 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:18 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:18 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:18 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:18 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:18 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:18 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:18 volumio volumio[1200]: info: ------------------------------ 44ms Dec 21 00:50:18 volumio volumio[1200]: info: ------------------------------ 41ms Dec 21 00:50:18 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:18 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:18 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:20 volumio go-librespot[1579]: time="2025-12-21T00:50:20-03:00" level=trace msg="sent dealer ping" Dec 21 00:50:20 volumio go-librespot[1579]: time="2025-12-21T00:50:20-03:00" level=trace msg="received dealer pong" Dec 21 00:50:21 volumio volumio[1200]: info: Preload queue cleared Dec 21 00:50:21 volumio volumio[1200]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::ClearQueue Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::stop Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::stPlaybackTimer Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::updateTrackBlock Dec 21 00:50:21 volumio volumio[1200]: info: CorePlayQueue::getTrackBlock Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:21 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:21 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 00:50:21 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:21 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:21 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:21 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:21 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::serviceStop Dec 21 00:50:21 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:21 volumio volumio[1200]: info: CoreCommandRouter::serviceStop Dec 21 00:50:21 volumio volumio[1200]: info: [1766289021952] ControllerTidal::stop Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 21 00:50:21 volumio volumio[1200]: info: ControllerMpd::stop Dec 21 00:50:21 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand stop Dec 21 00:50:21 volumio volumio[1200]: info: CorePlayQueue::clearPlayQueue Dec 21 00:50:21 volumio volumio[1200]: info: CorePlayQueue::saveQueue Dec 21 00:50:21 volumio volumio[1200]: info: CoreCommandRouter::volumioPushQueue Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::addQueueItems Dec 21 00:50:21 volumio volumio[1200]: info: CorePlayQueue::addQueueItems Dec 21 00:50:21 volumio volumio[1200]: info: Preload queue cleared Dec 21 00:50:21 volumio volumio[1200]: info: Adding Item to queue: tidal://song/55391440 Dec 21 00:50:21 volumio volumio[1200]: info: Using cached record of: tidal://song/55391440 Dec 21 00:50:21 volumio volumio[1200]: info: CoreCommandRouter::volumioPushQueue Dec 21 00:50:21 volumio volumio[1200]: info: CorePlayQueue::saveQueue Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::updateTrackBlock Dec 21 00:50:21 volumio volumio[1200]: info: CorePlayQueue::getTrackBlock Dec 21 00:50:21 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:21 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Dec 21 00:50:21 volumio volumio[1200]: info: CoreCommandRouter::volumioPlay Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::play index 0 Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::stop Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::play index undefined Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 21 00:50:21 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::startPlaybackTimer Dec 21 00:50:21 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:21 volumio volumio[1200]: info: CoreCommandRouter::volumioGetVisibleSources Dec 21 00:50:21 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 21 00:50:21 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 21 00:50:21 volumio volumio[1200]: info: [1766289021967] ControllerTidal::clearAddPlayTrack Dec 21 00:50:21 volumio volumio[1200]: info: Getting stream with soundQuality HI_RES Dec 21 00:50:21 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:21 volumio volumio[1200]: info: Dec 21 00:50:21 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:21 volumio volumio[1200]: info: sendMpdCommand stop took 37 milliseconds Dec 21 00:50:21 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:21 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:21 volumio volumio[1200]: info: Dec 21 00:50:21 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:21 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:21 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:21 volumio volumio[1200]: info: sendMpdCommand status took 2 milliseconds Dec 21 00:50:21 volumio volumio[1200]: info: sendMpdCommand status took 1 milliseconds Dec 21 00:50:21 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:21 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:21 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:21 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:21 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 21 00:50:21 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 21 00:50:21 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:21 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:21 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:21 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:21 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:21 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:21 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:22 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:22 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:22 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:22 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:22 volumio volumio[1200]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Dec 21 00:50:22 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:22 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:22 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:22 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:22 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:22 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:22 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:22 volumio volumio[1200]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd Dec 21 00:50:22 volumio volumio[1200]: info: ------------------------------ 22ms Dec 21 00:50:22 volumio volumio[1200]: info: ------------------------------ 21ms Dec 21 00:50:22 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:22 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:22 volumio volumio[1200]: info: getStreamUrl took 509 milliseconds Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand stop Dec 21 00:50:22 volumio volumio[1200]: info: sendMpdCommand stop took 1 milliseconds Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand clear Dec 21 00:50:22 volumio volumio[1200]: info: Dec 21 00:50:22 volumio volumio[1200]: ---------------------------- MPD announces system playlist update Dec 21 00:50:22 volumio volumio[1200]: info: Ignoring MPD Status Update Dec 21 00:50:22 volumio volumio[1200]: info: sendMpdCommand clear took 1 milliseconds Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzZTYyNTBjYmVlZTZkZmUzYjFhY2RlZmM2NTRiNDFiNC5tcDQ/0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==" Dec 21 00:50:22 volumio volumio[1200]: info: Dec 21 00:50:22 volumio volumio[1200]: ---------------------------- MPD announces system playlist update Dec 21 00:50:22 volumio volumio[1200]: info: Ignoring MPD Status Update Dec 21 00:50:22 volumio volumio[1200]: error: updateQueue error: null Dec 21 00:50:22 volumio volumio[1200]: info: Dec 21 00:50:22 volumio volumio[1200]: ---------------------------- MPD announces system playlist update Dec 21 00:50:22 volumio volumio[1200]: info: Ignoring MPD Status Update Dec 21 00:50:22 volumio volumio[1200]: info: ------------------------------ 3ms Dec 21 00:50:22 volumio volumio[1200]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzZTYyNTBjYmVlZTZkZmUzYjFhY2RlZmM2NTRiNDFiNC5tcDQ/0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==" took 2 milliseconds Dec 21 00:50:22 volumio volumio[1200]: info: ------------------------------ 2ms Dec 21 00:50:22 volumio volumio[1200]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand play Dec 21 00:50:22 volumio volumio[1200]: info: Dec 21 00:50:22 volumio volumio[1200]: ---------------------------- MPD announces system playlist update Dec 21 00:50:22 volumio volumio[1200]: info: Ignoring MPD Status Update Dec 21 00:50:22 volumio volumio[1200]: info: ------------------------------ 3ms Dec 21 00:50:22 volumio volumio[1200]: info: sendMpdCommand play took 2 milliseconds Dec 21 00:50:22 volumio volumio[1200]: info: ------------------------------ 2ms Dec 21 00:50:22 volumio volumio[1200]: info: Dec 21 00:50:22 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:22 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:22 volumio volumio[1200]: info: Dec 21 00:50:22 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:22 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:22 volumio volumio[1200]: info: FusionDsp - ---- read samplerate, raw: 192000,S32_LE,2,32 Dec 21 00:50:22 volumio volumio[1200]: info: FusionDsp - ---- read samplerate from file: 192000 Dec 21 00:50:22 volumio volumio[1200]: info: FusionDsp - If filter freq >samplerate/2 then disable it Dec 21 00:50:22 volumio volumio[1200]: info: FusionDsp - crossfeed bauer Dec 21 00:50:22 volumio volumio[1200]: info: FusionDsp - ---- read samplerate, raw: 192000,S32_LE,2,32 Dec 21 00:50:22 volumio volumio[1200]: info: FusionDsp - ---- read samplerate from file: 192000 Dec 21 00:50:22 volumio volumio[1200]: info: FusionDsp - If filter freq >samplerate/2 then disable it Dec 21 00:50:22 volumio volumio[1200]: info: FusionDsp - crossfeed bauer Dec 21 00:50:22 volumio volumio[1200]: info: Dec 21 00:50:22 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:22 volumio volumio[1200]: info: sendMpdCommand status took 23 milliseconds Dec 21 00:50:22 volumio volumio[1200]: info: sendMpdCommand status took 23 milliseconds Dec 21 00:50:22 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:22 volumio volumio[1200]: info: Dec 21 00:50:22 volumio volumio[1200]: ---------------------------- MPD announces state update: player Dec 21 00:50:22 volumio volumio[1200]: info: ControllerMpd::getState Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand status Dec 21 00:50:22 volumio volumio[1200]: info: sendMpdCommand status took 10 milliseconds Dec 21 00:50:22 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 9 milliseconds Dec 21 00:50:22 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 8 milliseconds Dec 21 00:50:22 volumio volumio[1200]: info: sendMpdCommand status took 6 milliseconds Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::parseState Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 21 00:50:22 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:22 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:22 volumio volumio[1200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":85,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzZTYyNTBjYmVlZTZkZmUzYjFhY2RlZmM2NTRiNDFiNC5tcDQ/0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","trackType":"tidal"} Dec 21 00:50:22 volumio volumio[1200]: verbose: CURRENT POSITION 0 Dec 21 00:50:22 volumio volumio[1200]: info: CoreStateMachine::syncState stateService play Dec 21 00:50:22 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus stop Dec 21 00:50:22 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:22 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:22 volumio volumio[1200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":85,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzZTYyNTBjYmVlZTZkZmUzYjFhY2RlZmM2NTRiNDFiNC5tcDQ/0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","trackType":"tidal"} Dec 21 00:50:22 volumio volumio[1200]: verbose: CURRENT POSITION 0 Dec 21 00:50:22 volumio volumio[1200]: info: CoreStateMachine::syncState stateService play Dec 21 00:50:22 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus play Dec 21 00:50:22 volumio volumio[1200]: info: Received an update from plugin. extracting info from payload Dec 21 00:50:22 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:22 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:22 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:22 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:22 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:22 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:22 volumio volumio[1200]: info: ------------------------------ 57ms Dec 21 00:50:22 volumio volumio[1200]: info: ------------------------------ 73ms Dec 21 00:50:22 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 39 milliseconds Dec 21 00:50:22 volumio volumio[1200]: info: sendMpdCommand playlistinfo took 39 milliseconds Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:22 volumio volumio[1200]: verbose: ControllerMpd::parseTrackInfo Dec 21 00:50:22 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:22 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:22 volumio volumio[1200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":85,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzZTYyNTBjYmVlZTZkZmUzYjFhY2RlZmM2NTRiNDFiNC5tcDQ/0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","trackType":"tidal"} Dec 21 00:50:22 volumio volumio[1200]: verbose: CURRENT POSITION 0 Dec 21 00:50:22 volumio volumio[1200]: info: CoreStateMachine::syncState stateService play Dec 21 00:50:22 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus play Dec 21 00:50:22 volumio volumio[1200]: info: Received an update from plugin. extracting info from payload Dec 21 00:50:22 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:22 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:22 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:22 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:22 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:22 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:22 volumio volumio[1200]: info: ControllerMpd::pushState Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::servicePushState Dec 21 00:50:22 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Dec 21 00:50:22 volumio volumio[1200]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":85,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQzZTYyNTBjYmVlZTZkZmUzYjFhY2RlZmM2NTRiNDFiNC5tcDQ/0.flac?token=1766292595~ZGUyOTBjOTZmNTcwMzlhZGVlOTg0ODMyNTczN2NhNTIzZTVhYzk3ZA==","trackType":"tidal"} Dec 21 00:50:22 volumio volumio[1200]: verbose: CURRENT POSITION 0 Dec 21 00:50:22 volumio volumio[1200]: info: CoreStateMachine::syncState stateService play Dec 21 00:50:22 volumio volumio[1200]: info: CoreStateMachine::syncState currentStatus play Dec 21 00:50:22 volumio volumio[1200]: info: Received an update from plugin. extracting info from payload Dec 21 00:50:22 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:22 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:22 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:22 volumio volumio[1200]: info: CoreStateMachine::pushState Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Dec 21 00:50:22 volumio volumio[1200]: info: MRS: Pushing multiroomSync output update for this device Dec 21 00:50:22 volumio volumio[1200]: info: MRS: Pushing multiroomSync output Dec 21 00:50:22 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Dec 21 00:50:22 volumio volumio[1200]: info: ------------------------------ 91ms Dec 21 00:50:22 volumio volumio[1200]: info: ------------------------------ 86ms Dec 21 00:50:22 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:22 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:22 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:22 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:22 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:22 volumio volumio[1200]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Dec 21 00:50:43 volumio volumio[1200]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 21 00:50:43 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 21 00:50:43 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Dec 21 00:50:43 volumio sudo[15380]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Dec 21 00:50:43 volumio sudo[15380]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:50:43 volumio sudo[15380]: pam_unix(sudo:session): session closed for user root Dec 21 00:50:43 volumio sudo[15385]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 21 00:50:43 volumio sudo[15385]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:50:43 volumio sudo[15385]: pam_unix(sudo:session): session closed for user root Dec 21 00:50:43 volumio sudo[15394]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 21 00:50:43 volumio sudo[15394]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:50:43 volumio sudo[15399]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 21 00:50:43 volumio sudo[15399]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:50:43 volumio sudo[15394]: pam_unix(sudo:session): session closed for user root Dec 21 00:50:43 volumio sudo[15399]: pam_unix(sudo:session): session closed for user root Dec 21 00:50:43 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Dec 21 00:50:43 volumio sudo[15405]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 21 00:50:43 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Dec 21 00:50:43 volumio sudo[15405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:50:43 volumio sudo[15405]: pam_unix(sudo:session): session closed for user root Dec 21 00:50:43 volumio sudo[15408]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 21 00:50:43 volumio sudo[15408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:50:43 volumio sudo[15408]: pam_unix(sudo:session): session closed for user root Dec 21 00:50:43 volumio sudo[15412]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 21 00:50:43 volumio sudo[15412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:50:47 volumio sudo[15412]: pam_unix(sudo:session): session closed for user root Dec 21 00:50:50 volumio go-librespot[1579]: time="2025-12-21T00:50:50-03:00" level=trace msg="sent dealer ping" Dec 21 00:50:50 volumio go-librespot[1579]: time="2025-12-21T00:50:50-03:00" level=trace msg="received dealer pong" Dec 21 00:50:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Dec 21 00:50:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Dec 21 00:50:55 volumio sudo[15434]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 21 00:50:55 volumio sudo[15434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:50:59 volumio sudo[15434]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:09 volumio volumio[1200]: info: CALLMETHOD: system_controller network saveHotspotSettings [object Object] Dec 21 00:51:09 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , saveHotspotSettings Dec 21 00:51:10 volumio sudo[15470]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hostapd/hostapd.conf Dec 21 00:51:10 volumio sudo[15470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:10 volumio sudo[15470]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:10 volumio volumio[1200]: info: Permissions for /etc/hostapd/hostapd.conf Dec 21 00:51:10 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Dec 21 00:51:10 volumio volumio[1200]: info: Discovery: Restarting Advertising due to device name change Dec 21 00:51:10 volumio sudo[15473]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Dec 21 00:51:10 volumio sudo[15473]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:10 volumio systemd[1]: Stopping wireless.service - Wireless Services... Dec 21 00:51:10 volumio systemd[1]: wireless.service: Killing process 1113 (wpa_supplicant) with signal SIGKILL. Dec 21 00:51:10 volumio systemd[1]: wireless.service: Deactivated successfully. Dec 21 00:51:10 volumio systemd[1]: Stopped wireless.service - Wireless Services. Dec 21 00:51:10 volumio systemd[1]: wireless.service: Consumed 8min 47.796s CPU time. Dec 21 00:51:11 volumio systemd[1]: Starting wireless.service - Wireless Services... Dec 21 00:51:11 volumio volumio[1200]: info: Discovery: A device disappeared from network Dec 21 00:51:11 volumio volumio[1200]: info: Discovery: Device volumio disappeared from network Dec 21 00:51:11 volumio volumio[1200]: info: Discovery: A device disappeared from network Dec 21 00:51:11 volumio wireless.js[15481]: WIRELESS.JS: Single Network Mode enabled, only one network device can be active at a time between ethernet and wireless Dec 21 00:51:11 volumio wireless.js[15481]: WIRELESS.JS: Wireless.js initializing wireless flow Dec 21 00:51:11 volumio wireless.js[15481]: WIRELESS.JS: Cleaning previous... Dec 21 00:51:11 volumio sudo[15500]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Dec 21 00:51:11 volumio sudo[15500]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 00:51:11 volumio dhcpcd[795]: wlan0: pid 15501 deleted IP address 192.168.1.10/24 Dec 21 00:51:11 volumio dhcpcd[795]: wlan0: deleting route to 192.168.1.0/24 Dec 21 00:51:11 volumio avahi-daemon[1210]: Withdrawing address record for 192.168.1.10 on wlan0. Dec 21 00:51:11 volumio avahi-daemon[1210]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.10. Dec 21 00:51:11 volumio avahi-daemon[1210]: Interface wlan0.IPv4 no longer relevant for mDNS. Dec 21 00:51:11 volumio sudo[15500]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:11 volumio dhcpcd[795]: wlan0: deleting default route via 192.168.1.1 Dec 21 00:51:11 volumio sudo[15504]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Dec 21 00:51:11 volumio sudo[15504]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 00:51:11 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 21 00:51:11 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Dec 21 00:51:11 volumio systemd[1]: welcome.service: Deactivated successfully. Dec 21 00:51:11 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 21 00:51:11 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 21 00:51:11 volumio dhcpcd[795]: wlan0: rebinding lease of 192.168.1.10 Dec 21 00:51:11 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 21 00:51:12 volumio welcome[15514]: Resolved ip:[0] Dec 21 00:51:12 volumio sudo[15504]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:12 volumio dhcpcd[795]: wlan0: carrier lost Dec 21 00:51:12 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 21 00:51:12 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 21 00:51:12 volumio wireless.js[15481]: WIRELESS.JS: Stopped aP Dec 21 00:51:12 volumio sudo[15538]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 21 00:51:12 volumio sudo[15538]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:12 volumio sudo[15538]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:12 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 21 00:51:12 volumio sudo[15541]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Dec 21 00:51:12 volumio sudo[15541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:12 volumio sudo[15541]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:12 volumio sudo[15549]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 21 00:51:12 volumio sudo[15549]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:12 volumio sudo[15549]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:12 volumio sudo[15553]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Dec 21 00:51:12 volumio sudo[15553]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:13 volumio ntpd[874]: IO: Deleting interface #3 wlan0, 192.168.1.10#123, interface stats: received=255, sent=263, dropped=0, active_time=7181 secs Dec 21 00:51:13 volumio ntpd[874]: PROTO: 170.155.148.1 unlink local addr 192.168.1.10 -> Dec 21 00:51:13 volumio ntpd[874]: PROTO: 162.159.200.1 unlink local addr 192.168.1.10 -> Dec 21 00:51:13 volumio ntpd[874]: PROTO: 170.210.222.10 unlink local addr 192.168.1.10 -> Dec 21 00:51:13 volumio ntpd[874]: PROTO: 168.96.251.195 unlink local addr 192.168.1.10 -> Dec 21 00:51:13 volumio ntpd[874]: PROTO: 162.159.200.123 unlink local addr 192.168.1.10 -> Dec 21 00:51:15 volumio sudo[15553]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:15 volumio wireless.js[15481]: WIRELESS.JS: SETTING APPROPRIATE REG DOMAIN: AR Dec 21 00:51:15 volumio sudo[15559]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Dec 21 00:51:15 volumio sudo[15559]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:15 volumio sudo[15559]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:15 volumio sudo[15561]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set AR Dec 21 00:51:15 volumio sudo[15561]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:15 volumio sudo[15561]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:15 volumio wireless.js[15481]: WIRELESS.JS: SUCCESSFULLY SET NEW REGDOMAIN: AR Dec 21 00:51:15 volumio wireless.js[15481]: WIRELESS.JS: Start wireless flow Dec 21 00:51:15 volumio wireless.js[15481]: WIRELESS.JS: Stopped hotspot (if there).. Dec 21 00:51:15 volumio sudo[15571]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 Dec 21 00:51:15 volumio sudo[15571]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 00:51:15 volumio sudo[15571]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:15 volumio sudo[15573]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down Dec 21 00:51:15 volumio sudo[15573]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 00:51:15 volumio volumio[1200]: info: Discovery: Started advertising with name: Volumio Dec 21 00:51:15 volumio volumio[1200]: compat.c: read() failed: Resource temporarily unavailable Dec 21 00:51:15 volumio volumio[1200]: info: Discovery: mDNS temporarily unavailable during network transition Dec 21 00:51:15 volumio sudo[15573]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:15 volumio wireless.js[15481]: WIRELESS.JS: DHCP IP fallback Dec 21 00:51:15 volumio wireless.js[15481]: WIRELESS.JS: Start ap Dec 21 00:51:16 volumio wpa_supplicant[15579]: Successfully initialized wpa_supplicant Dec 21 00:51:16 volumio sudo[15580]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Dec 21 00:51:16 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 21 00:51:16 volumio sudo[15580]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 00:51:16 volumio dhcpcd[795]: ps_ctl_dispatch: cannot handle another client Dec 21 00:51:16 volumio dhcpcd[795]: control_free: No such file or directory Dec 21 00:51:16 volumio sudo[15580]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:16 volumio wpa_supplicant[15579]: nl80211: kernel reports: Registration to specific type not supported Dec 21 00:51:17 volumio wireless.js[15481]: WIRELESS.JS: trying... Dec 21 00:51:17 volumio sudo[15587]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 21 00:51:17 volumio sudo[15587]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:17 volumio sudo[15587]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:18 volumio wireless.js[15481]: WIRELESS.JS: trying... Dec 21 00:51:18 volumio sudo[15591]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 21 00:51:18 volumio sudo[15591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:18 volumio sudo[15591]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:18 volumio wpa_supplicant[15584]: wlan0: Trying to associate with 5c:8c:30:6c:a4:a9 (SSID='Personal-WiFi-B7F-5Ghz' freq=5805 MHz) Dec 21 00:51:18 volumio wpa_supplicant[15584]: wlan0: Associated with 5c:8c:30:6c:a4:a9 Dec 21 00:51:18 volumio wpa_supplicant[15584]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Dec 21 00:51:18 volumio wpa_supplicant[15584]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=AR Dec 21 00:51:18 volumio wpa_supplicant[15584]: wlan0: WPA: Key negotiation completed with 5c:8c:30:6c:a4:a9 [PTK=CCMP GTK=CCMP] Dec 21 00:51:18 volumio wpa_supplicant[15584]: wlan0: CTRL-EVENT-CONNECTED - Connection to 5c:8c:30:6c:a4:a9 completed [id=0 id_str=] Dec 21 00:51:18 volumio dhcpcd[795]: wlan0: carrier acquired Dec 21 00:51:18 volumio dhcpcd[795]: wlan0: IAID eb:df:24:f3 Dec 21 00:51:18 volumio volumio[1200]: info: Volumio Network Manager: Network status updated: 0 Dec 21 00:51:19 volumio wireless.js[15481]: WIRELESS.JS: trying... Dec 21 00:51:19 volumio sudo[15610]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 21 00:51:19 volumio sudo[15610]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:19 volumio sudo[15610]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:19 volumio dhcpcd[795]: wlan0: soliciting an IPv6 router Dec 21 00:51:20 volumio wireless.js[15481]: WIRELESS.JS: trying... Dec 21 00:51:20 volumio sudo[15614]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 21 00:51:20 volumio sudo[15614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:20 volumio sudo[15614]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:20 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 21 00:51:20 volumio go-librespot[1579]: time="2025-12-21T00:51:20-03:00" level=error msg="did not receive last pong ack from accesspoint, 120s passed" Dec 21 00:51:20 volumio go-librespot[1579]: time="2025-12-21T00:51:20-03:00" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 192.168.1.10:54006->104.154.127.247:4070: use of closed network connection" Dec 21 00:51:20 volumio go-librespot[1579]: time="2025-12-21T00:51:20-03:00" level=trace msg="sent dealer ping" Dec 21 00:51:20 volumio go-librespot[1579]: time="2025-12-21T00:51:20-03:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-guc3.spotify.com: device or resource busy" Dec 21 00:51:20 volumio go-librespot[1579]: time="2025-12-21T00:51:20-03:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-guc3.spotify.com: device or resource busy" Dec 21 00:51:20 volumio go-librespot[1579]: time="2025-12-21T00:51:20-03:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Dec 21 00:51:20 volumio go-librespot[1579]: time="2025-12-21T00:51:20-03:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: device or resource busy" Dec 21 00:51:20 volumio go-librespot[1579]: time="2025-12-21T00:51:20-03:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gew4.spotify.com: device or resource busy" Dec 21 00:51:20 volumio dhcpcd[795]: wlan0: rebinding lease of 192.168.1.10 Dec 21 00:51:20 volumio dhcpcd[795]: wlan0: probing address 192.168.1.10/24 Dec 21 00:51:20 volumio go-librespot[1579]: time="2025-12-21T00:51:20-03:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-guc3.spotify.com: device or resource busy" Dec 21 00:51:20 volumio go-librespot[1579]: time="2025-12-21T00:51:20-03:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-guc3.spotify.com: device or resource busy" Dec 21 00:51:20 volumio go-librespot[1579]: time="2025-12-21T00:51:20-03:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Dec 21 00:51:20 volumio go-librespot[1579]: time="2025-12-21T00:51:20-03:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: device or resource busy" Dec 21 00:51:20 volumio go-librespot[1579]: time="2025-12-21T00:51:20-03:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gew4.spotify.com: device or resource busy" Dec 21 00:51:21 volumio wireless.js[15481]: WIRELESS.JS: trying... Dec 21 00:51:21 volumio sudo[15621]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 21 00:51:21 volumio sudo[15621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:21 volumio sudo[15621]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:21 volumio go-librespot[1579]: time="2025-12-21T00:51:21-03:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-guc3.spotify.com: device or resource busy" Dec 21 00:51:21 volumio go-librespot[1579]: time="2025-12-21T00:51:21-03:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-guc3.spotify.com: device or resource busy" Dec 21 00:51:21 volumio go-librespot[1579]: time="2025-12-21T00:51:21-03:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Dec 21 00:51:21 volumio go-librespot[1579]: time="2025-12-21T00:51:21-03:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: device or resource busy" Dec 21 00:51:21 volumio go-librespot[1579]: time="2025-12-21T00:51:21-03:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gew4.spotify.com: device or resource busy" Dec 21 00:51:22 volumio wireless.js[15481]: WIRELESS.JS: trying... Dec 21 00:51:22 volumio sudo[15625]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 21 00:51:22 volumio sudo[15625]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:22 volumio sudo[15625]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:22 volumio go-librespot[1579]: time="2025-12-21T00:51:22-03:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-guc3.spotify.com: device or resource busy" Dec 21 00:51:22 volumio go-librespot[1579]: time="2025-12-21T00:51:22-03:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-guc3.spotify.com: device or resource busy" Dec 21 00:51:22 volumio go-librespot[1579]: time="2025-12-21T00:51:22-03:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Dec 21 00:51:22 volumio go-librespot[1579]: time="2025-12-21T00:51:22-03:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: device or resource busy" Dec 21 00:51:22 volumio go-librespot[1579]: time="2025-12-21T00:51:22-03:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gew4.spotify.com: device or resource busy" Dec 21 00:51:23 volumio wireless.js[15481]: WIRELESS.JS: trying... Dec 21 00:51:23 volumio sudo[15629]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 21 00:51:23 volumio sudo[15629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:23 volumio sudo[15629]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:24 volumio wireless.js[15481]: WIRELESS.JS: trying... Dec 21 00:51:24 volumio sudo[15633]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 21 00:51:24 volumio sudo[15633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:24 volumio sudo[15633]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:24 volumio kernel: hwmon hwmon1: Voltage normalised Dec 21 00:51:25 volumio wireless.js[15481]: WIRELESS.JS: trying... Dec 21 00:51:25 volumio sudo[15638]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 21 00:51:25 volumio sudo[15638]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:25 volumio sudo[15638]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:25 volumio go-librespot[1579]: time="2025-12-21T00:51:25-03:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-guc3.spotify.com: device or resource busy" Dec 21 00:51:25 volumio go-librespot[1579]: time="2025-12-21T00:51:25-03:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-guc3.spotify.com: device or resource busy" Dec 21 00:51:25 volumio go-librespot[1579]: time="2025-12-21T00:51:25-03:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gae2.spotify.com: device or resource busy" Dec 21 00:51:25 volumio go-librespot[1579]: time="2025-12-21T00:51:25-03:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: device or resource busy" Dec 21 00:51:25 volumio go-librespot[1579]: time="2025-12-21T00:51:25-03:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp: lookup ap-gew4.spotify.com: device or resource busy" Dec 21 00:51:25 volumio volumio[1200]: info: Discovery: Started advertising with name: Volumio Dec 21 00:51:25 volumio volumio[1200]: compat.c: read() failed: Resource temporarily unavailable Dec 21 00:51:25 volumio volumio[1200]: error: Discovery: advertisement error: Error: dns service error: unknown Dec 21 00:51:25 volumio volumio[1200]: info: Discovery: Advertisement raised the following error Error: dns service error: unknown Dec 21 00:51:25 volumio dhcpcd[795]: wlan0: leased 192.168.1.10 for 86400 seconds Dec 21 00:51:25 volumio avahi-daemon[1210]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.10. Dec 21 00:51:25 volumio avahi-daemon[1210]: New relevant interface wlan0.IPv4 for mDNS. Dec 21 00:51:25 volumio avahi-daemon[1210]: Registering new address record for 192.168.1.10 on wlan0.IPv4. Dec 21 00:51:25 volumio dhcpcd[795]: wlan0: adding route to 192.168.1.0/24 Dec 21 00:51:25 volumio dhcpcd[795]: wlan0: adding default route via 192.168.1.1 Dec 21 00:51:25 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 21 00:51:25 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... Dec 21 00:51:25 volumio systemd[1]: welcome.service: Deactivated successfully. Dec 21 00:51:25 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Dec 21 00:51:25 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Dec 21 00:51:25 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Dec 21 00:51:25 volumio welcome[15649]: Resolved ip:[1] 192.168.1.10 Dec 21 00:51:25 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Dec 21 00:51:25 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. Dec 21 00:51:26 volumio wireless.js[15481]: WIRELESS.JS: trying... Dec 21 00:51:26 volumio sudo[15666]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Dec 21 00:51:26 volumio sudo[15666]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 21 00:51:26 volumio sudo[15666]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:26 volumio wireless.js[15481]: WIRELESS.JS: Connected to: ----Personal-WiFi-B7F-5Ghz---- Dec 21 00:51:26 volumio sudo[15669]: root : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 21 00:51:26 volumio sudo[15669]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 21 00:51:26 volumio sudo[15669]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:26 volumio wireless.js[15481]: WIRELESS.JS: ... joined AP, wlan0 IPv4 is 192.168.1.10, ipV6 is undefined Dec 21 00:51:26 volumio wireless.js[15481]: WIRELESS.JS: It's done! AP Dec 21 00:51:26 volumio wireless.js[15481]: WIRELESS.JS: Restarting avahi-daemon... Dec 21 00:51:26 volumio volumio[1200]: compat.c: read() failed: Resource temporarily unavailable Dec 21 00:51:26 volumio volumio[1200]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 21 00:51:26 volumio volumio[1200]: Error: dns service error: unknown Dec 21 00:51:26 volumio volumio[1200]: at MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Dec 21 00:51:26 volumio volumio[1200]: errorCode: -65537 Dec 21 00:51:26 volumio volumio[1200]: } Dec 21 00:51:26 volumio volumio[1200]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 21 00:51:26 volumio wireless.js[15481]: WIRELESS.JS: Notified systemd about wireless ready Dec 21 00:51:26 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 21 00:51:26 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 21 00:51:26 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Dec 21 00:51:26 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 21 00:51:26 volumio systemd[1]: shairport-sync.service: Consumed 3.646s CPU time. Dec 21 00:51:26 volumio systemd[1]: Started wireless.service - Wireless Services. Dec 21 00:51:26 volumio sudo[15473]: pam_unix(sudo:session): session closed for user root Dec 21 00:51:26 volumio systemd[1]: Stopping avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Dec 21 00:51:26 volumio avahi-daemon[1210]: Got SIGTERM, quitting. Dec 21 00:51:26 volumio avahi-daemon[1210]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.10. Dec 21 00:51:26 volumio avahi-daemon[1210]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Dec 21 00:51:26 volumio avahi-daemon[1210]: avahi-daemon 0.8 exiting. Dec 21 00:51:26 volumio systemd[1]: avahi-daemon.service: Deactivated successfully. Dec 21 00:51:26 volumio systemd[1]: Stopped avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Dec 21 00:51:26 volumio systemd[1]: avahi-daemon.service: Consumed 2.278s CPU time. Dec 21 00:51:26 volumio vtcs[14383]: [2025-12-21 00:51:26.260] [tisoc] [error] [avahiImpl.cpp:113] avahiClientCallback() AVAHI_CLIENT_S_COLLISION/AVAHI_CLIENT_FAILURE Dec 21 00:51:26 volumio systemd[1]: Starting avahi-daemon.service - Avahi mDNS/DNS-SD Stack... Dec 21 00:51:26 volumio dbus-daemon[683]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' requested by ':1.62' (uid=0 pid=1246 comm="/usr/sbin/smbd --foreground --no-process-group") Dec 21 00:51:26 volumio avahi-daemon[15689]: Process 1210 died: No such process; trying to remove PID file. (/run/avahi-daemon//pid) Dec 21 00:51:26 volumio avahi-daemon[15689]: Found user 'avahi' (UID 103) and group 'avahi' (GID 109). Dec 21 00:51:26 volumio avahi-daemon[15689]: Successfully dropped root privileges. Dec 21 00:51:26 volumio avahi-daemon[15689]: avahi-daemon 0.8 starting up. Dec 21 00:51:26 volumio dbus-daemon[683]: [system] Successfully activated service 'org.freedesktop.Avahi' Dec 21 00:51:26 volumio systemd[1]: Started avahi-daemon.service - Avahi mDNS/DNS-SD Stack. Dec 21 00:51:26 volumio avahi-daemon[15689]: Successfully called chroot(). Dec 21 00:51:26 volumio avahi-daemon[15689]: Successfully dropped remaining capabilities. Dec 21 00:51:26 volumio avahi-daemon[15689]: No service file found in /etc/avahi/services. Dec 21 00:51:26 volumio avahi-daemon[15689]: *** WARNING: Detected another IPv4 mDNS stack running on this host. This makes mDNS unreliable and is thus not recommended. *** Dec 21 00:51:26 volumio avahi-daemon[15689]: *** WARNING: Detected another IPv6 mDNS stack running on this host. This makes mDNS unreliable and is thus not recommended. *** Dec 21 00:51:26 volumio avahi-daemon[15689]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.10. Dec 21 00:51:26 volumio avahi-daemon[15689]: New relevant interface wlan0.IPv4 for mDNS. Dec 21 00:51:26 volumio avahi-daemon[15689]: Joining mDNS multicast group on interface lo.IPv4 with address 127.0.0.1. Dec 21 00:51:26 volumio avahi-daemon[15689]: New relevant interface lo.IPv4 for mDNS. Dec 21 00:51:26 volumio avahi-daemon[15689]: Network interface enumeration completed. Dec 21 00:51:26 volumio avahi-daemon[15689]: Registering new address record for 192.168.1.10 on wlan0.IPv4. Dec 21 00:51:26 volumio avahi-daemon[15689]: Registering new address record for 127.0.0.1 on lo.IPv4. Dec 21 00:51:26 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 21 00:51:27 volumio sudo[15709]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-21 00:50' Dec 21 00:51:27 volumio sudo[15709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"