-- Logs begin at Sat 2025-01-18 20:34:33 JST, end at Sat 2025-01-18 21:11:12 JST. -- Jan 18 21:10:00 rivo volumio[3282]: info: Executing endpoint metavolumio Jan 18 21:10:00 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 18 21:10:00 rivo volumio[3282]: info: Executing endpoint metavolumio Jan 18 21:10:00 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 18 21:10:00 rivo volumio[3282]: info: Executing endpoint metavolumio Jan 18 21:10:00 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.0.17:52100/Music/F8010.mp3?Reader=454" Jan 18 21:10:01 rivo volumio[3282]: error: updateQueue error: null Jan 18 21:10:01 rivo volumio[3282]: error: updateQueue error: null Jan 18 21:10:01 rivo volumio[3282]: info: Jan 18 21:10:01 rivo volumio[3282]: ---------------------------- MPD announces system playlist update Jan 18 21:10:01 rivo volumio[3282]: info: Ignoring MPD Status Update Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 2872ms Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 2871ms Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand add "http://192.168.0.17:52100/Music/F8010.mp3?Reader=454" took 10 milliseconds Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand play Jan 18 21:10:01 rivo volumio[3282]: info: Jan 18 21:10:01 rivo volumio[3282]: ---------------------------- MPD announces system playlist update Jan 18 21:10:01 rivo volumio[3282]: info: Ignoring MPD Status Update Jan 18 21:10:01 rivo volumio[3282]: info: Jan 18 21:10:01 rivo volumio[3282]: ---------------------------- MPD announces system playlist update Jan 18 21:10:01 rivo volumio[3282]: info: Ignoring MPD Status Update Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 15ms Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand play took 9 milliseconds Jan 18 21:10:01 rivo kernel: aml_spdif_open Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 8ms Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 5ms Jan 18 21:10:01 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Jan 18 21:10:01 rivo volumio[3282]: info: Jan 18 21:10:01 rivo volumio[3282]: ---------------------------- MPD announces state update: player Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::getState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jan 18 21:10:01 rivo kernel: set normal 512 fs /4 fs Jan 18 21:10:01 rivo kernel: set spdifout clk:5644800, mpll:22579200 Jan 18 21:10:01 rivo kernel: get spdifout clk:5644797, mpll:22579186 Jan 18 21:10:01 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Jan 18 21:10:01 rivo kernel: set normal 512 fs /4 fs Jan 18 21:10:01 rivo kernel: set spdifout clk:5644800, mpll:22579200 Jan 18 21:10:01 rivo kernel: get spdifout clk:5644797, mpll:22579186 Jan 18 21:10:01 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Jan 18 21:10:01 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Jan 18 21:10:01 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Jan 18 21:10:01 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Jan 18 21:10:01 rivo volumio[3282]: info: Jan 18 21:10:01 rivo volumio[3282]: ---------------------------- MPD announces state update: player Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::getState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jan 18 21:10:01 rivo volumio[3282]: info: Jan 18 21:10:01 rivo volumio[3282]: ---------------------------- MPD announces state update: player Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::getState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jan 18 21:10:01 rivo volumio[3282]: info: Jan 18 21:10:01 rivo volumio[3282]: ---------------------------- MPD announces state update: player Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand status took 24 milliseconds Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::getState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand status took 23 milliseconds Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand status took 5 milliseconds Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::parseState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::parseState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::parseState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 18 21:10:01 rivo volumio[3282]: info: Jan 18 21:10:01 rivo volumio[3282]: ---------------------------- MPD announces state update: player Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::getState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jan 18 21:10:01 rivo volumio[3282]: info: Jan 18 21:10:01 rivo volumio[3282]: ---------------------------- MPD announces state update: player Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::getState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jan 18 21:10:01 rivo volumio[3282]: info: Jan 18 21:10:01 rivo volumio[3282]: ---------------------------- MPD announces system playlist update Jan 18 21:10:01 rivo volumio[3282]: info: Ignoring MPD Status Update Jan 18 21:10:01 rivo volumio[3282]: info: Jan 18 21:10:01 rivo volumio[3282]: ---------------------------- MPD announces state update: player Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand status took 19 milliseconds Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::getState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand playlistinfo took 17 milliseconds Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand playlistinfo took 16 milliseconds Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand playlistinfo took 16 milliseconds Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand status took 13 milliseconds Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand status took 9 milliseconds Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::parseState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::parseState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::parseState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::servicePushState Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getTrack 179 Jan 18 21:10:01 rivo volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"JOEPO ～DOWN TOWN","artist":"EPO","album":"THE BEST STATION JOEPO 1980-1984","uri":"http://192.168.0.17:52100/Music/F8010.mp3?Reader=454","trackType":""} Jan 18 21:10:01 rivo volumio[3282]: verbose: CURRENT POSITION 179 Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState stateService play Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState currentStatus stop Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::servicePushState Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getTrack 179 Jan 18 21:10:01 rivo volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"JOEPO ～DOWN TOWN","artist":"EPO","album":"THE BEST STATION JOEPO 1980-1984","uri":"http://192.168.0.17:52100/Music/F8010.mp3?Reader=454","trackType":""} Jan 18 21:10:01 rivo volumio[3282]: verbose: CURRENT POSITION 179 Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState stateService play Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState currentStatus play Jan 18 21:10:01 rivo volumio[3282]: info: Received an update from plugin. extracting info from payload Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioPushState Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output update for this device Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioPushState Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output update for this device Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::servicePushState Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getTrack 179 Jan 18 21:10:01 rivo volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"JOEPO ～DOWN TOWN","artist":"EPO","album":"THE BEST STATION JOEPO 1980-1984","uri":"http://192.168.0.17:52100/Music/F8010.mp3?Reader=454","trackType":""} Jan 18 21:10:01 rivo volumio[3282]: verbose: CURRENT POSITION 179 Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState stateService play Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState currentStatus play Jan 18 21:10:01 rivo volumio[3282]: info: Received an update from plugin. extracting info from payload Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioPushState Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output update for this device Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioPushState Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output update for this device Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 113ms Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 143ms Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 142ms Jan 18 21:10:01 rivo volumio[3282]: info: Jan 18 21:10:01 rivo volumio[3282]: ---------------------------- MPD announces system playlist update Jan 18 21:10:01 rivo volumio[3282]: info: Ignoring MPD Status Update Jan 18 21:10:01 rivo volumio[3282]: info: Jan 18 21:10:01 rivo volumio[3282]: ---------------------------- MPD announces state update: player Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::getState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jan 18 21:10:01 rivo volumio[3282]: info: Jan 18 21:10:01 rivo volumio[3282]: ---------------------------- MPD announces system playlist update Jan 18 21:10:01 rivo volumio[3282]: info: Ignoring MPD Status Update Jan 18 21:10:01 rivo volumio[3282]: info: Jan 18 21:10:01 rivo volumio[3282]: ---------------------------- MPD announces state update: player Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::getState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand status Jan 18 21:10:01 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 120ms Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand status took 117 milliseconds Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand playlistinfo took 112 milliseconds Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand playlistinfo took 93 milliseconds Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 17ms Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand status took 13 milliseconds Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 11ms Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand status took 12 milliseconds Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::parseState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::parseState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::parseState Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::servicePushState Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getTrack 179 Jan 18 21:10:01 rivo volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":191,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"JOEPO ～DOWN TOWN","artist":"EPO","album":"THE BEST STATION JOEPO 1980-1984","uri":"http://192.168.0.17:52100/Music/F8010.mp3?Reader=454","trackType":""} Jan 18 21:10:01 rivo volumio[3282]: verbose: CURRENT POSITION 179 Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState stateService play Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState currentStatus play Jan 18 21:10:01 rivo volumio[3282]: info: Received an update from plugin. extracting info from payload Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioPushState Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output update for this device Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioPushState Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output update for this device Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::servicePushState Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getTrack 179 Jan 18 21:10:01 rivo volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1188,"duration":191,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"JOEPO ～DOWN TOWN","artist":"EPO","album":"THE BEST STATION JOEPO 1980-1984","uri":"http://192.168.0.17:52100/Music/F8010.mp3?Reader=454","trackType":""} Jan 18 21:10:01 rivo volumio[3282]: verbose: CURRENT POSITION 179 Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState stateService play Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState currentStatus play Jan 18 21:10:01 rivo volumio[3282]: info: Received an update from plugin. extracting info from payload Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioPushState Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output update for this device Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioPushState Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output update for this device Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::servicePushState Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getTrack 179 Jan 18 21:10:01 rivo volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1188,"duration":191,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"JOEPO ～DOWN TOWN","artist":"EPO","album":"THE BEST STATION JOEPO 1980-1984","uri":"http://192.168.0.17:52100/Music/F8010.mp3?Reader=454","trackType":""} Jan 18 21:10:01 rivo volumio[3282]: verbose: CURRENT POSITION 179 Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState stateService play Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState currentStatus play Jan 18 21:10:01 rivo volumio[3282]: info: Received an update from plugin. extracting info from payload Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioPushState Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output update for this device Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioPushState Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output update for this device Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 269ms Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 259ms Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 257ms Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioGetQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioGetQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioGetQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioGetQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioGetQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioGetQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioGetQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioGetQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioGetQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioGetQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: Signalling Playback active due to playback status change Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand playlistinfo took 238 milliseconds Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand playlistinfo took 235 milliseconds Jan 18 21:10:01 rivo volumio[3282]: info: sendMpdCommand playlistinfo took 234 milliseconds Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jan 18 21:10:01 rivo volumio[3282]: verbose: ControllerMpd::parseTrackInfo Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::servicePushState Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getTrack 179 Jan 18 21:10:01 rivo volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1234,"duration":191,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"JOEPO ～DOWN TOWN","artist":"EPO","album":"THE BEST STATION JOEPO 1980-1984","uri":"http://192.168.0.17:52100/Music/F8010.mp3?Reader=454","trackType":""} Jan 18 21:10:01 rivo volumio[3282]: verbose: CURRENT POSITION 179 Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState stateService play Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState currentStatus play Jan 18 21:10:01 rivo volumio[3282]: info: Received an update from plugin. extracting info from payload Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioPushState Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output update for this device Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioPushState Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output update for this device Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::servicePushState Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getTrack 179 Jan 18 21:10:01 rivo volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1360,"duration":191,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"JOEPO ～DOWN TOWN","artist":"EPO","album":"THE BEST STATION JOEPO 1980-1984","uri":"http://192.168.0.17:52100/Music/F8010.mp3?Reader=454","trackType":""} Jan 18 21:10:01 rivo volumio[3282]: verbose: CURRENT POSITION 179 Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState stateService play Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState currentStatus play Jan 18 21:10:01 rivo volumio[3282]: info: Received an update from plugin. extracting info from payload Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioPushState Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output update for this device Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioPushState Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output update for this device Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output Jan 18 21:10:01 rivo volumio[3282]: info: ControllerMpd::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::servicePushState Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getTrack 179 Jan 18 21:10:01 rivo volumio[3282]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1485,"duration":191,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"JOEPO ～DOWN TOWN","artist":"EPO","album":"THE BEST STATION JOEPO 1980-1984","uri":"http://192.168.0.17:52100/Music/F8010.mp3?Reader=454","trackType":""} Jan 18 21:10:01 rivo volumio[3282]: verbose: CURRENT POSITION 179 Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState stateService play Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::syncState currentStatus play Jan 18 21:10:01 rivo volumio[3282]: info: Received an update from plugin. extracting info from payload Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioPushState Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output update for this device Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::pushState Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioPushState Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output update for this device Jan 18 21:10:01 rivo volumio[3282]: info: MRS: Pushing multiroomSync output Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 448ms Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 343ms Jan 18 21:10:01 rivo volumio[3282]: info: ------------------------------ 338ms Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioGetQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioGetQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioGetQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioGetQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioGetQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreCommandRouter::volumioGetQueue Jan 18 21:10:01 rivo volumio[3282]: info: CoreStateMachine::getQueue Jan 18 21:10:01 rivo volumio[3282]: info: CorePlayQueue::getQueue Jan 18 21:10:02 rivo volumio[3282]: info: MCU Signalled Playback Active Jan 18 21:10:02 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 21:10:02 rivo volumio[3282]: info: Preload queue cleared Jan 18 21:10:03 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 21:10:03 rivo volumio[3282]: info: Preload queue cleared Jan 18 21:10:05 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 21:10:05 rivo volumio[3282]: info: Preload queue cleared Jan 18 21:10:07 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 21:10:07 rivo volumio[3282]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:s":"http://schemas.xmlsoap.org/soap/envelope/","s:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"BrowseResponse":[{"$":{"xmlns:u":"urn:schemas-upnp-org:service:ContentDirectory:1"},"Result":[""],"NumberReturned":[{"_":"12389920"}],"TotalMatches":[{"_":"0"}],"UpdateID":[{"_":"0"}]}]}]}} Jan 18 21:10:07 rivo volumio[3282]: error: Failed to execute browseSource: Jan 18 21:10:24 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 18 21:10:24 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 18 21:10:24 rivo volumio[3282]: info: Discovery: Getting this device information Jan 18 21:10:24 rivo volumio[3282]: info: CoreCommandRouter::volumioGetState Jan 18 21:10:24 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 18 21:10:30 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 21:10:30 rivo volumio[3282]: info: Preload queue cleared Jan 18 21:10:30 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 21:10:31 rivo volumio[3282]: info: Preload queue cleared Jan 18 21:10:36 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 21:10:36 rivo volumio[3282]: info: Preload queue cleared Jan 18 21:10:40 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 21:10:41 rivo volumio[3282]: info: Preload queue cleared Jan 18 21:10:44 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 21:10:44 rivo volumio[3282]: info: Preload queue cleared Jan 18 21:10:54 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 18 21:10:54 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 18 21:10:54 rivo volumio[3282]: info: Discovery: Getting this device information Jan 18 21:10:54 rivo volumio[3282]: info: CoreCommandRouter::volumioGetState Jan 18 21:10:54 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 18 21:10:55 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 21:10:55 rivo volumio[3282]: info: Preload queue cleared Jan 18 21:10:58 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 21:10:58 rivo volumio[3282]: info: Preload queue cleared Jan 18 21:11:02 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 21:11:02 rivo volumio[3282]: info: Preload queue cleared Jan 18 21:11:06 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 21:11:06 rivo volumio[3282]: info: Preload queue cleared Jan 18 21:11:11 rivo volumio[3282]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 18 21:11:11 rivo volumio[3282]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 18 21:11:11 rivo volumio[3282]: TypeError: Cannot read property 'length' of undefined Jan 18 21:11:11 rivo volumio[3282]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jan 18 21:11:11 rivo volumio[3282]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jan 18 21:11:11 rivo volumio[3282]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jan 18 21:11:11 rivo volumio[3282]: at Parser.emit (events.js:400:28) Jan 18 21:11:11 rivo volumio[3282]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jan 18 21:11:11 rivo volumio[3282]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jan 18 21:11:11 rivo volumio[3282]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jan 18 21:11:11 rivo volumio[3282]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jan 18 21:11:11 rivo volumio[3282]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jan 18 21:11:11 rivo volumio[3282]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jan 18 21:11:11 rivo volumio[3282]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jan 18 21:11:11 rivo volumio[3282]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jan 18 21:11:11 rivo volumio[3282]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jan 18 21:11:11 rivo volumio[3282]: at IncomingMessage.emit (events.js:412:35) Jan 18 21:11:11 rivo volumio[3282]: at endReadableNT (internal/streams/readable.js:1333:12) Jan 18 21:11:11 rivo volumio[3282]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Jan 18 21:11:11 rivo volumio[3282]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 18 21:11:12 rivo sudo[11133]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-18 21:10 Jan 18 21:11:12 rivo sudo[11133]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 05:04:03 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="b3e66dc85ea2c87aca7db72b97d00dff"