May 31 09:42:02 motivo volumio[1227]: info: CoreCommandRouter::volumioNext May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::next May 31 09:42:02 motivo volumio[1227]: info: [1780213322230] ControllerTidal::next May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::next May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::stop May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::stPlaybackTimer May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::updateTrackBlock May 31 09:42:02 motivo volumio[1227]: info: CorePlayQueue::getTrackBlock May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:42:02 motivo volumio[1227]: info: CorePlayQueue::getTrack 154 May 31 09:42:02 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 09:42:02 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:42:02 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:42:02 motivo volumio[1227]: info: CorePlayQueue::getTrack 154 May 31 09:42:02 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:42:02 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::serviceStop May 31 09:42:02 motivo volumio[1227]: info: CorePlayQueue::getTrack 154 May 31 09:42:02 motivo volumio[1227]: info: CoreCommandRouter::serviceStop May 31 09:42:02 motivo volumio[1227]: info: [1780213322245] ControllerTidal::stop May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::setConsumeUpdateService mpd May 31 09:42:02 motivo volumio[1227]: info: ControllerMpd::stop May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand stop May 31 09:42:02 motivo volumio[1227]: info: FusionDsp - Volumio is not playing May 31 09:42:02 motivo volumio[1227]: info: FusionDsp - Clipped samples monitor stopped May 31 09:42:02 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:42:02 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:42:02 motivo volumio[1227]: info: May 31 09:42:02 motivo volumio[1227]: ---------------------------- MPD announces state update: player May 31 09:42:02 motivo volumio[1227]: info: sendMpdCommand stop took 28 milliseconds May 31 09:42:02 motivo volumio[1227]: info: ControllerMpd::getState May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand status May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::play index undefined May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 09:42:02 motivo volumio[1227]: info: CorePlayQueue::getTrack 155 May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::startPlaybackTimer May 31 09:42:02 motivo volumio[1227]: info: CorePlayQueue::getTrack 155 May 31 09:42:02 motivo volumio[1227]: info: [1780213322278] ControllerTidal::clearAddPlayTrack May 31 09:42:02 motivo volumio[1227]: info: Getting stream with soundQuality HI_RES May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::updateTrackBlock May 31 09:42:02 motivo volumio[1227]: info: CorePlayQueue::getTrackBlock May 31 09:42:02 motivo volumio[1227]: info: sendMpdCommand status took 22 milliseconds May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::parseState May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 09:42:02 motivo volumio[1227]: info: sendMpdCommand playlistinfo took 1 milliseconds May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::parseTrackInfo May 31 09:42:02 motivo volumio[1227]: info: ControllerMpd::pushState May 31 09:42:02 motivo volumio[1227]: info: CoreCommandRouter::servicePushState May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:42:02 motivo volumio[1227]: info: CorePlayQueue::getTrack 155 May 31 09:42:02 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 09:42:02 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:42:02 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:42:02 motivo volumio[1227]: info: CorePlayQueue::getTrack 155 May 31 09:42:02 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:42:02 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:42:02 motivo volumio[1227]: info: CorePlayQueue::getTrack 155 May 31 09:42:02 motivo volumio[1227]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 31 09:42:02 motivo volumio[1227]: info: ------------------------------ 40ms May 31 09:42:02 motivo volumio[1227]: info: FusionDsp - Volumio is not playing May 31 09:42:02 motivo volumio[1227]: info: FusionDsp - Clipped samples monitor stopped May 31 09:42:02 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:42:02 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:42:02 motivo volumio[1227]: info: MCU Signalled Playback Inactive May 31 09:42:02 motivo volumio[1227]: info: getStreamUrl took 285 milliseconds May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand stop May 31 09:42:02 motivo volumio[1227]: info: sendMpdCommand stop took 1 milliseconds May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand clear May 31 09:42:02 motivo volumio[1227]: info: May 31 09:42:02 motivo volumio[1227]: ---------------------------- MPD announces system playlist update May 31 09:42:02 motivo volumio[1227]: info: Ignoring MPD Status Update May 31 09:42:02 motivo volumio[1227]: info: sendMpdCommand clear took 2 milliseconds May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQxYmQxYjZiNzExMjhlZWQ3MDYyNWQ2MTIxZmU1Y2IwNS5tcDQ/0.flac?token=1780216922~NjUxNGIzZDJiZWRkNTNmMTRlYTZlNjJkOWUxMDU1NGM2MTcyMDJhNw==" May 31 09:42:02 motivo volumio[1227]: error: updateQueue error: null May 31 09:42:02 motivo volumio[1227]: info: May 31 09:42:02 motivo volumio[1227]: ---------------------------- MPD announces system playlist update May 31 09:42:02 motivo volumio[1227]: info: Ignoring MPD Status Update May 31 09:42:02 motivo volumio[1227]: info: ------------------------------ 2ms May 31 09:42:02 motivo volumio[1227]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQxYmQxYjZiNzExMjhlZWQ3MDYyNWQ2MTIxZmU1Y2IwNS5tcDQ/0.flac?token=1780216922~NjUxNGIzZDJiZWRkNTNmMTRlYTZlNjJkOWUxMDU1NGM2MTcyMDJhNw==" took 2 milliseconds May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::setConsumeUpdateService mpd May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand play May 31 09:42:02 motivo volumio[1227]: info: ------------------------------ 3ms May 31 09:42:02 motivo volumio[1227]: info: sendMpdCommand play took 4 milliseconds May 31 09:42:02 motivo volumio[1227]: info: May 31 09:42:02 motivo volumio[1227]: ---------------------------- MPD announces state update: player May 31 09:42:02 motivo volumio[1227]: info: ControllerMpd::getState May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand status May 31 09:42:02 motivo volumio[1227]: info: May 31 09:42:02 motivo volumio[1227]: ---------------------------- MPD announces state update: player May 31 09:42:02 motivo volumio[1227]: info: sendMpdCommand status took 4 milliseconds May 31 09:42:02 motivo volumio[1227]: info: ControllerMpd::getState May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand status May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::parseState May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 09:42:02 motivo volumio[1227]: info: sendMpdCommand status took 2 milliseconds May 31 09:42:02 motivo volumio[1227]: info: sendMpdCommand playlistinfo took 1 milliseconds May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::parseState May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::parseTrackInfo May 31 09:42:02 motivo volumio[1227]: info: ControllerMpd::pushState May 31 09:42:02 motivo volumio[1227]: info: CoreCommandRouter::servicePushState May 31 09:42:02 motivo volumio[1227]: info: CorePlayQueue::getTrack 155 May 31 09:42:02 motivo volumio[1227]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":214,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1780216922~NjUxNGIzZDJiZWRkNTNmMTRlYTZlNjJkOWUxMDU1NGM2MTcyMDJhNw==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQxYmQxYjZiNzExMjhlZWQ3MDYyNWQ2MTIxZmU1Y2IwNS5tcDQ/0.flac?token=1780216922~NjUxNGIzZDJiZWRkNTNmMTRlYTZlNjJkOWUxMDU1NGM2MTcyMDJhNw==","trackType":"tidal"} May 31 09:42:02 motivo volumio[1227]: verbose: CURRENT POSITION 155 May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::syncState stateService play May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::syncState currentStatus stop May 31 09:42:02 motivo volumio[1227]: info: ------------------------------ 10ms May 31 09:42:02 motivo volumio[1227]: info: sendMpdCommand playlistinfo took 4 milliseconds May 31 09:42:02 motivo volumio[1227]: verbose: ControllerMpd::parseTrackInfo May 31 09:42:02 motivo volumio[1227]: info: ControllerMpd::pushState May 31 09:42:02 motivo volumio[1227]: info: CoreCommandRouter::servicePushState May 31 09:42:02 motivo volumio[1227]: info: CorePlayQueue::getTrack 155 May 31 09:42:02 motivo volumio[1227]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":214,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1780216922~NjUxNGIzZDJiZWRkNTNmMTRlYTZlNjJkOWUxMDU1NGM2MTcyMDJhNw==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiQxYmQxYjZiNzExMjhlZWQ3MDYyNWQ2MTIxZmU1Y2IwNS5tcDQ/0.flac?token=1780216922~NjUxNGIzZDJiZWRkNTNmMTRlYTZlNjJkOWUxMDU1NGM2MTcyMDJhNw==","trackType":"tidal"} May 31 09:42:02 motivo volumio[1227]: verbose: CURRENT POSITION 155 May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::syncState stateService play May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::syncState currentStatus play May 31 09:42:02 motivo volumio[1227]: info: Received an update from plugin. extracting info from payload May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:42:02 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 09:42:02 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:42:02 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:42:02 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:42:02 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:42:02 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:42:02 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:42:02 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:42:02 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:42:02 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:42:02 motivo volumio[1227]: info: ------------------------------ 29ms May 31 09:42:02 motivo volumio[1227]: info: FusionDsp - Volumio is playing May 31 09:42:02 motivo volumio[1227]: warn: FusionDsp - Monitor WebSocket not open, skipping commands May 31 09:42:02 motivo volumio[1227]: info: FusionDsp - Volumio is playing May 31 09:42:02 motivo volumio[1227]: info: Signalling Playback active due to playback status change May 31 09:42:02 motivo volumio[1227]: info: Signalling Playback active due to playback status change May 31 09:42:02 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:42:02 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:42:02 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:42:02 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:42:02 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:02 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:02 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:02 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:02 motivo volumio[1227]: info: MCU Signalled Playback Active May 31 09:42:02 motivo volumio[1227]: info: FusionDsp - ---- read samplerate, raw: 384000,S32_LE,2,32 May 31 09:42:02 motivo volumio[1227]: info: FusionDsp - ---- read samplerate from file: 384000 May 31 09:42:03 motivo volumio[1227]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 31 09:42:03 motivo volumio[1227]: error: FusionDsp - Reload WebSocket error: [object Object] May 31 09:42:07 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:07 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:07 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:07 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:16 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:16 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:16 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:16 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:19 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:42:19 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:19 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:19 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:19 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:21 motivo volumio[1227]: info: Executing endpoint metavolumio May 31 09:42:21 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 09:42:21 motivo volumio[1227]: info: Executing endpoint metavolumio May 31 09:42:21 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 09:42:21 motivo volumio[1227]: info: Executing endpoint metavolumio May 31 09:42:21 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 09:42:22 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:22 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:22 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:22 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:22 motivo volumio[1227]: warn: FusionDsp - Monitor WebSocket not open, skipping commands May 31 09:42:22 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:22 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:22 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:22 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:32 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:32 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:32 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:32 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:33 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 09:42:33 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:42:33 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 09:42:33 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:42:33 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:42:33 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:42:33 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:42:33 motivo volumio[1227]: info: FusionDsp - Volumio is playing May 31 09:42:33 motivo volumio[1227]: info: Signalling Playback active due to playback status change May 31 09:42:33 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:42:33 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:42:33 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:33 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:34 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:42:34 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 09:42:34 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:42:34 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:42:34 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:42:34 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:42:34 motivo volumio[1227]: info: FusionDsp - Volumio is playing May 31 09:42:34 motivo volumio[1227]: info: Signalling Playback active due to playback status change May 31 09:42:34 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:42:34 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:42:34 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:34 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:35 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume May 31 09:42:35 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:42:35 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 09:42:35 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:42:35 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:42:35 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:42:35 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:42:35 motivo volumio[1227]: info: FusionDsp - Volumio is playing May 31 09:42:35 motivo volumio[1227]: info: Signalling Playback active due to playback status change May 31 09:42:35 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:42:35 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:42:35 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:35 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:35 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:42:35 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 09:42:35 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:42:35 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:42:35 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:42:35 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:42:35 motivo volumio[1227]: info: FusionDsp - Volumio is playing May 31 09:42:35 motivo volumio[1227]: info: Signalling Playback active due to playback status change May 31 09:42:35 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:42:35 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:42:35 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:35 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:37 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:37 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:37 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:37 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:42 motivo volumio[1227]: warn: FusionDsp - Monitor WebSocket not open, skipping commands May 31 09:42:43 motivo volumio[1227]: info: CoreCommandRouter::volumioNext May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::next May 31 09:42:43 motivo volumio[1227]: info: [1780213363083] ControllerTidal::next May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::next May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::stop May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::stPlaybackTimer May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::updateTrackBlock May 31 09:42:43 motivo volumio[1227]: info: CorePlayQueue::getTrackBlock May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:42:43 motivo volumio[1227]: info: CorePlayQueue::getTrack 155 May 31 09:42:43 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 09:42:43 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:42:43 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:42:43 motivo volumio[1227]: info: CorePlayQueue::getTrack 155 May 31 09:42:43 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:42:43 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::serviceStop May 31 09:42:43 motivo volumio[1227]: info: CorePlayQueue::getTrack 155 May 31 09:42:43 motivo volumio[1227]: info: CoreCommandRouter::serviceStop May 31 09:42:43 motivo volumio[1227]: info: [1780213363093] ControllerTidal::stop May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::setConsumeUpdateService mpd May 31 09:42:43 motivo volumio[1227]: info: ControllerMpd::stop May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand stop May 31 09:42:43 motivo volumio[1227]: info: FusionDsp - Volumio is not playing May 31 09:42:43 motivo volumio[1227]: info: FusionDsp - Clipped samples monitor stopped May 31 09:42:43 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:42:43 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:42:43 motivo volumio[1227]: info: May 31 09:42:43 motivo volumio[1227]: ---------------------------- MPD announces state update: player May 31 09:42:43 motivo volumio[1227]: info: sendMpdCommand stop took 34 milliseconds May 31 09:42:43 motivo volumio[1227]: info: ControllerMpd::getState May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand status May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::play index undefined May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 09:42:43 motivo volumio[1227]: info: CorePlayQueue::getTrack 156 May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::startPlaybackTimer May 31 09:42:43 motivo volumio[1227]: info: CorePlayQueue::getTrack 156 May 31 09:42:43 motivo volumio[1227]: info: [1780213363130] ControllerTidal::clearAddPlayTrack May 31 09:42:43 motivo volumio[1227]: info: Getting stream with soundQuality HI_RES May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::updateTrackBlock May 31 09:42:43 motivo volumio[1227]: info: CorePlayQueue::getTrackBlock May 31 09:42:43 motivo volumio[1227]: info: sendMpdCommand status took 11 milliseconds May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::parseState May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 09:42:43 motivo volumio[1227]: info: sendMpdCommand playlistinfo took 1 milliseconds May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::parseTrackInfo May 31 09:42:43 motivo volumio[1227]: info: ControllerMpd::pushState May 31 09:42:43 motivo volumio[1227]: info: CoreCommandRouter::servicePushState May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:42:43 motivo volumio[1227]: info: CorePlayQueue::getTrack 156 May 31 09:42:43 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 09:42:43 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:42:43 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:42:43 motivo volumio[1227]: info: CorePlayQueue::getTrack 156 May 31 09:42:43 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:42:43 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:42:43 motivo volumio[1227]: info: CorePlayQueue::getTrack 156 May 31 09:42:43 motivo volumio[1227]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received mpd May 31 09:42:43 motivo volumio[1227]: info: ------------------------------ 29ms May 31 09:42:43 motivo volumio[1227]: info: FusionDsp - Volumio is not playing May 31 09:42:43 motivo volumio[1227]: info: FusionDsp - Clipped samples monitor stopped May 31 09:42:43 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:42:43 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:42:43 motivo volumio[1227]: info: MCU Signalled Playback Inactive May 31 09:42:43 motivo volumio[1227]: info: getStreamUrl took 273 milliseconds May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand stop May 31 09:42:43 motivo volumio[1227]: info: sendMpdCommand stop took 1 milliseconds May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand clear May 31 09:42:43 motivo volumio[1227]: info: May 31 09:42:43 motivo volumio[1227]: ---------------------------- MPD announces system playlist update May 31 09:42:43 motivo volumio[1227]: info: Ignoring MPD Status Update May 31 09:42:43 motivo volumio[1227]: info: sendMpdCommand clear took 1 milliseconds May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicxMzQxYWUyYjAzOTYxZDIxYTdjYmY5NTdlZWFjYzRkNF82MS5tcDQ/0.flac?token=1780216963~ZDVjODZmNGYzNWQ0YTc0ZDllNTBjOGU4OWU2ZDE5OTFhYjIyNGViMg==" May 31 09:42:43 motivo volumio[1227]: error: updateQueue error: null May 31 09:42:43 motivo volumio[1227]: info: ------------------------------ 2ms May 31 09:42:43 motivo volumio[1227]: info: May 31 09:42:43 motivo volumio[1227]: ---------------------------- MPD announces system playlist update May 31 09:42:43 motivo volumio[1227]: info: Ignoring MPD Status Update May 31 09:42:43 motivo volumio[1227]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicxMzQxYWUyYjAzOTYxZDIxYTdjYmY5NTdlZWFjYzRkNF82MS5tcDQ/0.flac?token=1780216963~ZDVjODZmNGYzNWQ0YTc0ZDllNTBjOGU4OWU2ZDE5OTFhYjIyNGViMg==" took 1 milliseconds May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::setConsumeUpdateService mpd May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand play May 31 09:42:43 motivo volumio[1227]: info: ------------------------------ 1ms May 31 09:42:43 motivo volumio[1227]: info: sendMpdCommand play took 1 milliseconds May 31 09:42:43 motivo volumio[1227]: info: May 31 09:42:43 motivo volumio[1227]: ---------------------------- MPD announces state update: player May 31 09:42:43 motivo volumio[1227]: info: ControllerMpd::getState May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand status May 31 09:42:43 motivo volumio[1227]: info: May 31 09:42:43 motivo volumio[1227]: ---------------------------- MPD announces state update: player May 31 09:42:43 motivo volumio[1227]: info: sendMpdCommand status took 6 milliseconds May 31 09:42:43 motivo volumio[1227]: info: ControllerMpd::getState May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand status May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::parseState May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 09:42:43 motivo volumio[1227]: info: sendMpdCommand status took 4 milliseconds May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::parseState May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 09:42:43 motivo volumio[1227]: info: sendMpdCommand playlistinfo took 5 milliseconds May 31 09:42:43 motivo volumio[1227]: info: sendMpdCommand playlistinfo took 1 milliseconds May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::parseTrackInfo May 31 09:42:43 motivo volumio[1227]: verbose: ControllerMpd::parseTrackInfo May 31 09:42:43 motivo volumio[1227]: info: ControllerMpd::pushState May 31 09:42:43 motivo volumio[1227]: info: CoreCommandRouter::servicePushState May 31 09:42:43 motivo volumio[1227]: info: CorePlayQueue::getTrack 156 May 31 09:42:43 motivo volumio[1227]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":226,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1780216963~ZDVjODZmNGYzNWQ0YTc0ZDllNTBjOGU4OWU2ZDE5OTFhYjIyNGViMg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicxMzQxYWUyYjAzOTYxZDIxYTdjYmY5NTdlZWFjYzRkNF82MS5tcDQ/0.flac?token=1780216963~ZDVjODZmNGYzNWQ0YTc0ZDllNTBjOGU4OWU2ZDE5OTFhYjIyNGViMg==","trackType":"tidal"} May 31 09:42:43 motivo volumio[1227]: verbose: CURRENT POSITION 156 May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::syncState stateService play May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::syncState currentStatus stop May 31 09:42:43 motivo volumio[1227]: info: ControllerMpd::pushState May 31 09:42:43 motivo volumio[1227]: info: CoreCommandRouter::servicePushState May 31 09:42:43 motivo volumio[1227]: info: CorePlayQueue::getTrack 156 May 31 09:42:43 motivo volumio[1227]: verbose: STATE SERVICE {"status":"play","position":0,"seek":22,"duration":226,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1780216963~ZDVjODZmNGYzNWQ0YTc0ZDllNTBjOGU4OWU2ZDE5OTFhYjIyNGViMg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicxMzQxYWUyYjAzOTYxZDIxYTdjYmY5NTdlZWFjYzRkNF82MS5tcDQ/0.flac?token=1780216963~ZDVjODZmNGYzNWQ0YTc0ZDllNTBjOGU4OWU2ZDE5OTFhYjIyNGViMg==","trackType":"tidal"} May 31 09:42:43 motivo volumio[1227]: verbose: CURRENT POSITION 156 May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::syncState stateService play May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::syncState currentStatus play May 31 09:42:43 motivo volumio[1227]: info: Received an update from plugin. extracting info from payload May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:42:43 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 09:42:43 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:42:43 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:42:43 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:42:43 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:42:43 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:42:43 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:42:43 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:42:43 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:42:43 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:42:43 motivo volumio[1227]: info: ------------------------------ 40ms May 31 09:42:43 motivo volumio[1227]: info: ------------------------------ 49ms May 31 09:42:43 motivo volumio[1227]: info: FusionDsp - Volumio is playing May 31 09:42:43 motivo volumio[1227]: warn: FusionDsp - Monitor WebSocket not open, skipping commands May 31 09:42:43 motivo volumio[1227]: info: FusionDsp - Volumio is playing May 31 09:42:43 motivo volumio[1227]: info: Signalling Playback active due to playback status change May 31 09:42:43 motivo volumio[1227]: info: Signalling Playback active due to playback status change May 31 09:42:43 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:42:43 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:42:43 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:42:43 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:42:43 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:43 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:43 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:43 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:43 motivo volumio[1227]: info: MCU Signalled Playback Active May 31 09:42:43 motivo volumio[1227]: info: FusionDsp - ---- read samplerate, raw: 384000,S32_LE,2,32 May 31 09:42:43 motivo volumio[1227]: info: FusionDsp - ---- read samplerate from file: 384000 May 31 09:42:43 motivo volumio[1227]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 31 09:42:43 motivo volumio[1227]: error: FusionDsp - Reload WebSocket error: [object Object] May 31 09:42:45 motivo volumio[1227]: info: Executing endpoint metavolumio May 31 09:42:45 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 09:42:45 motivo volumio[1227]: info: Executing endpoint metavolumio May 31 09:42:45 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 09:42:45 motivo volumio[1227]: info: Executing endpoint metavolumio May 31 09:42:45 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 09:42:46 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:46 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:46 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:46 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:49 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:49 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:49 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:49 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:52 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:52 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:52 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:52 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:52 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:52 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:52 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:42:52 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:42:53 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:42:55 motivo volumio[1227]: info: Executing endpoint metavolumio May 31 09:42:55 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 09:42:55 motivo volumio[1227]: info: Executing endpoint metavolumio May 31 09:42:55 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 09:42:55 motivo volumio[1227]: info: Executing endpoint metavolumio May 31 09:42:55 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 31 09:42:58 motivo volumio[1227]: info: CoreCommandRouter::volumioPause May 31 09:42:58 motivo volumio[1227]: info: CoreStateMachine::pause May 31 09:42:58 motivo volumio[1227]: info: CoreStateMachine::stPlaybackTimer May 31 09:42:58 motivo volumio[1227]: info: CoreStateMachine::servicePause May 31 09:42:58 motivo volumio[1227]: info: CorePlayQueue::getTrack 156 May 31 09:42:58 motivo volumio[1227]: info: CoreCommandRouter::servicePause May 31 09:42:58 motivo volumio[1227]: info: [1780213378626] ControllerTidal::pause May 31 09:42:58 motivo volumio[1227]: info: CoreStateMachine::setConsumeUpdateService mpd May 31 09:42:58 motivo volumio[1227]: info: ControllerMpd::pause May 31 09:42:58 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand pause May 31 09:42:58 motivo volumio[1227]: info: May 31 09:42:58 motivo volumio[1227]: ---------------------------- MPD announces state update: player May 31 09:42:58 motivo volumio[1227]: info: sendMpdCommand pause took 3 milliseconds May 31 09:42:58 motivo volumio[1227]: info: ControllerMpd::getState May 31 09:42:58 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand status May 31 09:42:58 motivo volumio[1227]: info: sendMpdCommand status took 1 milliseconds May 31 09:42:58 motivo volumio[1227]: verbose: ControllerMpd::parseState May 31 09:42:58 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 09:42:58 motivo volumio[1227]: info: sendMpdCommand playlistinfo took 0 milliseconds May 31 09:42:58 motivo volumio[1227]: verbose: ControllerMpd::parseTrackInfo May 31 09:42:58 motivo volumio[1227]: info: ControllerMpd::pushState May 31 09:42:58 motivo volumio[1227]: info: CoreCommandRouter::servicePushState May 31 09:42:58 motivo volumio[1227]: info: CorePlayQueue::getTrack 156 May 31 09:42:58 motivo volumio[1227]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":550,"duration":226,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"713 Kbps","isStreaming":false,"title":"0.flac?token=1780216963~ZDVjODZmNGYzNWQ0YTc0ZDllNTBjOGU4OWU2ZDE5OTFhYjIyNGViMg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicxMzQxYWUyYjAzOTYxZDIxYTdjYmY5NTdlZWFjYzRkNF82MS5tcDQ/0.flac?token=1780216963~ZDVjODZmNGYzNWQ0YTc0ZDllNTBjOGU4OWU2ZDE5OTFhYjIyNGViMg==","trackType":"tidal"} May 31 09:42:58 motivo volumio[1227]: verbose: CURRENT POSITION 156 May 31 09:42:58 motivo volumio[1227]: info: CoreStateMachine::syncState stateService pause May 31 09:42:58 motivo volumio[1227]: info: CoreStateMachine::syncState currentStatus pause May 31 09:42:58 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:42:58 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 09:42:58 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:42:58 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:42:58 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:42:58 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:42:58 motivo volumio[1227]: info: CoreStateMachine::stPlaybackTimer May 31 09:42:58 motivo volumio[1227]: info: ------------------------------ 18ms May 31 09:42:58 motivo volumio[1227]: info: FusionDsp - Volumio is not playing May 31 09:42:58 motivo volumio[1227]: info: FusionDsp - Clipped samples monitor stopped May 31 09:42:58 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:42:58 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:42:58 motivo volumio[1227]: info: MCU Signalled Playback Inactive May 31 09:43:01 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:43:01 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] May 31 09:43:01 motivo volumio[1227]: info: CoreCommandRouter::volumioPlay May 31 09:43:01 motivo volumio[1227]: info: CoreStateMachine::play index undefined May 31 09:43:01 motivo volumio[1227]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 09:43:01 motivo volumio[1227]: info: CorePlayQueue::getTrack 156 May 31 09:43:01 motivo volumio[1227]: info: CoreStateMachine::startPlaybackTimer May 31 09:43:01 motivo volumio[1227]: info: CorePlayQueue::getTrack 156 May 31 09:43:01 motivo volumio[1227]: info: [1780213381718] ControllerTidal::resume May 31 09:43:01 motivo volumio[1227]: info: CoreStateMachine::setConsumeUpdateService mpd May 31 09:43:01 motivo volumio[1227]: info: ControllerMpd::resume May 31 09:43:01 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand play May 31 09:43:01 motivo volumio[1227]: info: May 31 09:43:01 motivo volumio[1227]: ---------------------------- MPD announces state update: player May 31 09:43:01 motivo volumio[1227]: info: sendMpdCommand play took 14 milliseconds May 31 09:43:01 motivo volumio[1227]: info: ControllerMpd::getState May 31 09:43:01 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand status May 31 09:43:01 motivo volumio[1227]: info: sendMpdCommand status took 2 milliseconds May 31 09:43:01 motivo volumio[1227]: verbose: ControllerMpd::parseState May 31 09:43:01 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 09:43:01 motivo volumio[1227]: info: sendMpdCommand playlistinfo took 3 milliseconds May 31 09:43:01 motivo volumio[1227]: verbose: ControllerMpd::parseTrackInfo May 31 09:43:01 motivo volumio[1227]: info: ControllerMpd::pushState May 31 09:43:01 motivo volumio[1227]: info: CoreCommandRouter::servicePushState May 31 09:43:01 motivo volumio[1227]: info: CorePlayQueue::getTrack 156 May 31 09:43:01 motivo volumio[1227]: verbose: STATE SERVICE {"status":"play","position":0,"seek":596,"duration":226,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"713 Kbps","isStreaming":false,"title":"0.flac?token=1780216963~ZDVjODZmNGYzNWQ0YTc0ZDllNTBjOGU4OWU2ZDE5OTFhYjIyNGViMg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicxMzQxYWUyYjAzOTYxZDIxYTdjYmY5NTdlZWFjYzRkNF82MS5tcDQ/0.flac?token=1780216963~ZDVjODZmNGYzNWQ0YTc0ZDllNTBjOGU4OWU2ZDE5OTFhYjIyNGViMg==","trackType":"tidal"} May 31 09:43:01 motivo volumio[1227]: verbose: CURRENT POSITION 156 May 31 09:43:01 motivo volumio[1227]: info: CoreStateMachine::syncState stateService play May 31 09:43:01 motivo volumio[1227]: info: CoreStateMachine::syncState currentStatus pause May 31 09:43:01 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:43:01 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 09:43:01 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:43:01 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:43:01 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:43:01 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:43:01 motivo volumio[1227]: info: ------------------------------ 44ms May 31 09:43:01 motivo volumio[1227]: info: FusionDsp - Volumio is playing May 31 09:43:01 motivo volumio[1227]: warn: FusionDsp - Monitor WebSocket not open, skipping commands May 31 09:43:01 motivo volumio[1227]: info: Signalling Playback active due to playback status change May 31 09:43:01 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:43:01 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:43:01 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:01 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:01 motivo volumio[1227]: info: MCU Signalled Playback Active May 31 09:43:01 motivo volumio[1227]: info: FusionDsp - ---- read samplerate, raw: 384000,S32_LE,2,32 May 31 09:43:01 motivo volumio[1227]: info: FusionDsp - ---- read samplerate from file: 384000 May 31 09:43:02 motivo volumio[1227]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 31 09:43:02 motivo volumio[1227]: error: FusionDsp - Reload WebSocket error: [object Object] May 31 09:43:02 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:02 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:02 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:02 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:04 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:04 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:04 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:04 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:05 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:05 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:05 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:05 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:07 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:07 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:07 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:07 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: inputs , getAdditionalUiSection May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:09 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:13 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:13 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:13 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:13 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:16 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:16 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:16 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:16 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:19 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:19 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:19 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:19 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:19 motivo volumio[1227]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] May 31 09:43:19 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions May 31 09:43:19 motivo volumio[1227]: info: Preparing to save Alsa Options, stopping services first May 31 09:43:19 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:43:19 motivo volumio[1227]: info: CoreCommandRouter::volumioPause May 31 09:43:19 motivo volumio[1227]: info: CoreStateMachine::pause May 31 09:43:19 motivo volumio[1227]: info: CoreStateMachine::stPlaybackTimer May 31 09:43:19 motivo volumio[1227]: info: CoreStateMachine::servicePause May 31 09:43:19 motivo volumio[1227]: info: CorePlayQueue::getTrack 156 May 31 09:43:19 motivo volumio[1227]: info: CoreCommandRouter::servicePause May 31 09:43:19 motivo volumio[1227]: info: [1780213399969] ControllerTidal::pause May 31 09:43:19 motivo volumio[1227]: info: CoreStateMachine::setConsumeUpdateService mpd May 31 09:43:19 motivo volumio[1227]: info: ControllerMpd::pause May 31 09:43:19 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand pause May 31 09:43:19 motivo volumio[1227]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"Analog + I2S + Headphones"}} May 31 09:43:19 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 31 09:43:20 motivo volumio[1227]: info: Setting mixer PCM for card Analog + I2S + Headphones May 31 09:43:20 motivo volumio[1227]: info: QobuzConnect: setDeactiveState invoked May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:43:20 motivo volumio[1227]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes May 31 09:43:20 motivo vtcs[6661]: [2026-05-31 09:43:20.068] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE May 31 09:43:20 motivo vtcs[6661]: [2026-05-31 09:43:20.068] [tisoc] [error] [SpkconServer.cpp:378] recv error. socket disconnected May 31 09:43:20 motivo sudo[30122]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 09:43:20 motivo sudo[30122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:20 motivo volumio[1227]: info: Applying Volume Override May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 31 09:43:20 motivo volumio[1227]: info: Updating Volume Controller Parameters: Device: 5 Name: Analog + I2S + Headphones Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 2 May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 31 09:43:20 motivo volumio[1227]: info: Enabling external Volume Control May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: inputs , updateVolumeSettings May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: inputs , retrievevolume May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 09:43:20 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:43:20 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:43:20 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:43:20 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:43:20 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:43:20 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:43:20 motivo systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... May 31 09:43:20 motivo systemd[1]: vtcs.service: Killing process 6663 (vtcs) with signal SIGKILL. May 31 09:43:20 motivo volumio[1227]: info: Preparing to generate the ALSA configuration file May 31 09:43:20 motivo systemd[1]: vtcs.service: Deactivated successfully. May 31 09:43:20 motivo systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. May 31 09:43:20 motivo systemd[1]: vtcs.service: Consumed 1min 2.671s CPU time. May 31 09:43:20 motivo sudo[30122]: pam_unix(sudo:session): session closed for user root May 31 09:43:20 motivo sudo[30143]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 09:43:20 motivo sudo[30143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:20 motivo volumio[1227]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 31 09:43:20 motivo volumio[1227]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 31 09:43:20 motivo volumio[1227]: info: Reading ALSA contributions from plugins. May 31 09:43:20 motivo volumio[1227]: error: Serial API: Failed to decode command: MAXVOL, message: 100 May 31 09:43:20 motivo volumio[1227]: info: May 31 09:43:20 motivo volumio[1227]: ---------------------------- MPD announces state update: player May 31 09:43:20 motivo volumio[1227]: info: sendMpdCommand pause took 348 milliseconds May 31 09:43:20 motivo volumio[1227]: info: ControllerMpd::getState May 31 09:43:20 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand status May 31 09:43:20 motivo volumio[1227]: info: FusionDsp - Volumio is playing May 31 09:43:20 motivo volumio[1227]: info: FusionDsp - Volumio is playing May 31 09:43:20 motivo volumio[1227]: info: Signalling Playback active due to playback status change May 31 09:43:20 motivo sudo[30150]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 31 09:43:20 motivo sudo[30150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:20 motivo volumio[1227]: info: Signalling Playback active due to playback status change May 31 09:43:20 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:43:20 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:43:20 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:43:20 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:43:20 motivo sudo[30143]: pam_unix(sudo:session): session closed for user root May 31 09:43:20 motivo volumio[1227]: info: sendMpdCommand status took 29 milliseconds May 31 09:43:20 motivo volumio[1227]: verbose: ControllerMpd::parseState May 31 09:43:20 motivo volumio[1227]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 09:43:20 motivo volumio[1227]: info: sendMpdCommand playlistinfo took 1 milliseconds May 31 09:43:20 motivo volumio[1227]: verbose: ControllerMpd::parseTrackInfo May 31 09:43:20 motivo volumio[1227]: info: ControllerMpd::pushState May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::servicePushState May 31 09:43:20 motivo volumio[1227]: info: CorePlayQueue::getTrack 156 May 31 09:43:20 motivo volumio[1227]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":1123,"duration":226,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"722 Kbps","isStreaming":false,"title":"0.flac?token=1780216963~ZDVjODZmNGYzNWQ0YTc0ZDllNTBjOGU4OWU2ZDE5OTFhYjIyNGViMg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicxMzQxYWUyYjAzOTYxZDIxYTdjYmY5NTdlZWFjYzRkNF82MS5tcDQ/0.flac?token=1780216963~ZDVjODZmNGYzNWQ0YTc0ZDllNTBjOGU4OWU2ZDE5OTFhYjIyNGViMg==","trackType":"tidal"} May 31 09:43:20 motivo volumio[1227]: verbose: CURRENT POSITION 156 May 31 09:43:20 motivo volumio[1227]: info: CoreStateMachine::syncState stateService pause May 31 09:43:20 motivo volumio[1227]: info: CoreStateMachine::syncState currentStatus pause May 31 09:43:20 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:43:20 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:43:20 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:43:20 motivo volumio[1227]: info: CoreStateMachine::stPlaybackTimer May 31 09:43:20 motivo volumio[1227]: info: ------------------------------ 44ms May 31 09:43:20 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:20 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:20 motivo volumio[1227]: error: FusionDsp - Monitor WebSocket error: [object Object] May 31 09:43:20 motivo volumio[1227]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms May 31 09:43:20 motivo volumio[1227]: info: FusionDsp - Volumio is not playing May 31 09:43:20 motivo volumio[1227]: info: FusionDsp - Clipped samples monitor stopped May 31 09:43:20 motivo sudo[30150]: pam_unix(sudo:session): session closed for user root May 31 09:43:20 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:43:20 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:43:20 motivo sudo[30156]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 31 09:43:20 motivo sudo[30156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 31 09:43:20 motivo systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... May 31 09:43:20 motivo qobuz-connect[6639]: 20260531 09:43:20.437 [6639.6639] INFO SampleApp: Stopping Local configuration server May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: inputs , getAdditionalUiSection May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: Asound.conf file unchanged, so no further update is needed May 31 09:43:20 motivo volumio[1227]: info: Output device has changed, restarting MPD May 31 09:43:20 motivo volumio[1227]: info: Output device has changed, restarting Shairport Sync May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 09:43:20 motivo sudo[30167]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 09:43:20 motivo sudo[30167]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:20 motivo sudo[30167]: pam_unix(sudo:session): session closed for user root May 31 09:43:20 motivo sudo[30169]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 09:43:20 motivo sudo[30169]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:20 motivo volumio[1227]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 09:43:20 motivo volumio[1227]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: QobuzConnect: setDeactiveState invoked May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:43:20 motivo volumio[1227]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo systemd[1]: Stopping mpd.service - Music Player Daemon... May 31 09:43:20 motivo sudo[30179]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 09:43:20 motivo sudo[30179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:20 motivo sudo[30182]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 09:43:20 motivo sudo[30182]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:20 motivo sudo[30179]: pam_unix(sudo:session): session closed for user root May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: Not Reporting Auto name since its the default one May 31 09:43:20 motivo volumio[1227]: info: MCU Signalled Playback Inactive May 31 09:43:20 motivo sudo[30182]: pam_unix(sudo:session): session closed for user root May 31 09:43:20 motivo sudo[30189]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 31 09:43:20 motivo sudo[30189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:20 motivo volumio[1227]: info: MPD Permissions set May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 31 09:43:20 motivo sudo[30189]: pam_unix(sudo:session): session closed for user root May 31 09:43:20 motivo sudo[30199]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 31 09:43:20 motivo sudo[30199]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo sudo[30204]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 31 09:43:20 motivo sudo[30204]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:20 motivo volumio[1227]: info: Starting Shairport Sync May 31 09:43:20 motivo sudo[30204]: pam_unix(sudo:session): session closed for user root May 31 09:43:20 motivo sudo[30212]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 09:43:20 motivo sudo[30212]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:20 motivo systemd[1]: mpd.service: Deactivated successfully. May 31 09:43:20 motivo systemd[1]: Stopped mpd.service - Music Player Daemon. May 31 09:43:20 motivo systemd[1]: mpd.service: Consumed 1h 44min 21.141s CPU time. May 31 09:43:20 motivo sudo[30213]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 31 09:43:20 motivo sudo[30213]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:20 motivo systemd[1]: mpd.socket: Deactivated successfully. May 31 09:43:20 motivo systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 31 09:43:20 motivo systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 31 09:43:20 motivo systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 31 09:43:20 motivo systemd[1]: Starting mpd.service - Music Player Daemon... May 31 09:43:20 motivo systemd[1]: Stopping raat-daemon.service - RAAT DAEMON... May 31 09:43:20 motivo systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 31 09:43:20 motivo systemd[1]: raat-daemon.service: Deactivated successfully. May 31 09:43:20 motivo systemd[1]: Stopped raat-daemon.service - RAAT DAEMON. May 31 09:43:20 motivo systemd[1]: shairport-sync.service: Deactivated successfully. May 31 09:43:20 motivo systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 31 09:43:20 motivo systemd[1]: shairport-sync.service: Consumed 7min 34.521s CPU time. May 31 09:43:20 motivo systemd[1]: Started raat-daemon.service - RAAT DAEMON. May 31 09:43:20 motivo sudo[30213]: pam_unix(sudo:session): session closed for user root May 31 09:43:20 motivo systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 31 09:43:21 motivo sudo[30212]: pam_unix(sudo:session): session closed for user root May 31 09:43:21 motivo volumio[1227]: info: Raat Daemon started successfully May 31 09:43:21 motivo volumio[1227]: info: Shairport-Sync Started May 31 09:43:21 motivo sudo[30217]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 31 09:43:21 motivo sudo[30217]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 31 09:43:21 motivo volumio[1227]: info: Executing endpoint restartRAATSocket May 31 09:43:21 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 31 09:43:21 motivo sudo[30217]: pam_unix(sudo:session): session closed for user root May 31 09:43:21 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:21 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:21 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:21 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:21 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:21 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:21 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:21 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:21 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:21 motivo volumio[1227]: info: Not Reporting Auto name since its the default one May 31 09:43:21 motivo volumio[1227]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 May 31 09:43:21 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 31 09:43:21 motivo sudo[30257]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 31 09:43:21 motivo sudo[30257]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:21 motivo sudo[30257]: pam_unix(sudo:session): session closed for user root May 31 09:43:21 motivo sudo[30259]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 31 09:43:21 motivo sudo[30259]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:21 motivo systemd[1]: Stopping raat-daemon.service - RAAT DAEMON... May 31 09:43:21 motivo systemd[1]: raat-daemon.service: Deactivated successfully. May 31 09:43:21 motivo systemd[1]: Stopped raat-daemon.service - RAAT DAEMON. May 31 09:43:21 motivo systemd[1]: Started raat-daemon.service - RAAT DAEMON. May 31 09:43:21 motivo sudo[30259]: pam_unix(sudo:session): session closed for user root May 31 09:43:21 motivo volumio[1227]: info: Raat Daemon started successfully May 31 09:43:21 motivo volumio[1227]: info: Executing endpoint restartRAATSocket May 31 09:43:21 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 31 09:43:21 motivo volumio[1227]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 May 31 09:43:22 motivo qobuz-connect[6639]: 20260531 09:43:22.025 [6639.6639] INFO SampleApp: shat down connection on UNIX socket May 31 09:43:22 motivo volumio[1227]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected May 31 09:43:22 motivo volumio[1227]: info: QobuzConnect: setDeactiveState invoked May 31 09:43:22 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:43:22 motivo systemd[1]: qobuz-connect.service: Deactivated successfully. May 31 09:43:22 motivo systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. May 31 09:43:22 motivo systemd[1]: qobuz-connect.service: Consumed 1.653s CPU time. May 31 09:43:22 motivo systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. May 31 09:43:22 motivo sudo[30199]: pam_unix(sudo:session): session closed for user root May 31 09:43:22 motivo sudo[30156]: pam_unix(sudo:session): session closed for user root May 31 09:43:22 motivo volumio[1227]: info: Executing endpoint qc_getconfig May 31 09:43:22 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig May 31 09:43:22 motivo qobuz-connect[30272]: 20260531 09:43:22.177 [30272.30272] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket May 31 09:43:22 motivo qobuz-connect[30272]: 20260531 09:43:22.181 [30272.30272] INFO VolumeManager: [0x1f5ef68]: Setting new playback volume: 75 May 31 09:43:22 motivo qobuz-connect[30272]: 20260531 09:43:22.181 [30272.30272] INFO VolumeManager: [0x1f5ef68]: Setting new mute state: 0 May 31 09:43:22 motivo qobuz-connect[30272]: 20260531 09:43:22.181 [30272.30272] INFO AudioStreamManager: [0x1f5ecc0]: Setting new audio download buffer size: 1048576 May 31 09:43:22 motivo qobuz-connect[30272]: 20260531 09:43:22.181 [30272.30272] INFO QobuzConnect: [0x1f5f830]: Client initialized! May 31 09:43:22 motivo qobuz-connect[30272]: 20260531 09:43:22.181 [30272.30272] INFO SampleApp: Starting Avahi advertising, name: Motivo, service name: _qobuz-connect._tcp May 31 09:43:22 motivo volumio[1227]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] May 31 09:43:22 motivo volumio[1227]: info: QobuzConnect: QOBUZ Connect daemon connected May 31 09:43:22 motivo qobuz-connect[30272]: 20260531 09:43:22.196 [30272.30272] INFO LocalConfigManager: [0x1f5e9e8]: Starting Local Configuration server May 31 09:43:22 motivo qobuz-connect[30272]: 20260531 09:43:22.196 [30272.30272] INFO SampleApp: Starting Local configuration server May 31 09:43:22 motivo qobuz-connect[30272]: 20260531 09:43:22.196 [30272.30272] INFO SampleApp: Connected to UNIX socket client 0x1f49818 May 31 09:43:22 motivo qobuz-connect[30272]: 20260531 09:43:22.327 [30272.30272] INFO SampleApp: Playback volume changed: 75 May 31 09:43:22 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:43:22 motivo mpd[30233]: 2026-05-31T09:43:22 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 31 09:43:22 motivo systemd[1]: Started mpd.service - Music Player Daemon. May 31 09:43:23 motivo sudo[30169]: pam_unix(sudo:session): session closed for user root May 31 09:43:23 motivo volumio[1227]: error: updateQueue error: null May 31 09:43:23 motivo volumio[1227]: info: TidalConnect service stoped! May 31 09:43:23 motivo volumio[1227]: info: TidalConnect service stoped! May 31 09:43:23 motivo volumio[1227]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions May 31 09:43:23 motivo volumio[1227]: info: Preparing to save Alsa Options, stopping services first May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::volumioPause May 31 09:43:23 motivo volumio[1227]: info: CoreStateMachine::pause May 31 09:43:23 motivo volumio[1227]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"Analog + I2S + Headphones"}} May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 31 09:43:23 motivo volumio[1227]: info: Setting mixer PCM for card Analog + I2S + Headphones May 31 09:43:23 motivo volumio[1227]: info: QobuzConnect: setDeactiveState invoked May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:43:23 motivo volumio[1227]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes May 31 09:43:23 motivo sudo[30294]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 09:43:23 motivo sudo[30294]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:23 motivo volumio[1227]: info: Applying Volume Override May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 31 09:43:23 motivo volumio[1227]: info: Updating Volume Controller Parameters: Device: 5 Name: Analog + I2S + Headphones Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 2 May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 31 09:43:23 motivo volumio[1227]: info: Enabling external Volume Control May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: inputs , updateVolumeSettings May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: inputs , retrievevolume May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 09:43:23 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:43:23 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:43:23 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:43:23 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:43:23 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:43:23 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:43:23 motivo volumio[1227]: info: Preparing to generate the ALSA configuration file May 31 09:43:23 motivo sudo[30294]: pam_unix(sudo:session): session closed for user root May 31 09:43:23 motivo sudo[30301]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 09:43:23 motivo sudo[30301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:23 motivo volumio[1227]: error: Serial API: Failed to decode command: MAXVOL, message: 100 May 31 09:43:23 motivo volumio[1227]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 31 09:43:23 motivo volumio[1227]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 31 09:43:23 motivo volumio[1227]: info: Reading ALSA contributions from plugins. May 31 09:43:23 motivo volumio[1227]: info: FusionDsp - Volumio is not playing May 31 09:43:23 motivo volumio[1227]: info: FusionDsp - Clipped samples monitor stopped May 31 09:43:23 motivo volumio[1227]: info: FusionDsp - Volumio is not playing May 31 09:43:23 motivo volumio[1227]: info: FusionDsp - Clipped samples monitor stopped May 31 09:43:23 motivo sudo[30308]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 31 09:43:23 motivo sudo[30308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:23 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:43:23 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:43:23 motivo sudo[30301]: pam_unix(sudo:session): session closed for user root May 31 09:43:23 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:43:23 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:43:23 motivo sudo[30308]: pam_unix(sudo:session): session closed for user root May 31 09:43:23 motivo sudo[30312]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 31 09:43:23 motivo sudo[30312]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:23 motivo systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... May 31 09:43:23 motivo qobuz-connect[30272]: 20260531 09:43:23.713 [30272.30272] INFO SampleApp: Stopping Local configuration server May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: inputs , getAdditionalUiSection May 31 09:43:23 motivo volumio[1227]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 31 09:43:23 motivo volumio[1227]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 31 09:43:23 motivo volumio[1227]: info: TidalConnect service stoped! May 31 09:43:23 motivo sudo[30325]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 31 09:43:23 motivo sudo[30325]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:23 motivo volumio[1227]: info: TidalConnect service stoped! May 31 09:43:23 motivo volumio[1227]: info: RAAT: Requesting Headphone Status May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:23 motivo volumio[1227]: info: Asound.conf file unchanged, so no further update is needed May 31 09:43:23 motivo volumio[1227]: info: Output device has changed, restarting MPD May 31 09:43:23 motivo systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. May 31 09:43:23 motivo sudo[30325]: pam_unix(sudo:session): session closed for user root May 31 09:43:23 motivo volumio[1227]: info: Output device has changed, restarting Shairport Sync May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 09:43:23 motivo sudo[30339]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 09:43:23 motivo sudo[30343]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 09:43:23 motivo sudo[30339]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:23 motivo sudo[30343]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:23 motivo volumio[1227]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 09:43:23 motivo volumio[1227]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:23 motivo sudo[30339]: pam_unix(sudo:session): session closed for user root May 31 09:43:23 motivo volumio[1227]: info: QobuzConnect: setDeactiveState invoked May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:43:23 motivo volumio[1227]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes May 31 09:43:23 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:23 motivo systemd[1]: Stopping mpd.service - Music Player Daemon... May 31 09:43:23 motivo systemd[1]: mpd.service: Deactivated successfully. May 31 09:43:23 motivo systemd[1]: Stopped mpd.service - Music Player Daemon. May 31 09:43:23 motivo systemd[1]: mpd.service: Consumed 1.872s CPU time. May 31 09:43:23 motivo systemd[1]: mpd.socket: Deactivated successfully. May 31 09:43:23 motivo systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 31 09:43:23 motivo systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 31 09:43:23 motivo sudo[30353]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 09:43:23 motivo sudo[30353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:23 motivo sudo[30355]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 31 09:43:23 motivo sudo[30355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:23 motivo systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 31 09:43:23 motivo systemd[1]: Starting mpd.service - Music Player Daemon... May 31 09:43:23 motivo volumio[1227]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 31 09:43:23 motivo volumio[1227]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 31 09:43:24 motivo sudo[30365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service May 31 09:43:24 motivo sudo[30365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:24 motivo sudo[30368]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 31 09:43:24 motivo systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... May 31 09:43:24 motivo sudo[30368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:24 motivo systemd[1]: vtcs.service: Deactivated successfully. May 31 09:43:24 motivo systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: Not Reporting Auto name since its the default one May 31 09:43:24 motivo volumio[1227]: info: MPD Permissions set May 31 09:43:24 motivo volumio[1227]: info: MCU Signalled Headphone Mode Disabled May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 31 09:43:24 motivo volumio[1227]: info: Reporting Headphone State: false May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo sudo[30365]: pam_unix(sudo:session): session closed for user root May 31 09:43:24 motivo sudo[30353]: pam_unix(sudo:session): session closed for user root May 31 09:43:24 motivo sudo[30355]: pam_unix(sudo:session): session closed for user root May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::volumioRetrieveVolumeLevels May 31 09:43:24 motivo volumio[1227]: info: CoreStateMachine::getcurrentVolume May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::volumioRetrievevolume May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::executeOnPlugin: inputs , retrievevolume May 31 09:43:24 motivo volumio[1227]: info: CoreStateMachine::pushState May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::volumioPushState May 31 09:43:24 motivo volumio[1227]: info: CoreCommandRouter::volumioGetState May 31 09:43:24 motivo volumio[1227]: info: MRS: Pushing multiroomSync output update for this device May 31 09:43:24 motivo volumio[1227]: info: MRS: Pushing multiroomSync output May 31 09:43:24 motivo volumio[1227]: info: FusionDsp - Volumio is not playing May 31 09:43:24 motivo volumio[1227]: info: FusionDsp - Clipped samples monitor stopped May 31 09:43:24 motivo sudo[30363]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 31 09:43:24 motivo sudo[30363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 31 09:43:24 motivo systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. May 31 09:43:24 motivo sudo[30368]: pam_unix(sudo:session): session closed for user root May 31 09:43:24 motivo sudo[30380]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service May 31 09:43:24 motivo sudo[30380]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 09:43:24 motivo sudo[30363]: pam_unix(sudo:session): session closed for user root May 31 09:43:24 motivo volumio[1227]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 31 09:43:24 motivo volumio[1227]: info: Updating RAAT Signal Path May 31 09:43:24 motivo volumio[1227]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 09:43:24 motivo volumio[1227]: Error: Command failed: /usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3 May 31 09:43:24 motivo volumio[1227]: Job for vtcs.service canceled. May 31 09:43:24 motivo volumio[1227]: at ChildProcess.exithandler (node:child_process:421:12) May 31 09:43:24 motivo volumio[1227]: at ChildProcess.emit (node:events:514:28) May 31 09:43:24 motivo volumio[1227]: at maybeClose (node:internal/child_process:1105:16) May 31 09:43:24 motivo volumio[1227]: at Socket. (node:internal/child_process:457:11) May 31 09:43:24 motivo volumio[1227]: at Socket.emit (node:events:514:28) May 31 09:43:24 motivo volumio[1227]: at Pipe. (node:net:337:12) { May 31 09:43:24 motivo volumio[1227]: code: 1, May 31 09:43:24 motivo volumio[1227]: killed: false, May 31 09:43:24 motivo volumio[1227]: signal: null, May 31 09:43:24 motivo volumio[1227]: cmd: '/usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3', May 31 09:43:24 motivo volumio[1227]: stdout: '', May 31 09:43:24 motivo volumio[1227]: stderr: 'Job for vtcs.service canceled.\n' May 31 09:43:24 motivo volumio[1227]: } May 31 09:43:24 motivo volumio[1227]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 09:43:24 motivo qobuz-connect[30272]: 20260531 09:43:24.206 [30272.30272] INFO SampleApp: shat down connection on UNIX socket May 31 09:43:24 motivo systemd[1]: qobuz-connect.service: Deactivated successfully. May 31 09:43:24 motivo systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. May 31 09:43:24 motivo systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. May 31 09:43:24 motivo sudo[30380]: pam_unix(sudo:session): session closed for user root May 31 09:43:24 motivo sudo[30312]: pam_unix(sudo:session): session closed for user root May 31 09:43:24 motivo sudo[30403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-31 09:42' May 31 09:43:24 motivo sudo[30403]: 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="9ccd1247f8cab3c5d64c23a96d243f6bfa34d032" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="e94c5b27ab2607d3918cd6a4973c240c1b2ce37e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="motivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat May 16 00:11:09 UTC 2026" VOLUMIO_VERSION="4.156" VOLUMIO_HARDWARE="cm4" VOLUMIO_DEVICENAME="CM4" VOLUMIO_VENDOR_MODEL="Volumio Motivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Motivo" VOLUMIO_HASH="67ebfb15187d4de64266b21b13da5443"