-- Logs begin at Sun 2025-09-14 21:44:26 JST, end at Mon 2025-09-15 18:26:41 JST. -- Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getTrack 14 Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::startPlaybackTimer Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getTrack 14 Sep 15 18:25:00 motivo volumio[15151]: info: [1757928300017] ControllerUPNPBrowser::clearAddPlayTrack Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand stop Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 39ms Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 39ms Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 39ms Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getTrack 14 Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getTrack 14 Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getTrack 14 Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getTrack 15 Sep 15 18:25:00 motivo volumio[15151]: info: Prefetching next song Sep 15 18:25:00 motivo volumio[15151]: info: Doing Prefetch in UPNP Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.104.241:50002/m/NDLNA/420.flac" Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:00 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand stop took 15 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand add "http://192.168.104.241:50002/m/NDLNA/420.flac" took 2 milliseconds Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand clear Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand consume 1 Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:00 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:00 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:00 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:00 motivo volumio[15151]: error: updateQueue error: null Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 25ms Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand clear took 24 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand consume 1 took 24 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 3ms Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.104.241:50002/m/NDLNA/415.flac" Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:00 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:00 motivo volumio[15151]: error: updateQueue error: null Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 4ms Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:00 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:00 motivo volumio[15151]: error: updateQueue error: null Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 39ms Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.104.241:50002/m/NDLNA/415.flac" Sep 15 18:25:00 motivo volumio[15151]: error: updateQueue error: null Sep 15 18:25:00 motivo volumio[15151]: error: updateQueue error: null Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:00 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 40ms Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 37ms Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand add "http://192.168.104.241:50002/m/NDLNA/415.flac" took 2 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService mpd Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand play Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:00 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:00 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 6ms Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand play took 4 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 5ms Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 4ms Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces state update: player Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::getState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand status Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces state update: player Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::getState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand status Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces state update: player Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::getState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand status Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces state update: player Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand status took 28 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::getState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand status Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand status took 27 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand status took 26 milliseconds Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::parseState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::parseState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::parseState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces state update: player Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::getState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand status Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces state update: player Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::getState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand status Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:00 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces state update: player Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand status took 8 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::getState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand status Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::parseState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:00 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces state update: player Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::getState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand status Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand playlistinfo took 13 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand playlistinfo took 11 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand playlistinfo took 11 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand status took 10 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand status took 9 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 8ms Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand status took 7 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand playlistinfo took 7 milliseconds Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::parseTrackInfo Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::parseTrackInfo Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::parseTrackInfo Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::parseState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::parseState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::parseState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::parseTrackInfo Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::servicePushState Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getTrack 14 Sep 15 18:25:00 motivo volumio[15151]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":5,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"UP with ATM #6","artist":"Yuji Ohno & Lupintic Five","album":"UP↑ with Yuji Ohno & Lupintic Five","uri":"http://192.168.104.241:50002/m/NDLNA/415.flac","trackType":"flac"} Sep 15 18:25:00 motivo volumio[15151]: verbose: CURRENT POSITION 14 Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState stateService play Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState currentStatus stop Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::servicePushState Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getTrack 14 Sep 15 18:25:00 motivo volumio[15151]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":5,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"UP with ATM #6","artist":"Yuji Ohno & Lupintic Five","album":"UP↑ with Yuji Ohno & Lupintic Five","uri":"http://192.168.104.241:50002/m/NDLNA/415.flac","trackType":"flac"} Sep 15 18:25:00 motivo volumio[15151]: verbose: CURRENT POSITION 14 Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState stateService play Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState currentStatus play Sep 15 18:25:00 motivo volumio[15151]: info: Received an update from plugin. extracting info from payload Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::servicePushState Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getTrack 14 Sep 15 18:25:00 motivo volumio[15151]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":5,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"UP with ATM #6","artist":"Yuji Ohno & Lupintic Five","album":"UP↑ with Yuji Ohno & Lupintic Five","uri":"http://192.168.104.241:50002/m/NDLNA/415.flac","trackType":"flac"} Sep 15 18:25:00 motivo volumio[15151]: verbose: CURRENT POSITION 14 Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState stateService play Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState currentStatus play Sep 15 18:25:00 motivo volumio[15151]: info: Received an update from plugin. extracting info from payload Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::servicePushState Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getTrack 14 Sep 15 18:25:00 motivo volumio[15151]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":5,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1527 Kbps","isStreaming":false,"title":"UP with ATM #6","artist":"Yuji Ohno & Lupintic Five","album":"UP↑ with Yuji Ohno & Lupintic Five","uri":"http://192.168.104.241:50002/m/NDLNA/415.flac","trackType":"flac"} Sep 15 18:25:00 motivo volumio[15151]: verbose: CURRENT POSITION 14 Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState stateService play Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState currentStatus play Sep 15 18:25:00 motivo volumio[15151]: info: Received an update from plugin. extracting info from payload Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 68ms Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 84ms Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 84ms Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 60ms Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:00 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:00 motivo volumio[15151]: info: Sep 15 18:25:00 motivo volumio[15151]: ---------------------------- MPD announces state update: player Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::getState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand status Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 51ms Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand status took 50 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand playlistinfo took 46 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand playlistinfo took 45 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand playlistinfo took 45 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 4ms Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand status took 3 milliseconds Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::parseState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::parseTrackInfo Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::parseState Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand playlistinfo Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::servicePushState Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getTrack 14 Sep 15 18:25:00 motivo volumio[15151]: verbose: STATE SERVICE {"status":"play","position":0,"seek":147,"duration":5,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1657 Kbps","isStreaming":false,"title":"UP with ATM #6","artist":"Yuji Ohno & Lupintic Five","album":"UP↑ with Yuji Ohno & Lupintic Five","uri":"http://192.168.104.241:50002/m/NDLNA/415.flac","trackType":"flac"} Sep 15 18:25:00 motivo volumio[15151]: verbose: CURRENT POSITION 14 Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState stateService play Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState currentStatus play Sep 15 18:25:00 motivo volumio[15151]: info: Received an update from plugin. extracting info from payload Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::servicePushState Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getTrack 14 Sep 15 18:25:00 motivo volumio[15151]: verbose: STATE SERVICE {"status":"play","position":0,"seek":483,"duration":5,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1633 Kbps","isStreaming":false,"title":"UP with ATM #6","artist":"Yuji Ohno & Lupintic Five","album":"UP↑ with Yuji Ohno & Lupintic Five","uri":"http://192.168.104.241:50002/m/NDLNA/415.flac","trackType":"flac"} Sep 15 18:25:00 motivo volumio[15151]: verbose: CURRENT POSITION 14 Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState stateService play Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState currentStatus play Sep 15 18:25:00 motivo volumio[15151]: info: Received an update from plugin. extracting info from payload Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::servicePushState Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getTrack 14 Sep 15 18:25:00 motivo volumio[15151]: verbose: STATE SERVICE {"status":"play","position":0,"seek":650,"duration":5,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1698 Kbps","isStreaming":false,"title":"UP with ATM #6","artist":"Yuji Ohno & Lupintic Five","album":"UP↑ with Yuji Ohno & Lupintic Five","uri":"http://192.168.104.241:50002/m/NDLNA/415.flac","trackType":"flac"} Sep 15 18:25:00 motivo volumio[15151]: verbose: CURRENT POSITION 14 Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState stateService play Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState currentStatus play Sep 15 18:25:00 motivo volumio[15151]: info: Received an update from plugin. extracting info from payload Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 99ms Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 99ms Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 99ms Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand playlistinfo took 120 milliseconds Sep 15 18:25:00 motivo volumio[15151]: info: sendMpdCommand playlistinfo took 121 milliseconds Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::parseTrackInfo Sep 15 18:25:00 motivo volumio[15151]: verbose: ControllerMpd::parseTrackInfo Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::servicePushState Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getTrack 14 Sep 15 18:25:00 motivo volumio[15151]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1238,"duration":5,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1609 Kbps","isStreaming":false,"title":"UP with ATM #6","artist":"Yuji Ohno & Lupintic Five","album":"UP↑ with Yuji Ohno & Lupintic Five","uri":"http://192.168.104.241:50002/m/NDLNA/415.flac","trackType":"flac"} Sep 15 18:25:00 motivo volumio[15151]: verbose: CURRENT POSITION 14 Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState stateService play Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState currentStatus play Sep 15 18:25:00 motivo volumio[15151]: info: Received an update from plugin. extracting info from payload Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: ControllerMpd::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::servicePushState Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getTrack 14 Sep 15 18:25:00 motivo volumio[15151]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1238,"duration":5,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1635 Kbps","isStreaming":false,"title":"UP with ATM #6","artist":"Yuji Ohno & Lupintic Five","album":"UP↑ with Yuji Ohno & Lupintic Five","uri":"http://192.168.104.241:50002/m/NDLNA/415.flac","trackType":"flac"} Sep 15 18:25:00 motivo volumio[15151]: verbose: CURRENT POSITION 14 Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState stateService play Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::syncState currentStatus play Sep 15 18:25:00 motivo volumio[15151]: info: Received an update from plugin. extracting info from payload Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:00 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 191ms Sep 15 18:25:00 motivo volumio[15151]: info: ------------------------------ 143ms Sep 15 18:25:00 motivo volumio[15151]: info: MCU Signalled Playback Inactive Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:00 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:00 motivo volumio[15151]: info: MCU Signalled Playback Active Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioNext Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::next Sep 15 18:25:02 motivo volumio[15151]: info: ControllerMpd::next Sep 15 18:25:02 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand next Sep 15 18:25:02 motivo volumio[15151]: info: Sep 15 18:25:02 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:02 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:02 motivo volumio[15151]: info: Sep 15 18:25:02 motivo volumio[15151]: ---------------------------- MPD announces state update: player Sep 15 18:25:02 motivo volumio[15151]: info: sendMpdCommand next took 12 milliseconds Sep 15 18:25:02 motivo volumio[15151]: info: ControllerMpd::getState Sep 15 18:25:02 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand status Sep 15 18:25:02 motivo volumio[15151]: error: updateQueue error: null Sep 15 18:25:02 motivo volumio[15151]: info: ------------------------------ 2ms Sep 15 18:25:02 motivo volumio[15151]: info: sendMpdCommand status took 1 milliseconds Sep 15 18:25:02 motivo volumio[15151]: verbose: ControllerMpd::parseState Sep 15 18:25:02 motivo volumio[15151]: info: ControllerMpd::pushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::servicePushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:02 motivo volumio[15151]: info: CorePlayQueue::getTrack 14 Sep 15 18:25:02 motivo volumio[15151]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 15 18:25:02 motivo volumio[15151]: verbose: CURRENT POSITION 14 Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::syncState stateService stop Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::syncState currentStatus play Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:02 motivo volumio[15151]: info: ------------------------------ 26ms Sep 15 18:25:02 motivo volumio[15151]: info: Sep 15 18:25:02 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:02 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:02 motivo volumio[15151]: info: Sep 15 18:25:02 motivo volumio[15151]: ---------------------------- MPD announces state update: player Sep 15 18:25:02 motivo volumio[15151]: info: ControllerMpd::getState Sep 15 18:25:02 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand status Sep 15 18:25:02 motivo volumio[15151]: info: Sep 15 18:25:02 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:02 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:02 motivo volumio[15151]: info: Sep 15 18:25:02 motivo volumio[15151]: ---------------------------- MPD announces state update: player Sep 15 18:25:02 motivo volumio[15151]: info: ControllerMpd::getState Sep 15 18:25:02 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand status Sep 15 18:25:02 motivo volumio[15151]: info: CorePlayQueue::getTrack 15 Sep 15 18:25:02 motivo volumio[15151]: info: CorePlayQueue::getTrack 16 Sep 15 18:25:02 motivo volumio[15151]: info: Prefetching next song Sep 15 18:25:02 motivo volumio[15151]: info: Doing Prefetch in UPNP Sep 15 18:25:02 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.104.241:50002/m/NDLNA/419.flac" Sep 15 18:25:02 motivo volumio[15151]: error: updateQueue error: null Sep 15 18:25:02 motivo volumio[15151]: error: updateQueue error: null Sep 15 18:25:02 motivo volumio[15151]: info: Sep 15 18:25:02 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:02 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:02 motivo volumio[15151]: info: ------------------------------ 6ms Sep 15 18:25:02 motivo volumio[15151]: info: sendMpdCommand status took 6 milliseconds Sep 15 18:25:02 motivo volumio[15151]: info: ------------------------------ 5ms Sep 15 18:25:02 motivo volumio[15151]: info: sendMpdCommand status took 4 milliseconds Sep 15 18:25:02 motivo volumio[15151]: info: sendMpdCommand add "http://192.168.104.241:50002/m/NDLNA/419.flac" took 3 milliseconds Sep 15 18:25:02 motivo volumio[15151]: verbose: ControllerMpd::parseState Sep 15 18:25:02 motivo volumio[15151]: verbose: ControllerMpd::parseState Sep 15 18:25:02 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand consume 1 Sep 15 18:25:02 motivo volumio[15151]: info: ControllerMpd::pushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::servicePushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:02 motivo volumio[15151]: info: CorePlayQueue::getTrack 15 Sep 15 18:25:02 motivo volumio[15151]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 15 18:25:02 motivo volumio[15151]: verbose: CURRENT POSITION 15 Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::syncState stateService stop Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::syncState currentStatus stop Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:02 motivo volumio[15151]: info: No code Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:02 motivo volumio[15151]: info: ControllerMpd::pushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::servicePushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:02 motivo volumio[15151]: info: CorePlayQueue::getTrack 15 Sep 15 18:25:02 motivo volumio[15151]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Sep 15 18:25:02 motivo volumio[15151]: verbose: CURRENT POSITION 15 Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::syncState stateService stop Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::syncState currentStatus stop Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:02 motivo volumio[15151]: info: No code Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::pushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioPushState Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioGetState Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:25:02 motivo volumio[15151]: info: MRS: Pushing multiroomSync output Sep 15 18:25:02 motivo volumio[15151]: info: ------------------------------ 43ms Sep 15 18:25:02 motivo volumio[15151]: info: ------------------------------ 43ms Sep 15 18:25:02 motivo volumio[15151]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:25:02 motivo volumio[15151]: info: CoreStateMachine::getQueue Sep 15 18:25:02 motivo volumio[15151]: info: CorePlayQueue::getQueue Sep 15 18:25:02 motivo volumio[15151]: info: Signalling Playback active due to playback status change Sep 15 18:25:02 motivo volumio[15151]: info: ------------------------------ 60ms Sep 15 18:25:02 motivo volumio[15151]: info: sendMpdCommand consume 1 took 58 milliseconds Sep 15 18:25:02 motivo volumio[15151]: info: Sep 15 18:25:02 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:02 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:02 motivo volumio[15151]: info: Sep 15 18:25:02 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:02 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:02 motivo volumio[15151]: info: ------------------------------ 2ms Sep 15 18:25:02 motivo volumio[15151]: info: ------------------------------ 2ms Sep 15 18:25:02 motivo volumio[15151]: info: MCU Signalled Playback Inactive Sep 15 18:25:05 motivo volumio[15151]: info: CoreCommandRouter::volumioPlay Sep 15 18:25:05 motivo volumio[15151]: info: CoreStateMachine::play index undefined Sep 15 18:25:05 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:25:05 motivo volumio[15151]: info: CorePlayQueue::getTrack 15 Sep 15 18:25:05 motivo volumio[15151]: info: CoreStateMachine::startPlaybackTimer Sep 15 18:25:05 motivo volumio[15151]: info: CorePlayQueue::getTrack 15 Sep 15 18:25:05 motivo volumio[15151]: info: [1757928305787] ControllerUPNPBrowser::clearAddPlayTrack Sep 15 18:25:05 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand stop Sep 15 18:25:05 motivo volumio[15151]: info: sendMpdCommand stop took 0 milliseconds Sep 15 18:25:05 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand clear Sep 15 18:25:05 motivo volumio[15151]: info: Sep 15 18:25:05 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:05 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:05 motivo volumio[15151]: info: sendMpdCommand clear took 1 milliseconds Sep 15 18:25:05 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.104.241:50002/m/NDLNA/420.flac" Sep 15 18:25:05 motivo volumio[15151]: info: Sep 15 18:25:05 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:05 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:05 motivo volumio[15151]: info: Sep 15 18:25:05 motivo volumio[15151]: ---------------------------- MPD announces system playlist update Sep 15 18:25:05 motivo volumio[15151]: info: Ignoring MPD Status Update Sep 15 18:25:05 motivo volumio[15151]: error: updateQueue error: null Sep 15 18:25:05 motivo volumio[15151]: info: ------------------------------ 4ms Sep 15 18:25:07 motivo volumio[15151]: info: CoreCommandRouter::volumioNext Sep 15 18:25:07 motivo volumio[15151]: info: CoreStateMachine::next Sep 15 18:25:07 motivo volumio[15151]: info: CoreStateMachine::stop Sep 15 18:25:07 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:25:07 motivo volumio[15151]: info: CoreStateMachine::play index undefined Sep 15 18:25:07 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:25:07 motivo volumio[15151]: info: CorePlayQueue::getTrack 16 Sep 15 18:25:07 motivo volumio[15151]: info: CoreStateMachine::startPlaybackTimer Sep 15 18:25:07 motivo volumio[15151]: info: CorePlayQueue::getTrack 16 Sep 15 18:25:07 motivo volumio[15151]: info: CoreCommandRouter::volumioGetVisibleSources Sep 15 18:25:07 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 15 18:25:07 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Sep 15 18:25:07 motivo volumio[15151]: info: [1757928307920] ControllerUPNPBrowser::clearAddPlayTrack Sep 15 18:25:07 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand stop Sep 15 18:25:07 motivo volumio[15151]: info: CoreStateMachine::updateTrackBlock Sep 15 18:25:07 motivo volumio[15151]: info: CorePlayQueue::getTrackBlock Sep 15 18:25:19 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 15 18:25:19 motivo volumio[15151]: info: Preload queue cleared Sep 15 18:25:20 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 15 18:25:21 motivo volumio[15151]: info: Preload queue cleared Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@393 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@410 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@413 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@395 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@406 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@400 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@404 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@397 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@401 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@399 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@396 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@398 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@405 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@408 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@403 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@407 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@409 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@402 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@411 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@412 Sep 15 18:25:21 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@394 Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@393 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@410 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@413 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@395 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@406 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@400 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@404 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@397 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@401 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@399 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@396 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@398 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@405 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@408 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@403 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@407 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@409 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@402 in service upnp_browser Sep 15 18:25:21 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@411 in service upnp_browser Sep 15 18:25:22 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@412 in service upnp_browser Sep 15 18:25:22 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@394 in service upnp_browser Sep 15 18:25:23 motivo volumio[15151]: info: Preload queue cleared Sep 15 18:25:23 motivo volumio[15151]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 15 18:25:23 motivo volumio[15151]: info: CoreStateMachine::ClearQueue Sep 15 18:25:23 motivo volumio[15151]: info: CoreStateMachine::stop Sep 15 18:25:23 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:25:23 motivo volumio[15151]: info: CorePlayQueue::clearPlayQueue Sep 15 18:25:23 motivo volumio[15151]: info: CorePlayQueue::saveQueue Sep 15 18:25:23 motivo volumio[15151]: info: CoreCommandRouter::volumioPushQueue Sep 15 18:25:23 motivo volumio[15151]: info: CoreStateMachine::addQueueItems Sep 15 18:25:23 motivo volumio[15151]: info: CorePlayQueue::addQueueItems Sep 15 18:25:23 motivo volumio[15151]: info: Preload queue cleared Sep 15 18:25:23 motivo volumio[15151]: info: Adding Item to queue: upnp/folder/http://192.168.104.241:50001/ContentDirectory/control@22$190 Sep 15 18:25:23 motivo volumio[15151]: info: Exploding uri upnp/folder/http://192.168.104.241:50001/ContentDirectory/control@22$190 in service upnp_browser Sep 15 18:25:23 motivo volumio[15151]: info: CoreCommandRouter::volumioPushQueue Sep 15 18:25:23 motivo volumio[15151]: info: CorePlayQueue::saveQueue Sep 15 18:25:23 motivo volumio[15151]: info: CoreStateMachine::updateTrackBlock Sep 15 18:25:23 motivo volumio[15151]: info: CorePlayQueue::getTrackBlock Sep 15 18:25:23 motivo volumio[15151]: info: CoreCommandRouter::volumioPlay Sep 15 18:25:23 motivo volumio[15151]: info: CoreStateMachine::play index 0 Sep 15 18:25:23 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:25:23 motivo volumio[15151]: info: CoreStateMachine::stop Sep 15 18:25:23 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:25:23 motivo volumio[15151]: info: CoreStateMachine::play index undefined Sep 15 18:25:23 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:25:23 motivo volumio[15151]: info: CorePlayQueue::getTrack 0 Sep 15 18:25:23 motivo volumio[15151]: info: CoreStateMachine::startPlaybackTimer Sep 15 18:25:23 motivo volumio[15151]: info: CorePlayQueue::getTrack 0 Sep 15 18:25:23 motivo volumio[15151]: info: [1757928323349] ControllerUPNPBrowser::clearAddPlayTrack Sep 15 18:25:23 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand stop Sep 15 18:25:24 motivo volumio[15151]: info: Preload queue cleared Sep 15 18:25:24 motivo volumio[15151]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 15 18:25:24 motivo volumio[15151]: info: CoreStateMachine::ClearQueue Sep 15 18:25:24 motivo volumio[15151]: info: CoreStateMachine::stop Sep 15 18:25:24 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:25:24 motivo volumio[15151]: info: CorePlayQueue::clearPlayQueue Sep 15 18:25:24 motivo volumio[15151]: info: CorePlayQueue::saveQueue Sep 15 18:25:24 motivo volumio[15151]: info: CoreCommandRouter::volumioPushQueue Sep 15 18:25:24 motivo volumio[15151]: info: CoreStateMachine::addQueueItems Sep 15 18:25:24 motivo volumio[15151]: info: CorePlayQueue::addQueueItems Sep 15 18:25:24 motivo volumio[15151]: info: Preload queue cleared Sep 15 18:25:24 motivo volumio[15151]: info: Adding Item to queue: upnp/folder/http://192.168.104.241:50001/ContentDirectory/control@22$190 Sep 15 18:25:24 motivo volumio[15151]: info: Using cached record of: upnp/folder/http://192.168.104.241:50001/ContentDirectory/control@22$190 Sep 15 18:25:24 motivo volumio[15151]: info: CoreCommandRouter::volumioPushQueue Sep 15 18:25:24 motivo volumio[15151]: info: CorePlayQueue::saveQueue Sep 15 18:25:24 motivo volumio[15151]: info: CoreStateMachine::updateTrackBlock Sep 15 18:25:24 motivo volumio[15151]: info: CorePlayQueue::getTrackBlock Sep 15 18:25:24 motivo volumio[15151]: info: CoreCommandRouter::volumioPlay Sep 15 18:25:24 motivo volumio[15151]: info: CoreStateMachine::play index 0 Sep 15 18:25:24 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:25:24 motivo volumio[15151]: info: CoreStateMachine::stop Sep 15 18:25:24 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:25:24 motivo volumio[15151]: info: CoreStateMachine::play index undefined Sep 15 18:25:24 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:25:24 motivo volumio[15151]: info: CorePlayQueue::getTrack 0 Sep 15 18:25:24 motivo volumio[15151]: info: CoreStateMachine::startPlaybackTimer Sep 15 18:25:24 motivo volumio[15151]: info: CorePlayQueue::getTrack 0 Sep 15 18:25:24 motivo volumio[15151]: info: [1757928324405] ControllerUPNPBrowser::clearAddPlayTrack Sep 15 18:25:24 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand stop Sep 15 18:25:26 motivo mpd_monitor.sh[736]: MPD Monitor Service: MPD Appears to be inactive, restarting Sep 15 18:25:26 motivo systemd[1]: Stopping Music Player Daemon... Sep 15 18:25:46 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 15 18:25:46 motivo volumio[15151]: info: Preload queue cleared Sep 15 18:25:47 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 15 18:25:47 motivo volumio[15151]: info: Preload queue cleared Sep 15 18:25:47 motivo volumio[15151]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@431 Sep 15 18:25:47 motivo volumio[15151]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@431 in service upnp_browser Sep 15 18:25:47 motivo volumio[15151]: info: Executing endpoint getSimilarAlbums Sep 15 18:25:47 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Sep 15 18:25:47 motivo volumio[15151]: info: Executing endpoint metavolumio Sep 15 18:25:47 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 15 18:25:47 motivo volumio[15151]: info: Executing endpoint metavolumio Sep 15 18:25:47 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 15 18:25:51 motivo volumio[15151]: info: Preload queue cleared Sep 15 18:25:51 motivo volumio[15151]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 15 18:25:51 motivo volumio[15151]: info: CoreStateMachine::ClearQueue Sep 15 18:25:51 motivo volumio[15151]: info: CoreStateMachine::stop Sep 15 18:25:51 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:25:51 motivo volumio[15151]: info: CorePlayQueue::clearPlayQueue Sep 15 18:25:51 motivo volumio[15151]: info: CorePlayQueue::saveQueue Sep 15 18:25:51 motivo volumio[15151]: info: CoreCommandRouter::volumioPushQueue Sep 15 18:25:51 motivo volumio[15151]: info: CoreStateMachine::addQueueItems Sep 15 18:25:51 motivo volumio[15151]: info: CorePlayQueue::addQueueItems Sep 15 18:25:51 motivo volumio[15151]: info: Preload queue cleared Sep 15 18:25:51 motivo volumio[15151]: info: Adding Item to queue: upnp/folder/http://192.168.104.241:50001/ContentDirectory/control@22$194 Sep 15 18:25:51 motivo volumio[15151]: info: Exploding uri upnp/folder/http://192.168.104.241:50001/ContentDirectory/control@22$194 in service upnp_browser Sep 15 18:25:51 motivo volumio[15151]: info: CoreCommandRouter::volumioPushQueue Sep 15 18:25:51 motivo volumio[15151]: info: CorePlayQueue::saveQueue Sep 15 18:25:51 motivo volumio[15151]: info: CoreStateMachine::updateTrackBlock Sep 15 18:25:51 motivo volumio[15151]: info: CorePlayQueue::getTrackBlock Sep 15 18:25:51 motivo volumio[15151]: info: CoreCommandRouter::volumioPlay Sep 15 18:25:51 motivo volumio[15151]: info: CoreStateMachine::play index 0 Sep 15 18:25:51 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:25:51 motivo volumio[15151]: info: CoreStateMachine::stop Sep 15 18:25:51 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:25:51 motivo volumio[15151]: info: CoreStateMachine::play index undefined Sep 15 18:25:51 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:25:51 motivo volumio[15151]: info: CorePlayQueue::getTrack 0 Sep 15 18:25:51 motivo volumio[15151]: info: CoreStateMachine::startPlaybackTimer Sep 15 18:25:51 motivo volumio[15151]: info: CorePlayQueue::getTrack 0 Sep 15 18:25:51 motivo volumio[15151]: info: CoreCommandRouter::volumioGetVisibleSources Sep 15 18:25:51 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 15 18:25:51 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Sep 15 18:25:51 motivo volumio[15151]: info: [1757928351050] ControllerUPNPBrowser::clearAddPlayTrack Sep 15 18:25:51 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand stop Sep 15 18:25:56 motivo volumio[15151]: info: CoreCommandRouter::volumioPlay Sep 15 18:25:56 motivo volumio[15151]: info: CoreStateMachine::play index undefined Sep 15 18:25:56 motivo volumio[15151]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:25:56 motivo volumio[15151]: info: CorePlayQueue::getTrack 0 Sep 15 18:25:56 motivo volumio[15151]: info: CoreStateMachine::startPlaybackTimer Sep 15 18:25:56 motivo volumio[15151]: info: CorePlayQueue::getTrack 0 Sep 15 18:25:56 motivo volumio[15151]: info: CoreCommandRouter::volumioGetVisibleSources Sep 15 18:25:56 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 15 18:25:56 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Sep 15 18:25:56 motivo volumio[15151]: info: [1757928356635] ControllerUPNPBrowser::clearAddPlayTrack Sep 15 18:25:56 motivo volumio[15151]: verbose: ControllerMpd::sendMpdCommand stop Sep 15 18:26:13 motivo volumio[15151]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 15 18:26:13 motivo volumio[15151]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 15 18:26:13 motivo volumio[15151]: TypeError: Cannot read property 'length' of undefined Sep 15 18:26:13 motivo volumio[15151]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Sep 15 18:26:13 motivo volumio[15151]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Sep 15 18:26:13 motivo volumio[15151]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Sep 15 18:26:13 motivo volumio[15151]: at Parser.emit (events.js:315:20) Sep 15 18:26:13 motivo volumio[15151]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Sep 15 18:26:13 motivo volumio[15151]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Sep 15 18:26:13 motivo volumio[15151]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Sep 15 18:26:13 motivo volumio[15151]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Sep 15 18:26:13 motivo volumio[15151]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Sep 15 18:26:13 motivo volumio[15151]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Sep 15 18:26:13 motivo volumio[15151]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Sep 15 18:26:13 motivo volumio[15151]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Sep 15 18:26:13 motivo volumio[15151]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Sep 15 18:26:13 motivo volumio[15151]: at IncomingMessage.emit (events.js:327:22) Sep 15 18:26:13 motivo volumio[15151]: at endReadableNT (internal/streams/readable.js:1327:12) Sep 15 18:26:13 motivo volumio[15151]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Sep 15 18:26:13 motivo volumio[15151]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 15 18:26:13 motivo sudo[17640]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-15 18:25 Sep 15 18:26:13 motivo sudo[17640]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:13 motivo sudo[17640]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:13 motivo qobuz-connect[15364]: 20250915 18:26:13.904 [15364.15364] INFO SampleApp: Socket closed Sep 15 18:26:13 motivo volumio-remote-updater[714]: [2025-09-15 18:26:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Sep 15 18:26:13 motivo volumio-remote-updater[714]: [2025-09-15 18:26:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Sep 15 18:26:13 motivo systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Sep 15 18:26:13 motivo sudo[15378]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:13 motivo systemd[1]: volumio.service: Failed with result 'exit-code'. Sep 15 18:26:13 motivo systemd[1]: Started dynamicswap service. Sep 15 18:26:13 motivo systemd[1]: dynamicswap.service: Succeeded. Sep 15 18:26:14 motivo systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Sep 15 18:26:14 motivo systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4. Sep 15 18:26:14 motivo systemd[1]: Stopped Volumio Backend Module. Sep 15 18:26:14 motivo systemd[1]: Started Volumio Backend Module. Sep 15 18:26:14 motivo systemd[1]: Started dynamicswap service. Sep 15 18:26:14 motivo systemd[1]: dynamicswap.service: Succeeded. Sep 15 18:26:15 motivo volumio[17652]: info: ------------------------------------------- Sep 15 18:26:15 motivo volumio[17652]: info: ----- Volumio3 ---- Sep 15 18:26:15 motivo volumio[17652]: info: ------------------------------------------- Sep 15 18:26:15 motivo volumio[17652]: info: ----- System startup ---- Sep 15 18:26:15 motivo volumio[17652]: info: ------------------------------------------- Sep 15 18:26:15 motivo volumio[17652]: info: MYVOLUMIO Environment detected Sep 15 18:26:15 motivo volumio[17652]: info: Plugin folders cleanup Sep 15 18:26:15 motivo volumio[17652]: info: Scanning into folder /volumio/app/plugins/ Sep 15 18:26:15 motivo volumio[17652]: info: Scanning category audio_interface Sep 15 18:26:15 motivo volumio[17652]: info: Scanning category miscellanea Sep 15 18:26:15 motivo volumio[17652]: info: Scanning category music_service Sep 15 18:26:15 motivo volumio[17652]: info: Scanning category plugins.json Sep 15 18:26:15 motivo volumio[17652]: info: Scanning category system_controller Sep 15 18:26:15 motivo volumio[17652]: info: Scanning category user_interface Sep 15 18:26:15 motivo volumio[17652]: info: Scanning into folder /data/plugins/ Sep 15 18:26:15 motivo volumio[17652]: info: Plugin folders cleanup completed Sep 15 18:26:15 motivo volumio[17652]: info: ------------------------------------------- Sep 15 18:26:15 motivo volumio[17652]: info: ----- Core plugins startup ---- Sep 15 18:26:15 motivo volumio[17652]: info: ------------------------------------------- Sep 15 18:26:15 motivo volumio[17652]: info: Loading plugins from folder /volumio/app/plugins/ Sep 15 18:26:15 motivo volumio[17652]: info: Adding plugin bluetooth to MyMusic Plugins Sep 15 18:26:15 motivo volumio[17652]: info: Adding plugin multiroom to MyMusic Plugins Sep 15 18:26:15 motivo volumio[17652]: info: Adding plugin upnp to MyMusic Plugins Sep 15 18:26:15 motivo volumio[17652]: info: Adding plugin metavolumio to MyMusic Plugins Sep 15 18:26:15 motivo volumio[17652]: info: Adding plugin airplay_emulation to MyMusic Plugins Sep 15 18:26:15 motivo volumio[17652]: info: Adding plugin cd_controller to MyMusic Plugins Sep 15 18:26:15 motivo volumio[17652]: info: Adding plugin qobuzconnect to MyMusic Plugins Sep 15 18:26:15 motivo volumio[17652]: info: Adding plugin raat to MyMusic Plugins Sep 15 18:26:15 motivo volumio[17652]: info: Adding plugin smart_inputs to MyMusic Plugins Sep 15 18:26:15 motivo volumio[17652]: info: Adding plugin tidalconnect to MyMusic Plugins Sep 15 18:26:15 motivo volumio[17652]: info: Adding plugin upnp_browser to MyMusic Plugins Sep 15 18:26:15 motivo volumio[17652]: info: Loading plugins from folder /data/plugins/ Sep 15 18:26:15 motivo volumio[17652]: info: Loading plugin "system"... Sep 15 18:26:15 motivo volumio[17652]: info: Loading plugin "appearance"... Sep 15 18:26:16 motivo volumio[17652]: info: Loading plugin "network"... Sep 15 18:26:16 motivo volumio[17652]: info: Refreshing Cached IP Addresses Sep 15 18:26:16 motivo sudo[17679]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 15 18:26:16 motivo sudo[17679]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:16 motivo sudo[17681]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 15 18:26:16 motivo sudo[17681]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:16 motivo volumio[17652]: info: Loading plugin "services"... Sep 15 18:26:16 motivo volumio[17652]: info: Loading plugin "alsa_controller"... Sep 15 18:26:16 motivo sudo[17679]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:16 motivo sudo[17681]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:16 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 15 18:26:16 motivo volumio[17652]: info: Loading plugin "wizard"... Sep 15 18:26:16 motivo volumio[17652]: info: Loading plugin "networkfs"... Sep 15 18:26:16 motivo volumio[17652]: info: Starting Udev Watcher for removable devices Sep 15 18:26:16 motivo volumio[17652]: info: Ignoring mount for partition: boot Sep 15 18:26:16 motivo volumio[17652]: info: Ignoring mount for partition: volumio Sep 15 18:26:16 motivo volumio[17652]: info: Ignoring mount for partition: volumio_data Sep 15 18:26:16 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 15 18:26:16 motivo volumio[17652]: info: Loading plugin "volumio_command_line_client"... Sep 15 18:26:16 motivo volumio[17652]: info: Loading plugin "upnp"... Sep 15 18:26:16 motivo volumio[17652]: info: [1757928376704] Starting Upmpd Daemon Sep 15 18:26:16 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 15 18:26:16 motivo volumio[17652]: info: Loading plugin "my_music"... Sep 15 18:26:16 motivo volumio[17652]: info: Loading plugin "mpd"... Sep 15 18:26:16 motivo volumio[17652]: info: Loading plugin "upnp_browser"... Sep 15 18:26:17 motivo volumio[17652]: info: Plugin bluetooth is not enabled Sep 15 18:26:17 motivo volumio[17652]: info: Loading plugin "alarm-clock"... Sep 15 18:26:17 motivo volumio[17652]: info: Loading plugin "manifestui"... Sep 15 18:26:17 motivo volumio[17652]: info: Loading plugin "metavolumio"... Sep 15 18:26:18 motivo volumio[17652]: info: Loading plugin "airplay_emulation"... Sep 15 18:26:18 motivo volumio[17652]: info: Starting Shairport Sync Sep 15 18:26:18 motivo volumio[17652]: info: Plugin cd_controller is not enabled Sep 15 18:26:18 motivo volumio[17652]: info: Loading plugin "last_100"... Sep 15 18:26:18 motivo volumio[17652]: info: Loading plugin "qobuzconnect"... Sep 15 18:26:18 motivo volumio[17652]: info: Plugin raat is not enabled Sep 15 18:26:18 motivo volumio[17652]: info: Loading plugin "streaming_services"... Sep 15 18:26:18 motivo volumio[17652]: info: Starting Streaming Service Transparent Proxy Sep 15 18:26:18 motivo volumio[17652]: info: Plugin tidalconnect is not enabled Sep 15 18:26:18 motivo volumio[17652]: info: Loading plugin "webradio"... Sep 15 18:26:18 motivo volumio[17652]: info: Loading plugin "i2s_dacs"... Sep 15 18:26:18 motivo volumio[17652]: info: I2S DAC not set, start Auto-detection Sep 15 18:26:18 motivo volumio[17652]: info: Loading plugin "volumiodiscovery"... Sep 15 18:26:18 motivo volumio[17652]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 15 18:26:18 motivo volumio[17652]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 15 18:26:18 motivo volumio[17652]: *** WARNING *** For more information see Sep 15 18:26:18 motivo volumio[17652]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 15 18:26:18 motivo node[17652]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 15 18:26:18 motivo volumio[17652]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 15 18:26:18 motivo volumio[17652]: *** WARNING *** For more information see Sep 15 18:26:18 motivo node[17652]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 15 18:26:18 motivo node[17652]: *** WARNING *** For more information see Sep 15 18:26:18 motivo node[17652]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 15 18:26:18 motivo node[17652]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 15 18:26:18 motivo node[17652]: *** WARNING *** For more information see Sep 15 18:26:18 motivo volumio[17652]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 15 18:26:18 motivo volumio[17652]: info: Discovery: Started advertising with name: Motivo Sep 15 18:26:18 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 15 18:26:18 motivo volumio[17652]: info: Loading plugin "multiroom"... Sep 15 18:26:18 motivo volumio-remote-updater[714]: [2025-09-15 18:26:18] [connect] Successful connection Sep 15 18:26:19 motivo volumio[17652]: STREAMING PROXY: Starting server on port 3245 Sep 15 18:26:19 motivo volumio[17652]: Node JS runtime: 14 Sep 15 18:26:19 motivo volumio[17652]: info: Applying required configuration parameters for plugin multiroom Sep 15 18:26:19 motivo sudo[17716]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Sep 15 18:26:19 motivo sudo[17716]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:19 motivo sudo[17716]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:19 motivo volumio[17652]: /bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Sep 15 18:26:19 motivo volumio[17652]: info: MRS: MultiRoom plugin initialized Sep 15 18:26:19 motivo volumio[17652]: info: MRS: STOPPING SNAPCLIENT Sep 15 18:26:19 motivo volumio[17652]: info: MRS: Snap server stop Sep 15 18:26:19 motivo sudo[17732]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Sep 15 18:26:19 motivo sudo[17732]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:19 motivo volumio[17652]: info: MRS: STOPPING volumioStreaming Sep 15 18:26:19 motivo sudo[17734]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Sep 15 18:26:19 motivo sudo[17734]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:19 motivo sudo[17737]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Sep 15 18:26:19 motivo sudo[17737]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:19 motivo volumio[17652]: info: Loading plugin "outputs"... Sep 15 18:26:19 motivo volumio[17652]: info: Loading plugin "albumart"... Sep 15 18:26:19 motivo sudo[17741]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Sep 15 18:26:19 motivo sudo[17741]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:19 motivo sudo[17732]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:19 motivo sudo[17741]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:19 motivo volumio[17652]: info: Plugin example_plugin is not enabled Sep 15 18:26:19 motivo volumio[17652]: info: Loading plugin "hi_res_audio"... Sep 15 18:26:19 motivo sudo[17737]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:19 motivo sudo[17734]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:20 motivo volumio[17652]: Forking 3 albumart workers Sep 15 18:26:20 motivo volumio[17652]: Starting albumart workers Sep 15 18:26:21 motivo volumio[17652]: Starting albumart workers Sep 15 18:26:21 motivo volumio[17652]: Starting albumart workers Sep 15 18:26:21 motivo volumio[17652]: info: Applying required configuration parameters for plugin hi_res_audio Sep 15 18:26:21 motivo volumio[17652]: info: Loading plugin "inputs"... Sep 15 18:26:22 motivo volumio[17652]: info: Loading plugin "qobuz"... Sep 15 18:26:22 motivo volumio[17652]: info: Loading plugin "smart_inputs"... Sep 15 18:26:22 motivo volumio[17652]: info: Loading plugin "tidal"... Sep 15 18:26:23 motivo volumio[17652]: info: Loading plugin "motivocontrol"... Sep 15 18:26:23 motivo volumio[17652]: info: Initializing System Ready GPIO for kernel version: 6.6.30-v8+ Sep 15 18:26:23 motivo volumio[17652]: info: Adding this device properties Sep 15 18:26:23 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , setThisDeviceVolumioProperties Sep 15 18:26:23 motivo volumio[17652]: info: Setting Additional Device Volumio Properties: [object Object] Sep 15 18:26:23 motivo volumio[17652]: info: Checking For Motivo Hardware Sep 15 18:26:23 motivo volumio[17652]: info: Loading plugin "updater_comm"... Sep 15 18:26:23 motivo volumio[17652]: info: Plugin mpdemulation is not enabled Sep 15 18:26:23 motivo volumio[17652]: info: Loading plugin "rest_api"... Sep 15 18:26:23 motivo volumio[17652]: info: Loading plugin "websocket"... Sep 15 18:26:23 motivo volumio[17652]: info: Starting Socket.io Server version 2.3.0 Sep 15 18:26:23 motivo volumio[17652]: info: Loading i18n strings for locale ja Sep 15 18:26:23 motivo volumio[17652]: Updating browse sources language Sep 15 18:26:23 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 15 18:26:23 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 15 18:26:23 motivo volumio[17652]: info: CoreCommandRouter::initPlayerControls Sep 15 18:26:23 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:23 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:23 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:23 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:23 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:23 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:23 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:23 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:23 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 15 18:26:23 motivo volumio[17652]: Express server listening on port 3000 Sep 15 18:26:23 motivo volumio[17652]: [Metrics] WebUI: 8s 842.45ms Sep 15 18:26:23 motivo volumio[17652]: info: CoreStateMachine::resetVolumioState Sep 15 18:26:23 motivo volumio[17652]: info: CoreStateMachine::getcurrentVolume Sep 15 18:26:23 motivo volumio[17652]: info: CoreCommandRouter::volumioRetrievevolume Sep 15 18:26:23 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 15 18:26:23 motivo volumio[17652]: info: Volumio Network Manager: Network status updated: 1 Sep 15 18:26:23 motivo volumio[17652]: info: Motivo Hardware found Sep 15 18:26:23 motivo volumio[17652]: info: MRS: Removed streaming files Sep 15 18:26:23 motivo volumio[17652]: info: MRS: volumioStreaming STOPPED Sep 15 18:26:23 motivo volumio[17652]: info: MRS: SNAPSERVER STOPPED Sep 15 18:26:23 motivo volumio[17652]: info: MRS: SNAPCLIENT STOPPED Sep 15 18:26:23 motivo volumio[17652]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 1 Sep 15 18:26:23 motivo volumio[17652]: verbose: New Socket.io Connection to 192.168.104.230 from 192.168.104.202 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 2 Sep 15 18:26:23 motivo volumio[17652]: verbose: New Socket.io Connection to 192.168.104.230 from 192.168.104.202 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 3 Sep 15 18:26:23 motivo volumio[17652]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 4 Sep 15 18:26:23 motivo volumio[17652]: verbose: New Socket.io Connection to 192.168.104.230 from 192.168.104.202 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 5 Sep 15 18:26:24 motivo volumio[17652]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 6 Sep 15 18:26:24 motivo volumio[17652]: info: Reloading queue from file Sep 15 18:26:24 motivo volumio[17652]: info: Setting Device type: Raspberry PI Sep 15 18:26:24 motivo volumio[17652]: info: CoreStateMachine::setRepeat false single undefined Sep 15 18:26:24 motivo volumio[17652]: info: CoreStateMachine::pushState Sep 15 18:26:24 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::volumioPushState Sep 15 18:26:24 motivo volumio[17652]: info: CoreStateMachine::setRandom false Sep 15 18:26:24 motivo volumio[17652]: info: CoreStateMachine::pushState Sep 15 18:26:24 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::volumioPushState Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 15 18:26:24 motivo volumio[17652]: info: VolumeController:: Volume=30 Mute =false Sep 15 18:26:24 motivo volumio[17652]: info: CoreStateMachine::pushState Sep 15 18:26:24 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::volumioPushState Sep 15 18:26:24 motivo volumio[17652]: info: CoreStateMachine::updateTrackBlock Sep 15 18:26:24 motivo volumio[17652]: info: CorePlayQueue::getTrackBlock Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::volumioRetrievevolume Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::volumioGetVisibleSources Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::volumioGetState Sep 15 18:26:24 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:26:24 motivo volumio[17652]: info: CoreStateMachine::getQueue Sep 15 18:26:24 motivo volumio[17652]: info: CorePlayQueue::getQueue Sep 15 18:26:24 motivo volumio[17652]: info: Listing playlists Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 15 18:26:24 motivo volumio[17652]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Sep 15 18:26:24 motivo volumio[17652]: info: Received Get System Info Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 15 18:26:24 motivo volumio[17652]: info: Discovery: Getting this device information Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::volumioGetState Sep 15 18:26:24 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::volumioGetState Sep 15 18:26:24 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:24 motivo volumio[17652]: info: Completed loading Core Plugins Sep 15 18:26:24 motivo volumio[17652]: info: Preparing to generate the ALSA configuration file Sep 15 18:26:24 motivo volumio[17652]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Sep 15 18:26:24 motivo volumio[17652]: info: Reading ALSA contributions from plugins. Sep 15 18:26:24 motivo volumio[17652]: info: VolumeController:: Volume=30 Mute =false Sep 15 18:26:24 motivo volumio[17652]: info: CoreStateMachine::pushState Sep 15 18:26:24 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::volumioPushState Sep 15 18:26:24 motivo volumio[17652]: info: Asound.conf file unchanged, so no further update is needed Sep 15 18:26:24 motivo volumio[17652]: info: Output device has changed, restarting MPD Sep 15 18:26:24 motivo sudo[17815]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 15 18:26:24 motivo sudo[17815]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:24 motivo volumio[17652]: info: Output device has changed, restarting Shairport Sync Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 15 18:26:24 motivo sudo[17815]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:24 motivo sudo[17817]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 15 18:26:24 motivo sudo[17817]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:24 motivo volumio[17652]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 15 18:26:24 motivo volumio[17652]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:24 motivo volumio[17652]: info: ___________ START PLUGINS ___________ Sep 15 18:26:24 motivo volumio[17652]: info: ControllerMpd::onStart: Initializing MPD Sep 15 18:26:24 motivo volumio[17652]: info: Creating MPD Configuration file Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 15 18:26:24 motivo sudo[17826]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 15 18:26:24 motivo sudo[17826]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:24 motivo sudo[17828]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 15 18:26:24 motivo sudo[17828]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:24 motivo volumio[17652]: info: [1757928384485] CoreMusicLibrary::Adding element DLNAサーバー Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 15 18:26:24 motivo sudo[17826]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:24 motivo volumio[17652]: info: Adding METAVOLUMIO REST API Endpoints Sep 15 18:26:24 motivo volumio[17652]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Sep 15 18:26:24 motivo volumio[17652]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Sep 15 18:26:24 motivo volumio[17652]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Sep 15 18:26:24 motivo volumio[17652]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 15 18:26:24 motivo volumio[17652]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 15 18:26:24 motivo volumio[17652]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 15 18:26:24 motivo volumio[17652]: info: [1757928384630] CoreMusicLibrary::Adding element Last_100 Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 15 18:26:24 motivo volumio[17652]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Sep 15 18:26:24 motivo volumio[17652]: info: QobuzConnect: Starting Qobuz Connect socket and service Sep 15 18:26:24 motivo volumio[17652]: info: Streaming services startup Sep 15 18:26:24 motivo volumio[17652]: info: Starting Streaming Daemon Sep 15 18:26:24 motivo sudo[17841]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Sep 15 18:26:24 motivo sudo[17841]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:24 motivo sudo[17841]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:24 motivo sudo[17843]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 15 18:26:24 motivo sudo[17843]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 15 18:26:24 motivo volumio[17652]: info: [1757928384750] CoreMusicLibrary::Adding element Webradio Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 15 18:26:24 motivo volumio[17652]: info: Initializing BBC Radios Sep 15 18:26:24 motivo sudo[17843]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:24 motivo sudo[17848]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Sep 15 18:26:24 motivo sudo[17848]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:24 motivo systemd[1]: Stopping Volumio Qobuz Connect Service... Sep 15 18:26:24 motivo qobuz-connect[15364]: 20250915 18:26:24.800 [15364.15364] INFO SampleApp: Stopping Local configuration server Sep 15 18:26:24 motivo systemd[1]: qobuz-connect.service: Succeeded. Sep 15 18:26:24 motivo systemd[1]: Stopped Volumio Qobuz Connect Service. Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Sep 15 18:26:24 motivo systemd[1]: Started Volumio Qobuz Connect Service. Sep 15 18:26:24 motivo sudo[17848]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:24 motivo volumio[17652]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Sep 15 18:26:24 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:24 motivo volumio[17652]: error: Hi Res Audio Failed Login: Missing Login Data Sep 15 18:26:24 motivo volumio[17652]: info: Adding HIGHRESAUDIO REST API Endpoints Sep 15 18:26:24 motivo volumio[17652]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Sep 15 18:26:24 motivo volumio[17652]: info: Initializing Serial Communication on port /dev/ttyAMA4 Sep 15 18:26:24 motivo volumio[17652]: info: Touch Event Listener Process Starting Sep 15 18:26:24 motivo volumio[17652]: info: Adding inputs REST Endpoints Sep 15 18:26:24 motivo volumio[17652]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Sep 15 18:26:24 motivo volumio[17652]: info: Scanning Audio Inputs Sep 15 18:26:24 motivo sudo[17870]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xinput --test-xi2 --root Sep 15 18:26:24 motivo sudo[17870]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:24 motivo volumio[17652]: info: Checking against Known Cards name Sep 15 18:26:25 motivo volumio[17652]: info: Checking against Known Cards name Sep 15 18:26:25 motivo volumio[17652]: info: Adding Server instance for streaming Sep 15 18:26:25 motivo volumio[17652]: info: Volumio Calling Home Sep 15 18:26:25 motivo volumio[17652]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Sep 15 18:26:25 motivo volumio[17652]: info: Stopping AccessToken refresher cron for QOBUZ Sep 15 18:26:25 motivo volumio[17652]: info: AccessToken refresher cron started for QOBUZ Sep 15 18:26:25 motivo volumio[17652]: info: Stopping AccessToken refresher cron Sep 15 18:26:25 motivo volumio[17652]: info: AccessToken refresher cron started Sep 15 18:26:25 motivo volumio[17652]: info: Adding TIDAL REST API Endpoints Sep 15 18:26:25 motivo volumio[17652]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Sep 15 18:26:25 motivo volumio[17652]: info: Adding QOBUZ REST API Endpoints Sep 15 18:26:25 motivo volumio[17652]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Sep 15 18:26:25 motivo volumio[17652]: info: Discovery: adding 3d4de5ee-9c91-4c01-a6f9-52e3de23bdbd Sep 15 18:26:25 motivo volumio[17652]: info: Discovery: Found device Motivo Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::volumioGetState Sep 15 18:26:25 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:25 motivo volumio[17652]: info: MRS: Pushing multiroomSync output for this device Sep 15 18:26:25 motivo volumio[17652]: info: MRS: Pushing multiroomSync output Sep 15 18:26:25 motivo volumio[17652]: info: Adding audio output: Sep 15 18:26:25 motivo volumio[17652]: info: Adding audio output: Sep 15 18:26:25 motivo volumio[17652]: info: Serial port opened successfully Sep 15 18:26:25 motivo volumio[17652]: info: Sending serial start messages Sep 15 18:26:25 motivo volumio[17652]: info: Display with brightness control is connected, setting display brightness Sep 15 18:26:25 motivo volumio[17652]: info: Setting Display Brightness to 7 Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: Reporting MCU Network Status: 1 Sep 15 18:26:25 motivo volumio[17652]: error: Cannot start Volumio Streaming Daemon Sep 15 18:26:25 motivo volumio[17652]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 15 18:26:25 motivo volumio[17652]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 15 18:26:25 motivo volumio[17652]: info: MPD Permissions set Sep 15 18:26:25 motivo volumio[17652]: info: MPD Permissions set Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride Sep 15 18:26:25 motivo volumio[17652]: info: Setting Device Volume Override Sep 15 18:26:25 motivo volumio[17652]: info: Applying Volume Override Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::volumioUpdateVolumeSettings Sep 15 18:26:25 motivo volumio[17652]: info: Updating Volume Controller Parameters: Device: 5 Name: Analog + I2S + Headphones Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Sep 15 18:26:25 motivo volumio[17652]: info: Enabling external Volume Control Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: inputs , updateVolumeSettings Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: inputs , retrievevolume Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreStateMachine::pushState Sep 15 18:26:25 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::volumioPushState Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::volumioGetState Sep 15 18:26:25 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:25 motivo volumio[17652]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:26:25 motivo volumio[17652]: info: MRS: Pushing multiroomSync output Sep 15 18:26:25 motivo volumio[17652]: info: Executing endpoint qc_getconfig Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Sep 15 18:26:25 motivo qobuz-connect[17858]: 20250915 18:26:25.565 [17858.17858] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Sep 15 18:26:25 motivo qobuz-connect[17858]: 20250915 18:26:25.569 [17858.17858] INFO VolumeManager: [0x22c22a0]: Setting new playback volume: 75 Sep 15 18:26:25 motivo qobuz-connect[17858]: 20250915 18:26:25.569 [17858.17858] INFO VolumeManager: [0x22c22a0]: Setting new mute state: 0 Sep 15 18:26:25 motivo qobuz-connect[17858]: 20250915 18:26:25.569 [17858.17858] INFO QobuzConnect: [0x22c2c70]: Client initialized! Sep 15 18:26:25 motivo qobuz-connect[17858]: 20250915 18:26:25.569 [17858.17858] INFO SampleApp: Starting Avahi advertising, name: Motivo, service name: _qobuz-connect._tcp Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Sep 15 18:26:25 motivo volumio[17652]: info: Setting Additional System Software info: Hardware Revision: 2.4 Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Sep 15 18:26:25 motivo volumio[17652]: info: Setting HW Firmware info: undefined Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Sep 15 18:26:25 motivo volumio[17652]: info: Setting HW Version info: 2.4 Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Sep 15 18:26:25 motivo volumio[17652]: info: Setting Additional System Software info: Hardware Revision: 2.4, Firmware Version: 0.1.9 Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Sep 15 18:26:25 motivo volumio[17652]: info: Setting HW Firmware info: 0.1.9 Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Sep 15 18:26:25 motivo volumio[17652]: info: Setting HW Version info: 2.4 Sep 15 18:26:25 motivo volumio[17652]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Sep 15 18:26:25 motivo volumio[17652]: info: MCU Signalled Headphone Mode Disabled Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Sep 15 18:26:25 motivo volumio[17652]: info: MCU Signalled Sleep Mode Disabled Sep 15 18:26:25 motivo qobuz-connect[17858]: 20250915 18:26:25.587 [17858.17858] INFO LocalConfigManager: [0x22c1b80]: Starting Local Configuration server Sep 15 18:26:25 motivo qobuz-connect[17858]: 20250915 18:26:25.588 [17858.17858] INFO SampleApp: Starting Local configuration server Sep 15 18:26:25 motivo qobuz-connect[17858]: 20250915 18:26:25.588 [17858.17858] INFO SampleApp: Connected to UNIX socket client 0x22b7f60 Sep 15 18:26:25 motivo volumio[17652]: info: Enabling Advanced system settings configuration Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , addAdditionalUISections Sep 15 18:26:25 motivo volumio[17652]: info: Additional UI Settings Added for plugin music_service/inputs Sep 15 18:26:25 motivo volumio[17652]: info: MCU Signalled Auto Boot Mode On Power Disabled Sep 15 18:26:25 motivo sudo[17884]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on Sep 15 18:26:25 motivo sudo[17884]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:25 motivo volumio[17652]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Sep 15 18:26:25 motivo volumio[17652]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Sep 15 18:26:25 motivo volumio[17652]: info: QobuzConnect: QOBUZ Connect daemon connected Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo sudo[17884]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 15 18:26:25 motivo volumio[17652]: error: Serial API: Failed to decode command: MAXVOL, message: 100 Sep 15 18:26:25 motivo volumio[17652]: error: Serial API: Failed to decode command: MAXVOL, message: 100 Sep 15 18:26:25 motivo qobuz-connect[17858]: 20250915 18:26:25.716 [17858.17858] INFO SampleApp: Playback volume changed: 75 Sep 15 18:26:25 motivo volumio[17652]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Sep 15 18:26:25 motivo volumio[17652]: info: Volumio called home Sep 15 18:26:25 motivo volumio[17652]: info: CoreCommandRouter::volumioGetState Sep 15 18:26:25 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:25 motivo sudo[17895]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0 Sep 15 18:26:25 motivo sudo[17895]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:25 motivo volumio[17652]: info: Starting Shairport Sync Sep 15 18:26:25 motivo sudo[17895]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:25 motivo volumio[17652]: info: Starting Shairport Sync Sep 15 18:26:25 motivo volumio[17652]: info: Starting Shairport Sync Sep 15 18:26:25 motivo sudo[17898]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 15 18:26:25 motivo sudo[17898]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:25 motivo volumio[17652]: info: Adding Inputs via Serial API Sep 15 18:26:25 motivo sudo[17900]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 15 18:26:26 motivo sudo[17900]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:26 motivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 15 18:26:26 motivo volumio[17652]: info: CoreCommandRouter::volumioGetState Sep 15 18:26:26 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:26 motivo systemd[1]: shairport-sync.service: Succeeded. Sep 15 18:26:26 motivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 15 18:26:26 motivo sudo[17903]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 15 18:26:26 motivo sudo[17903]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:26 motivo volumio[17652]: info: Adding Advanced Audio Settings via Serial API Sep 15 18:26:26 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Sep 15 18:26:26 motivo volumio[17652]: info: Additional UI Settings Added for plugin music_service/inputs Sep 15 18:26:26 motivo volumio[17652]: info: Adding Advanced Audio Settings via Serial API Sep 15 18:26:26 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Sep 15 18:26:26 motivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 15 18:26:26 motivo sudo[17898]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:26 motivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 15 18:26:26 motivo systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Sep 15 18:26:26 motivo systemd[1]: shairport-sync.service: Succeeded. Sep 15 18:26:26 motivo volumio[17652]: info: CoreCommandRouter::volumioGetState Sep 15 18:26:26 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:26 motivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 15 18:26:26 motivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 15 18:26:26 motivo sudo[17900]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:26 motivo sudo[17903]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:26 motivo volumio[17652]: info: CoreCommandRouter::servicePushState Sep 15 18:26:26 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:26 motivo volumio[17652]: verbose: STATE SERVICE {"status":"play","service":"inputs","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"","seek":0,"duration":0,"samplerate":"","bitdepth":"","stream":true,"disableUiControls":true,"channels":2} Sep 15 18:26:26 motivo volumio[17652]: verbose: CURRENT POSITION 0 Sep 15 18:26:26 motivo volumio[17652]: info: CoreStateMachine::syncState stateService play Sep 15 18:26:26 motivo volumio[17652]: info: CoreStateMachine::syncState currentStatus stop Sep 15 18:26:26 motivo volumio[17652]: info: CoreCommandRouter::volumiosetSourceActiveno-source Sep 15 18:26:26 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 15 18:26:26 motivo volumio[17652]: info: CoreStateMachine::pushState Sep 15 18:26:26 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:26 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:26:26 motivo volumio[17652]: info: CoreCommandRouter::volumioPushState Sep 15 18:26:26 motivo volumio[17652]: info: CoreCommandRouter::volumioGetState Sep 15 18:26:26 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:26 motivo volumio[17652]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:26:26 motivo volumio[17652]: info: MRS: Pushing multiroomSync output Sep 15 18:26:26 motivo volumio[17652]: info: CoreStateMachine::pushState Sep 15 18:26:26 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:26 motivo volumio[17652]: info: CoreCommandRouter::volumioPushState Sep 15 18:26:26 motivo volumio[17652]: info: CoreCommandRouter::volumioGetState Sep 15 18:26:26 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:26 motivo volumio[17652]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:26:26 motivo volumio[17652]: info: MRS: Pushing multiroomSync output Sep 15 18:26:26 motivo volumio[17652]: info: Shairport-Sync Started Sep 15 18:26:26 motivo volumio[17652]: Error adding Membership: Error: addMembership EINVAL Sep 15 18:26:26 motivo volumio[17652]: info: Shairport-Sync Started Sep 15 18:26:26 motivo volumio[17652]: info: Shairport-Sync Started Sep 15 18:26:26 motivo volumio[17652]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:26:26 motivo volumio[17652]: info: CoreStateMachine::getQueue Sep 15 18:26:26 motivo volumio[17652]: info: CorePlayQueue::getQueue Sep 15 18:26:26 motivo volumio[17652]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:26:26 motivo volumio[17652]: info: CoreStateMachine::getQueue Sep 15 18:26:26 motivo volumio[17652]: info: CorePlayQueue::getQueue Sep 15 18:26:26 motivo volumio[17652]: info: MCU Signalled Playback Inactive Sep 15 18:26:26 motivo sudo[17926]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 15 18:26:26 motivo sudo[17926]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:26 motivo sudo[17926]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:26 motivo sudo[17928]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 15 18:26:26 motivo sudo[17928]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:26 motivo sudo[17928]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:26 motivo sudo[17932]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 15 18:26:26 motivo sudo[17932]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 15 18:26:26 motivo sudo[17932]: pam_unix(sudo:session): session closed for user root Sep 15 18:26:26 motivo volumio[17652]: info: Upmpdcli Daemon Started Sep 15 18:26:27 motivo volumio[17652]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Sep 15 18:26:27 motivo volumio[17652]: info: CoreCommandRouter::volumioGetState Sep 15 18:26:27 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:27 motivo volumio[17652]: info: Signalling Playback active due to playback status change Sep 15 18:26:27 motivo volumio[17652]: info: MCU Signalled Playback Active Sep 15 18:26:27 motivo volumio[17652]: verbose: New Socket.io Connection to 192.168.104.230 from 192.168.104.202 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 10 Sep 15 18:26:27 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 15 18:26:27 motivo volumio[17652]: info: CoreCommandRouter::volumioGetVisibleSources Sep 15 18:26:27 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 15 18:26:27 motivo volumio[17652]: info: CoreCommandRouter::volumioGetState Sep 15 18:26:27 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:27 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 15 18:26:27 motivo volumio[17652]: info: CoreCommandRouter::volumioGetQueue Sep 15 18:26:27 motivo volumio[17652]: info: CoreStateMachine::getQueue Sep 15 18:26:27 motivo volumio[17652]: info: CorePlayQueue::getQueue Sep 15 18:26:27 motivo volumio[17652]: info: Listing playlists Sep 15 18:26:27 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 15 18:26:27 motivo volumio[17652]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Sep 15 18:26:27 motivo volumio[17652]: info: Received Get System Info Sep 15 18:26:27 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 15 18:26:27 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 15 18:26:27 motivo volumio[17652]: info: Discovery: Getting this device information Sep 15 18:26:27 motivo volumio[17652]: info: CoreCommandRouter::volumioGetState Sep 15 18:26:27 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:27 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 15 18:26:27 motivo volumio[17652]: info: CoreCommandRouter::volumioGetState Sep 15 18:26:27 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:28 motivo volumio[17652]: info: Initializing I2S Bus Sep 15 18:26:29 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 15 18:26:29 motivo volumio[17652]: info: Preload queue cleared Sep 15 18:26:29 motivo volumio[17652]: info: Successfully initialized Motivo I2S Bus Sep 15 18:26:29 motivo volumio[17652]: info: MRS: Getting audio outputs on start Sep 15 18:26:29 motivo volumio[17652]: info: MRS: Requesting all other devices output Sep 15 18:26:31 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 15 18:26:31 motivo volumio[17652]: info: Preload queue cleared Sep 15 18:26:31 motivo volumio-remote-updater[714]: [2025-09-15 18:26:31] [connect] Successful connection Sep 15 18:26:31 motivo volumio-remote-updater[714]: [2025-09-15 18:26:31] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1757928391 101 Sep 15 18:26:31 motivo volumio[17652]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 11 Sep 15 18:26:35 motivo volumio[17652]: info: Checking for updated MCU Firmware Sep 15 18:26:35 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 15 18:26:35 motivo volumio[17652]: info: Firware on device is on latest version, no need to update Sep 15 18:26:37 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 15 18:26:37 motivo volumio[17652]: info: Preload queue cleared Sep 15 18:26:38 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 15 18:26:38 motivo volumio[17652]: info: Preload queue cleared Sep 15 18:26:39 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 15 18:26:39 motivo volumio[17652]: info: Preload queue cleared Sep 15 18:26:39 motivo volumio[17652]: info: Preloading song: upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@431 Sep 15 18:26:40 motivo volumio[17652]: info: Exploding uri upnp/http://192.168.104.241:50001/ContentDirectory/control@22$@431 in service upnp_browser Sep 15 18:26:40 motivo volumio[17652]: info: Executing endpoint getSimilarAlbums Sep 15 18:26:40 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Sep 15 18:26:40 motivo volumio[17652]: info: Executing endpoint metavolumio Sep 15 18:26:40 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 15 18:26:40 motivo volumio[17652]: info: Executing endpoint metavolumio Sep 15 18:26:40 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 15 18:26:41 motivo volumio[17652]: info: Preload queue cleared Sep 15 18:26:41 motivo volumio[17652]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 15 18:26:41 motivo volumio[17652]: info: CoreStateMachine::ClearQueue Sep 15 18:26:41 motivo volumio[17652]: info: CoreStateMachine::stop Sep 15 18:26:41 motivo volumio[17652]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 15 18:26:41 motivo volumio[17652]: info: CoreStateMachine::stPlaybackTimer Sep 15 18:26:41 motivo volumio[17652]: info: CoreStateMachine::updateTrackBlock Sep 15 18:26:41 motivo volumio[17652]: info: CorePlayQueue::getTrackBlock Sep 15 18:26:41 motivo volumio[17652]: info: CoreStateMachine::pushState Sep 15 18:26:41 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:41 motivo volumio[17652]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 15 18:26:41 motivo volumio[17652]: info: CoreCommandRouter::volumioPushState Sep 15 18:26:41 motivo volumio[17652]: info: CoreCommandRouter::volumioGetState Sep 15 18:26:41 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:41 motivo volumio[17652]: info: MRS: Pushing multiroomSync output update for this device Sep 15 18:26:41 motivo volumio[17652]: info: MRS: Pushing multiroomSync output Sep 15 18:26:41 motivo volumio[17652]: info: CoreStateMachine::serviceStop Sep 15 18:26:41 motivo volumio[17652]: info: CorePlayQueue::getTrack 0 Sep 15 18:26:41 motivo volumio[17652]: info: CoreCommandRouter::serviceStop Sep 15 18:26:41 motivo volumio[17652]: info: [1757928401538] ControllerUPNPBrowser::stop Sep 15 18:26:41 motivo volumio[17652]: verbose: ControllerMpd::sendMpdCommand stop Sep 15 18:26:41 motivo volumio[17652]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 15 18:26:41 motivo volumio[17652]: TypeError: Cannot read property 'then' of undefined Sep 15 18:26:41 motivo volumio[17652]: at ControllerMpd.sendMpdCommand (/volumio/app/plugins/music_service/mpd/index.js:332:6) Sep 15 18:26:41 motivo volumio[17652]: at ControllerUPNPBrowser.stop (/volumio/app/plugins/music_service/upnp_browser/index.js:447:25) Sep 15 18:26:41 motivo volumio[17652]: at CoreCommandRouter.serviceStop (/volumio/app/index.js:371:25) Sep 15 18:26:41 motivo volumio[17652]: at CoreStateMachine.serviceStop (/volumio/app/statemachine.js:1271:33) Sep 15 18:26:41 motivo volumio[17652]: at CoreStateMachine.stop (/volumio/app/statemachine.js:1246:19) Sep 15 18:26:41 motivo volumio[17652]: at CoreStateMachine.clearQueue (/volumio/app/statemachine.js:275:8) Sep 15 18:26:41 motivo volumio[17652]: at CoreCommandRouter.replaceAndPlay (/volumio/app/index.js:494:21) Sep 15 18:26:41 motivo volumio[17652]: at CoreCommandRouter.playItemsList (/volumio/app/index.js:484:17) Sep 15 18:26:41 motivo volumio[17652]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:142:33) Sep 15 18:26:41 motivo volumio[17652]: at Socket.emit (events.js:315:20) Sep 15 18:26:41 motivo volumio[17652]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Sep 15 18:26:41 motivo volumio[17652]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Sep 15 18:26:41 motivo volumio[17652]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 15 18:26:41 motivo sudo[18002]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-15 18:25 Sep 15 18:26:41 motivo sudo[18002]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="669bb6cc406bb77b11c5184fedb8a4dfd19ba4ec" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="motivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 12:42:34 PM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="cm4" VOLUMIO_DEVICENAME="CM4" VOLUMIO_VENDOR_MODEL="Volumio Motivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Motivo" VOLUMIO_HASH="03b8c851b751de445da30842a70a04d1"