-- Logs begin at Wed 2025-05-07 15:56:51 CEST, end at Wed 2025-05-07 16:02:53 CEST. -- May 07 16:01:00 rivo volumio[3442]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 07 16:01:00 rivo volumio[3442]: info: CoreCommandRouter::volumioGetState May 07 16:01:00 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:02 rivo volumio[3442]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 07 16:01:02 rivo volumio[3442]: info: CoreCommandRouter::volumioGetState May 07 16:01:02 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:03 rivo volumio[3442]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 07 16:01:03 rivo volumio[3442]: info: CoreCommandRouter::volumioGetState May 07 16:01:03 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:03 rivo volumio[3442]: info: CoreCommandRouter::volumioPlay May 07 16:01:03 rivo volumio[3442]: info: CoreStateMachine::play index undefined May 07 16:01:03 rivo volumio[3442]: info: CoreStateMachine::setConsumeUpdateService undefined May 07 16:01:03 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:03 rivo volumio[3442]: info: CoreStateMachine::startPlaybackTimer May 07 16:01:03 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:03 rivo volumio[3442]: info: [1746626463804] ControllerQobuz::clearAddPlayTrack May 07 16:01:03 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand stop May 07 16:01:03 rivo volumio[3442]: info: sendMpdCommand stop took 5 milliseconds May 07 16:01:03 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand clear May 07 16:01:03 rivo volumio[3442]: info: sendMpdCommand clear took 1 milliseconds May 07 16:01:03 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/323383057" May 07 16:01:03 rivo volumio[3442]: info: May 07 16:01:03 rivo volumio[3442]: ---------------------------- MPD announces system playlist update May 07 16:01:03 rivo volumio[3442]: info: Ignoring MPD Status Update May 07 16:01:03 rivo volumio[3442]: info: May 07 16:01:03 rivo volumio[3442]: ---------------------------- MPD announces system playlist update May 07 16:01:03 rivo volumio[3442]: info: Ignoring MPD Status Update May 07 16:01:03 rivo volumio[3442]: info: May 07 16:01:03 rivo volumio[3442]: ---------------------------- MPD announces system playlist update May 07 16:01:03 rivo volumio[3442]: info: Ignoring MPD Status Update May 07 16:01:03 rivo volumio[3442]: error: Upnp client error: Error: This socket has been ended by the other party May 07 16:01:03 rivo volumio[3442]: STREAMING PROXY: Handling url /?data=qobuz://song/323383057 May 07 16:01:03 rivo volumio[3442]: info: Executing endpoint getStreamUrlqobuz May 07 16:01:03 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI May 07 16:01:04 rivo volumio[3442]: info: getStreamUrl took 703 milliseconds May 07 16:01:04 rivo volumio[3442]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2774837&eid=323383057&fmt=7&profile=raw&app_id=539451548&cid=1944016&etsp=1746630064&hmac=ObxSPFJrfI7rBTNnN8TzuAWYk6Q May 07 16:01:04 rivo volumio[3442]: STREAMING PROXY: Response: 200, length: 172391255 May 07 16:01:04 rivo mpd[4002]: exception: No such playlist May 07 16:01:04 rivo volumio[3442]: error: updateQueue error: null May 07 16:01:04 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/323383057" May 07 16:01:04 rivo volumio[3442]: info: ------------------------------ 1037ms May 07 16:01:04 rivo volumio[3442]: info: ------------------------------ 1033ms May 07 16:01:04 rivo volumio[3442]: info: ------------------------------ 1031ms May 07 16:01:04 rivo volumio[3442]: info: May 07 16:01:04 rivo volumio[3442]: ---------------------------- MPD announces system playlist update May 07 16:01:04 rivo volumio[3442]: info: Ignoring MPD Status Update May 07 16:01:04 rivo volumio[3442]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/323383057" took 5 milliseconds May 07 16:01:04 rivo volumio[3442]: info: CoreStateMachine::setConsumeUpdateService mpd May 07 16:01:04 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand play May 07 16:01:04 rivo volumio[3442]: info: May 07 16:01:04 rivo volumio[3442]: ---------------------------- MPD announces system playlist update May 07 16:01:04 rivo volumio[3442]: info: Ignoring MPD Status Update May 07 16:01:04 rivo volumio[3442]: info: May 07 16:01:04 rivo volumio[3442]: ---------------------------- MPD announces system playlist update May 07 16:01:04 rivo volumio[3442]: STREAMING PROXY: Client dropped request, destroying May 07 16:01:04 rivo volumio[3442]: info: Ignoring MPD Status Update May 07 16:01:04 rivo volumio[3442]: info: ------------------------------ 15ms May 07 16:01:04 rivo volumio[3442]: info: sendMpdCommand play took 12 milliseconds May 07 16:01:04 rivo volumio[3442]: info: ------------------------------ 12ms May 07 16:01:04 rivo volumio[3442]: info: ------------------------------ 10ms May 07 16:01:04 rivo volumio[3442]: STREAMING PROXY: Handling url /?data=qobuz://song/323383057 May 07 16:01:04 rivo volumio[3442]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 07 16:01:04 rivo volumio[3442]: info: Executing endpoint getStreamUrlqobuz May 07 16:01:04 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI May 07 16:01:04 rivo volumio[3442]: info: CoreCommandRouter::volumioGetState May 07 16:01:04 rivo volumio[3442]: error: Failed to parse state for serial connection: TypeError: Cannot read property 'toUpperCase' of undefined May 07 16:01:04 rivo volumio[3442]: info: MCU Signalled Playback Inactive May 07 16:01:05 rivo volumio[3442]: info: getStreamUrl took 499 milliseconds May 07 16:01:05 rivo volumio[3442]: STREAMING PROXY: Got real url: https://streaming-qobuz-std.akamaized.net/file?uid=2774837&eid=323383057&fmt=7&profile=raw&app_id=539451548&cid=1944016&etsp=1746630065&hmac=VxzDLSVlYDwxS6ogtuQaRQKwTsE May 07 16:01:05 rivo volumio[3442]: STREAMING PROXY: Response: 200, length: 172391255 May 07 16:01:05 rivo volumio[3442]: info: May 07 16:01:05 rivo volumio[3442]: ---------------------------- MPD announces state update: player May 07 16:01:05 rivo kernel: aml_tdm_open May 07 16:01:05 rivo kernel: Not init audio effects May 07 16:01:05 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 May 07 16:01:05 rivo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk May 07 16:01:05 rivo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk May 07 16:01:05 rivo kernel: set mclk:12288000, mpll:24576000, get mclk:12287994, mpll:24575987 May 07 16:01:05 rivo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d12d218, id(1), clksel(1) May 07 16:01:05 rivo kernel: aml_dai_set_tdm_fmt(), fmt not change May 07 16:01:05 rivo kernel: dump_pcm_setting(ffffffc03d12d218) May 07 16:01:05 rivo kernel: pcm_mode(1) May 07 16:01:05 rivo kernel: sysclk(12288000) May 07 16:01:05 rivo kernel: sysclk_bclk_ratio(4) May 07 16:01:05 rivo kernel: bclk(3072000) May 07 16:01:05 rivo kernel: bclk_lrclk_ratio(64) May 07 16:01:05 rivo kernel: lrclk(48000) May 07 16:01:05 rivo kernel: tx_mask(0x3) May 07 16:01:05 rivo kernel: rx_mask(0x3) May 07 16:01:05 rivo kernel: slots(2) May 07 16:01:05 rivo kernel: slot_width(32) May 07 16:01:05 rivo kernel: lane_mask_in(0x2) May 07 16:01:05 rivo kernel: lane_mask_out(0x1) May 07 16:01:05 rivo kernel: lane_oe_mask_in(0x0) May 07 16:01:05 rivo kernel: lane_oe_mask_out(0x0) May 07 16:01:05 rivo kernel: lane_lb_mask_in(0x0) May 07 16:01:05 rivo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk May 07 16:01:05 rivo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk May 07 16:01:05 rivo kernel: set mclk:12288000, mpll:24576000, get mclk:12287994, mpll:24575987 May 07 16:01:05 rivo kernel: aml_dai_set_clkdiv, div 4, clksel(1) May 07 16:01:05 rivo kernel: aml_dai_set_bclk_ratio, select I2S mode May 07 16:01:05 rivo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B May 07 16:01:05 rivo kernel: aml_tdm_prepare(), reset fddr May 07 16:01:05 rivo kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10 May 07 16:01:05 rivo kernel: spdif_info: rate: 48000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x200, ch1_r:0x200 May 07 16:01:05 rivo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 07 16:01:05 rivo kernel: tdm playback mute: 0, lane_cnt = 8 May 07 16:01:05 rivo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 07 16:01:05 rivo kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B May 07 16:01:05 rivo kernel: set mclk:24576000, mpll:49152000, get mclk:24575987, mpll:49151974 May 07 16:01:05 rivo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d12d218, id(1), clksel(1) May 07 16:01:05 rivo kernel: aml_dai_set_tdm_fmt(), fmt not change May 07 16:01:05 rivo kernel: dump_pcm_setting(ffffffc03d12d218) May 07 16:01:05 rivo kernel: pcm_mode(1) May 07 16:01:05 rivo kernel: sysclk(24576000) May 07 16:01:05 rivo kernel: sysclk_bclk_ratio(4) May 07 16:01:05 rivo kernel: bclk(6144000) May 07 16:01:05 rivo kernel: bclk_lrclk_ratio(64) May 07 16:01:05 rivo kernel: lrclk(96000) May 07 16:01:05 rivo kernel: tx_mask(0x3) May 07 16:01:05 rivo kernel: rx_mask(0x3) May 07 16:01:05 rivo kernel: slots(2) May 07 16:01:05 rivo kernel: slot_width(32) May 07 16:01:05 rivo kernel: lane_mask_in(0x2) May 07 16:01:05 rivo kernel: lane_mask_out(0x1) May 07 16:01:05 rivo kernel: lane_oe_mask_in(0x0) May 07 16:01:05 rivo kernel: lane_oe_mask_out(0x0) May 07 16:01:05 rivo kernel: lane_lb_mask_in(0x0) May 07 16:01:05 rivo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk May 07 16:01:05 rivo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk May 07 16:01:05 rivo kernel: set mclk:24576000, mpll:49152000, get mclk:24575987, mpll:49151974 May 07 16:01:05 rivo kernel: aml_dai_set_clkdiv, div 4, clksel(1) May 07 16:01:05 rivo kernel: aml_dai_set_bclk_ratio, select I2S mode May 07 16:01:05 rivo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B May 07 16:01:05 rivo kernel: aml_tdm_prepare(), reset fddr May 07 16:01:05 rivo kernel: spdif_a fifo ctrl, frddr:0 type:4, 24 bits, chmask 0x3, swap 0x10 May 07 16:01:05 rivo kernel: spdif_info: rate: 96000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0xa00, ch1_r:0xa00 May 07 16:01:05 rivo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 07 16:01:05 rivo kernel: tdm playback mute: 0, lane_cnt = 8 May 07 16:01:05 rivo kernel: aml_tdm_prepare(), reset fddr May 07 16:01:05 rivo kernel: spdif_a fifo ctrl, frddr:0 type:4, 24 bits, chmask 0x3, swap 0x10 May 07 16:01:05 rivo kernel: spdif_info: rate: 96000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0xa00, ch1_r:0xa00 May 07 16:01:05 rivo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 07 16:01:05 rivo kernel: tdm playback mute: 0, lane_cnt = 8 May 07 16:01:05 rivo volumio[3442]: info: ControllerMpd::getState May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand status May 07 16:01:05 rivo volumio[3442]: info: May 07 16:01:05 rivo volumio[3442]: ---------------------------- MPD announces state update: player May 07 16:01:05 rivo volumio[3442]: info: ControllerMpd::getState May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand status May 07 16:01:05 rivo volumio[3442]: info: May 07 16:01:05 rivo volumio[3442]: ---------------------------- MPD announces state update: player May 07 16:01:05 rivo volumio[3442]: info: ControllerMpd::getState May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand status May 07 16:01:05 rivo volumio[3442]: info: May 07 16:01:05 rivo volumio[3442]: ---------------------------- MPD announces state update: player May 07 16:01:05 rivo volumio[3442]: info: sendMpdCommand status took 9 milliseconds May 07 16:01:05 rivo volumio[3442]: info: ControllerMpd::getState May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand status May 07 16:01:05 rivo volumio[3442]: info: sendMpdCommand status took 8 milliseconds May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::parseState May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::parseState May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 07 16:01:05 rivo volumio[3442]: info: May 07 16:01:05 rivo volumio[3442]: ---------------------------- MPD announces state update: player May 07 16:01:05 rivo volumio[3442]: info: ControllerMpd::getState May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand status May 07 16:01:05 rivo volumio[3442]: info: May 07 16:01:05 rivo volumio[3442]: ---------------------------- MPD announces state update: player May 07 16:01:05 rivo volumio[3442]: info: ControllerMpd::getState May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand status May 07 16:01:05 rivo volumio[3442]: info: sendMpdCommand status took 25 milliseconds May 07 16:01:05 rivo volumio[3442]: info: sendMpdCommand status took 20 milliseconds May 07 16:01:05 rivo volumio[3442]: info: sendMpdCommand playlistinfo took 17 milliseconds May 07 16:01:05 rivo volumio[3442]: info: sendMpdCommand playlistinfo took 17 milliseconds May 07 16:01:05 rivo volumio[3442]: info: sendMpdCommand status took 14 milliseconds May 07 16:01:05 rivo volumio[3442]: info: sendMpdCommand status took 6 milliseconds May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::parseState May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::parseState May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::parseTrackInfo May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::parseTrackInfo May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::parseState May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::parseState May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 07 16:01:05 rivo volumio[3442]: info: ControllerMpd::pushState May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::servicePushState May 07 16:01:05 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:05 rivo volumio[3442]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":542,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"323383057","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/323383057","trackType":"qobuz"} May 07 16:01:05 rivo volumio[3442]: verbose: CURRENT POSITION 0 May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::syncState stateService play May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::syncState currentStatus stop May 07 16:01:05 rivo volumio[3442]: info: ControllerMpd::pushState May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::servicePushState May 07 16:01:05 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:05 rivo volumio[3442]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":542,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"323383057","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/323383057","trackType":"qobuz"} May 07 16:01:05 rivo volumio[3442]: verbose: CURRENT POSITION 0 May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::syncState stateService play May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::syncState currentStatus play May 07 16:01:05 rivo volumio[3442]: info: Received an update from plugin. extracting info from payload May 07 16:01:05 rivo kernel: asoc-aml-card auge_sound: tdm playback enable May 07 16:01:05 rivo kernel: spdif_a is set to enable May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:05 rivo volumio[3442]: info: ------------------------------ 92ms May 07 16:01:05 rivo volumio[3442]: info: ------------------------------ 109ms May 07 16:01:05 rivo volumio[3442]: info: sendMpdCommand playlistinfo took 90 milliseconds May 07 16:01:05 rivo volumio[3442]: info: sendMpdCommand playlistinfo took 90 milliseconds May 07 16:01:05 rivo volumio[3442]: info: sendMpdCommand playlistinfo took 86 milliseconds May 07 16:01:05 rivo volumio[3442]: verbose: ControllerMpd::parseTrackInfo May 07 16:01:05 rivo volumio[3442]: info: ControllerMpd::pushState May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::servicePushState May 07 16:01:05 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:05 rivo volumio[3442]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":542,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"323383057","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/323383057","trackType":"qobuz"} May 07 16:01:05 rivo volumio[3442]: verbose: CURRENT POSITION 0 May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::syncState stateService play May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::syncState currentStatus play May 07 16:01:05 rivo volumio[3442]: info: Received an update from plugin. extracting info from payload May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:05 rivo volumio[3442]: info: ControllerMpd::pushState May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::servicePushState May 07 16:01:05 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:05 rivo volumio[3442]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":542,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"323383057","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/323383057","trackType":"qobuz"} May 07 16:01:05 rivo volumio[3442]: verbose: CURRENT POSITION 0 May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::syncState stateService play May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::syncState currentStatus play May 07 16:01:05 rivo volumio[3442]: info: Received an update from plugin. extracting info from payload May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:05 rivo volumio[3442]: info: ControllerMpd::pushState May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::servicePushState May 07 16:01:05 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:05 rivo volumio[3442]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":542,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"323383057","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/323383057","trackType":"qobuz"} May 07 16:01:05 rivo volumio[3442]: verbose: CURRENT POSITION 0 May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::syncState stateService play May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::syncState currentStatus play May 07 16:01:05 rivo volumio[3442]: info: Received an update from plugin. extracting info from payload May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:05 rivo volumio[3442]: info: ControllerMpd::pushState May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::servicePushState May 07 16:01:05 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:05 rivo volumio[3442]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":542,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"323383057","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/323383057","trackType":"qobuz"} May 07 16:01:05 rivo volumio[3442]: verbose: CURRENT POSITION 0 May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::syncState stateService play May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::syncState currentStatus play May 07 16:01:05 rivo volumio[3442]: info: Received an update from plugin. extracting info from payload May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:05 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:05 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:05 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:05 rivo volumio[3442]: info: ------------------------------ 417ms May 07 16:01:05 rivo volumio[3442]: info: ------------------------------ 416ms May 07 16:01:05 rivo volumio[3442]: info: ------------------------------ 410ms May 07 16:01:05 rivo volumio[3442]: info: ------------------------------ 404ms May 07 16:01:06 rivo volumio[3442]: info: Signalling Playback active due to playback status change May 07 16:01:06 rivo volumio[3442]: info: MCU Signalled Playback Active May 07 16:01:50 rivo kernel: usb 1-1.4.2: USB disconnect, device number 5 May 07 16:01:50 rivo volumio[3442]: info: May 07 16:01:50 rivo volumio[3442]: ---------------------------- USB Audio Device Detached May 07 16:01:50 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach May 07 16:01:50 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 07 16:01:50 rivo volumio[3442]: No protocol specified May 07 16:01:50 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:01:50 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , onStop May 07 16:01:50 rivo volumio[3442]: info: Stopping RAAT Plugin May 07 16:01:50 rivo sudo[4970]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop raat-daemon.service May 07 16:01:50 rivo sudo[4970]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:50 rivo systemd[1]: Stopping RAAT DAEMON... May 07 16:01:50 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 07 16:01:50 rivo systemd[1]: raat-daemon.service: Succeeded. May 07 16:01:50 rivo systemd[1]: Stopped RAAT DAEMON. May 07 16:01:50 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: running May 07 16:01:50 rivo sudo[4970]: pam_unix(sudo:session): session closed for user root May 07 16:01:50 rivo volumio[3442]: info: Raat Daemon stopped successfully May 07 16:01:54 rivo kernel: usb 1-1.4.2: new high-speed USB device number 6 using xhci-hcd May 07 16:01:54 rivo kernel: usb 1-1.4.2: New USB device found, idVendor=245f, idProduct=0815 May 07 16:01:54 rivo kernel: usb 1-1.4.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 May 07 16:01:54 rivo kernel: usb 1-1.4.2: Product: Qutest May 07 16:01:54 rivo kernel: usb 1-1.4.2: Manufacturer: Chord Electronics Ltd May 07 16:01:54 rivo kernel: usb 1-1.4.2: SerialNumber: 413-001 May 07 16:01:54 rivo kernel: usb 1-1.4.2: Unsupported device May 07 16:01:54 rivo kernel: usb 1-1.4.2: Warning! Unlikely big volume range (=32767), cval->res is probably wrong. May 07 16:01:54 rivo kernel: usb 1-1.4.2: [10] FU [PCM Playback Volume] ch = 2, val = -32767/0/1 May 07 16:01:54 rivo kernel: usb 1-1.4.2: Warning! Unlikely big volume range (=32767), cval->res is probably wrong. May 07 16:01:54 rivo kernel: usb 1-1.4.2: [10] FU [PCM Playback Volume] ch = 1, val = -32767/0/1 May 07 16:01:54 rivo volumio[3442]: info: May 07 16:01:54 rivo volumio[3442]: ---------------------------- USB Audio Device Attached May 07 16:01:54 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach May 07 16:01:54 rivo volumio[3442]: No protocol specified May 07 16:01:54 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:01:54 rivo volumio[3442]: info: CoreCommandRouter::Close All Modals sent May 07 16:01:54 rivo volumio[3442]: info: Preparing to save Alsa Options, stopping services first May 07 16:01:54 rivo volumio[3442]: info: CoreCommandRouter::volumioGetState May 07 16:01:54 rivo volumio[3442]: info: CoreCommandRouter::volumioPause May 07 16:01:54 rivo volumio[3442]: info: CoreStateMachine::pause May 07 16:01:54 rivo volumio[3442]: info: CoreStateMachine::stPlaybackTimer May 07 16:01:54 rivo volumio[3442]: info: CoreStateMachine::servicePause May 07 16:01:54 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:54 rivo volumio[3442]: info: CoreCommandRouter::servicePause May 07 16:01:54 rivo volumio[3442]: info: [1746626514735] ControllerQobuz::pause May 07 16:01:54 rivo volumio[3442]: info: CoreStateMachine::setConsumeUpdateService mpd May 07 16:01:54 rivo volumio[3442]: info: ControllerMpd::pause May 07 16:01:54 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand pause May 07 16:01:54 rivo volumio[3442]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"Qutest","alsacard":"Qutest"},"i2s":false} May 07 16:01:54 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 07 16:01:54 rivo volumio[3442]: No protocol specified May 07 16:01:54 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:01:54 rivo volumio[3442]: No protocol specified May 07 16:01:54 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:01:54 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 07 16:01:54 rivo volumio[3442]: No protocol specified May 07 16:01:54 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:01:54 rivo volumio[3442]: info: Setting mixer PCM for card Qutest May 07 16:01:54 rivo volumio[3442]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes May 07 16:01:54 rivo vtcs[4157]: [2025-05-07 16:01:54.955] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected May 07 16:01:54 rivo vtcs[4157]: [2025-05-07 16:01:54.955] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE May 07 16:01:55 rivo sudo[4997]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 07 16:01:55 rivo sudo[4997]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:55 rivo systemd[1]: Stopping Volumio Tidal Connect Service... May 07 16:01:55 rivo systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 07 16:01:55 rivo systemd[1]: vtcs.service: Succeeded. May 07 16:01:55 rivo systemd[1]: Stopped Volumio Tidal Connect Service. May 07 16:01:55 rivo sudo[4997]: pam_unix(sudo:session): session closed for user root May 07 16:01:55 rivo volumio[3442]: No protocol specified May 07 16:01:55 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 07 16:01:55 rivo volumio[3442]: info: Updating Volume Controller Parameters: Device: 5 Name: Qutest Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 07 16:01:55 rivo volumio[3442]: info: Disabling external Volume Control May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::getUIConfigOnPlugin May 07 16:01:55 rivo volumio[3442]: info: Preparing to generate the ALSA configuration file May 07 16:01:55 rivo kernel: asoc-aml-card auge_sound: tdm playback stop May 07 16:01:55 rivo kernel: spdif_a is set to disable May 07 16:01:55 rivo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 May 07 16:01:55 rivo kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B May 07 16:01:55 rivo kernel: tdm playback mute: 1, lane_cnt = 8 May 07 16:01:55 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 May 07 16:01:55 rivo volumio[3442]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 07 16:01:55 rivo volumio[3442]: info: Reading ALSA contributions from plugins. May 07 16:01:55 rivo sudo[5005]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 07 16:01:55 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: running May 07 16:01:55 rivo sudo[5005]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:55 rivo volumio[3442]: info: May 07 16:01:55 rivo volumio[3442]: ---------------------------- MPD announces state update: player May 07 16:01:55 rivo volumio[3442]: info: sendMpdCommand pause took 533 milliseconds May 07 16:01:55 rivo volumio[3442]: info: ControllerMpd::getState May 07 16:01:55 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand status May 07 16:01:55 rivo volumio[3442]: info: May 07 16:01:55 rivo volumio[3442]: ---------------------------- MPD announces state update: player May 07 16:01:55 rivo volumio[3442]: info: ControllerMpd::getState May 07 16:01:55 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand status May 07 16:01:55 rivo volumio[3442]: info: May 07 16:01:55 rivo volumio[3442]: ---------------------------- MPD announces state update: player May 07 16:01:55 rivo volumio[3442]: info: ControllerMpd::getState May 07 16:01:55 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand status May 07 16:01:55 rivo volumio[3442]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 07 16:01:55 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:01:55 rivo sudo[5005]: pam_unix(sudo:session): session closed for user root May 07 16:01:55 rivo volumio[3442]: info: sendMpdCommand status took 54 milliseconds May 07 16:01:55 rivo volumio[3442]: info: sendMpdCommand status took 50 milliseconds May 07 16:01:55 rivo volumio[3442]: info: sendMpdCommand status took 49 milliseconds May 07 16:01:55 rivo volumio[3442]: verbose: ControllerMpd::parseState May 07 16:01:55 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 07 16:01:55 rivo volumio[3442]: verbose: ControllerMpd::parseState May 07 16:01:55 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 07 16:01:55 rivo volumio[3442]: verbose: ControllerMpd::parseState May 07 16:01:55 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 07 16:01:55 rivo volumio[3442]: info: sendMpdCommand playlistinfo took 7 milliseconds May 07 16:01:55 rivo volumio[3442]: info: sendMpdCommand playlistinfo took 7 milliseconds May 07 16:01:55 rivo volumio[3442]: info: sendMpdCommand playlistinfo took 6 milliseconds May 07 16:01:55 rivo volumio[3442]: verbose: ControllerMpd::parseTrackInfo May 07 16:01:55 rivo volumio[3442]: verbose: ControllerMpd::parseTrackInfo May 07 16:01:55 rivo volumio[3442]: verbose: ControllerMpd::parseTrackInfo May 07 16:01:55 rivo volumio[3442]: info: ControllerMpd::pushState May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::servicePushState May 07 16:01:55 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:55 rivo volumio[3442]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":49743,"duration":542,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2483 Kbps","isStreaming":false,"title":"323383057","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/323383057","trackType":"qobuz"} May 07 16:01:55 rivo volumio[3442]: verbose: CURRENT POSITION 0 May 07 16:01:55 rivo volumio[3442]: info: CoreStateMachine::syncState stateService pause May 07 16:01:55 rivo volumio[3442]: info: CoreStateMachine::syncState currentStatus pause May 07 16:01:55 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:55 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:55 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:55 rivo volumio[3442]: info: CoreStateMachine::stPlaybackTimer May 07 16:01:55 rivo volumio[3442]: info: ControllerMpd::pushState May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::servicePushState May 07 16:01:55 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:55 rivo volumio[3442]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":49743,"duration":542,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2483 Kbps","isStreaming":false,"title":"323383057","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/323383057","trackType":"qobuz"} May 07 16:01:55 rivo volumio[3442]: verbose: CURRENT POSITION 0 May 07 16:01:55 rivo volumio[3442]: info: CoreStateMachine::syncState stateService pause May 07 16:01:55 rivo volumio[3442]: info: CoreStateMachine::syncState currentStatus pause May 07 16:01:55 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:55 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:55 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:55 rivo volumio[3442]: info: CoreStateMachine::stPlaybackTimer May 07 16:01:55 rivo volumio[3442]: info: ControllerMpd::pushState May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::servicePushState May 07 16:01:55 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:55 rivo volumio[3442]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":49743,"duration":542,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2483 Kbps","isStreaming":false,"title":"323383057","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/323383057","trackType":"qobuz"} May 07 16:01:55 rivo volumio[3442]: verbose: CURRENT POSITION 0 May 07 16:01:55 rivo volumio[3442]: info: CoreStateMachine::syncState stateService pause May 07 16:01:55 rivo volumio[3442]: info: CoreStateMachine::syncState currentStatus pause May 07 16:01:55 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:55 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:55 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:55 rivo volumio[3442]: info: CoreStateMachine::stPlaybackTimer May 07 16:01:55 rivo volumio[3442]: info: ------------------------------ 137ms May 07 16:01:55 rivo volumio[3442]: info: ------------------------------ 134ms May 07 16:01:55 rivo volumio[3442]: info: ------------------------------ 132ms May 07 16:01:55 rivo volumio[3442]: No protocol specified May 07 16:01:55 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 07 16:01:55 rivo volumio[3442]: No protocol specified May 07 16:01:55 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection May 07 16:01:55 rivo volumio[3442]: info: VolumeController:: Volume=undefined Mute =false May 07 16:01:55 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:55 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:55 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: Not Reporting Auto name since its the default one May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: Not Reporting Auto name since its the default one May 07 16:01:55 rivo volumio[3442]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined May 07 16:01:55 rivo volumio[3442]: info: Updating RAAT Signal Path May 07 16:01:55 rivo volumio[3442]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 07 16:01:55 rivo volumio[3442]: No protocol specified May 07 16:01:55 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:01:55 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 07 16:01:55 rivo sudo[5056]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 07 16:01:55 rivo sudo[5056]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:55 rivo sudo[5056]: pam_unix(sudo:session): session closed for user root May 07 16:01:56 rivo sudo[5069]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 07 16:01:56 rivo sudo[5069]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:56 rivo volumio[3442]: No protocol specified May 07 16:01:56 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:01:56 rivo volumio[3442]: info: Asound.conf file unchanged, so no further update is needed May 07 16:01:56 rivo systemd[1]: Started RAAT DAEMON. May 07 16:01:56 rivo volumio[3442]: info: Output device has changed, restarting MPD May 07 16:01:56 rivo sudo[5069]: pam_unix(sudo:session): session closed for user root May 07 16:01:56 rivo sudo[5084]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 07 16:01:56 rivo sudo[5084]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:56 rivo sudo[5084]: pam_unix(sudo:session): session closed for user root May 07 16:01:56 rivo sudo[5099]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 07 16:01:56 rivo sudo[5099]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:56 rivo sudo[5099]: pam_unix(sudo:session): session closed for user root May 07 16:01:56 rivo sudo[5101]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 07 16:01:56 rivo sudo[5101]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:56 rivo volumio[3442]: info: Output device has changed, restarting Shairport Sync May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 07 16:01:56 rivo systemd[1]: Stopping RAAT DAEMON... May 07 16:01:56 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 07 16:01:56 rivo systemd[1]: raat-daemon.service: Succeeded. May 07 16:01:56 rivo systemd[1]: Stopped RAAT DAEMON. May 07 16:01:56 rivo sudo[5112]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 07 16:01:56 rivo sudo[5112]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:56 rivo systemd[1]: Started RAAT DAEMON. May 07 16:01:56 rivo sudo[5101]: pam_unix(sudo:session): session closed for user root May 07 16:01:56 rivo systemd[1]: Stopping Music Player Daemon... May 07 16:01:56 rivo volumio[3442]: STREAMING PROXY: Client dropped request, destroying May 07 16:01:56 rivo volumio[3442]: No protocol specified May 07 16:01:56 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:01:56 rivo volumio[3442]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 07 16:01:56 rivo volumio[3442]: No protocol specified May 07 16:01:56 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:01:56 rivo volumio[3442]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 07 16:01:56 rivo mpd[4002]: player: played "http://127.0.0.1:3245?data=qobuz://song/323383057" May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo systemd[1]: mpd.service: Succeeded. May 07 16:01:56 rivo systemd[1]: Stopped Music Player Daemon. May 07 16:01:56 rivo sudo[5132]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 07 16:01:56 rivo sudo[5132]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:56 rivo systemd[1]: Starting Music Player Daemon... May 07 16:01:56 rivo sudo[5132]: pam_unix(sudo:session): session closed for user root May 07 16:01:56 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: running May 07 16:01:56 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 07 16:01:56 rivo sudo[5138]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 07 16:01:56 rivo sudo[5138]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:56 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: running May 07 16:01:56 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 07 16:01:56 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: running May 07 16:01:56 rivo volumio[3442]: info: MCU Signalled Playback Inactive May 07 16:01:56 rivo sudo[5138]: pam_unix(sudo:session): session closed for user root May 07 16:01:56 rivo volumio[3442]: info: MPD Permissions set May 07 16:01:56 rivo volumio[3442]: info: Raat Daemon started successfully May 07 16:01:56 rivo volumio[3442]: info: Raat Daemon started successfully May 07 16:01:56 rivo volumio[3442]: error: Upnp client error: Error: This socket has been ended by the other party May 07 16:01:56 rivo volumio[3442]: info: Executing endpoint restartRAATSocket May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 07 16:01:56 rivo volumio[3442]: info: Executing endpoint restartRAATSocket May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 07 16:01:56 rivo sudo[5135]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 07 16:01:56 rivo sudo[5135]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:56 rivo sudo[5135]: pam_unix(sudo:session): session closed for user root May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 May 07 16:01:56 rivo volumio[3442]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 07 16:01:56 rivo volumio[3442]: info: Starting Shairport Sync May 07 16:01:56 rivo sudo[5155]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 07 16:01:56 rivo sudo[5155]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:56 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 07 16:01:56 rivo systemd[1]: shairport-sync.service: Succeeded. May 07 16:01:56 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 07 16:01:56 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 07 16:01:56 rivo sudo[5155]: pam_unix(sudo:session): session closed for user root May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:01:56 rivo volumio[3442]: info: Not Reporting Auto name since its the default one May 07 16:01:56 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: running May 07 16:01:56 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 07 16:01:56 rivo volumio[3442]: info: Shairport-Sync Started May 07 16:01:56 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 07 16:01:56 rivo volumio[3442]: No protocol specified May 07 16:01:56 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:01:57 rivo sudo[5169]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 07 16:01:57 rivo sudo[5169]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:57 rivo sudo[5169]: pam_unix(sudo:session): session closed for user root May 07 16:01:57 rivo sudo[5171]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 07 16:01:57 rivo sudo[5171]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:57 rivo systemd[1]: Stopping RAAT DAEMON... May 07 16:01:57 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 07 16:01:57 rivo systemd[1]: raat-daemon.service: Succeeded. May 07 16:01:57 rivo systemd[1]: Stopped RAAT DAEMON. May 07 16:01:57 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: running May 07 16:01:57 rivo systemd[1]: Started RAAT DAEMON. May 07 16:01:57 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 07 16:01:57 rivo sudo[5171]: pam_unix(sudo:session): session closed for user root May 07 16:01:57 rivo volumio[3442]: info: Raat Daemon started successfully May 07 16:01:57 rivo volumio[3442]: info: Executing endpoint restartRAATSocket May 07 16:01:57 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 07 16:01:57 rivo volumio[3442]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 07 16:01:58 rivo volumio[3442]: info: TidalConnect service stoped! May 07 16:01:58 rivo volumio[3442]: info: TidalConnect service stoped! May 07 16:01:58 rivo volumio[3442]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 07 16:01:58 rivo volumio[3442]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 07 16:01:58 rivo sudo[5194]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 07 16:01:58 rivo sudo[5194]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:58 rivo mpd[5151]: May 07 16:01 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 07 16:01:58 rivo systemd[1]: Started Volumio Tidal Connect Service. May 07 16:01:58 rivo sudo[5194]: pam_unix(sudo:session): session closed for user root May 07 16:01:58 rivo systemd[1]: Started Music Player Daemon. May 07 16:01:58 rivo sudo[5112]: pam_unix(sudo:session): session closed for user root May 07 16:01:58 rivo volumio[3442]: error: updateQueue error: null May 07 16:01:58 rivo volumio[3442]: info: Executing endpoint tc_getconfig May 07 16:01:58 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 07 16:01:58 rivo vtcs[5196]: STARTING TidalConnect services, version: 1.4.0.34 May 07 16:01:58 rivo volumio[3442]: info: RAAT: Requesting Headphone Status May 07 16:01:58 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 07 16:01:58 rivo vtcs[5196]: STARTED TidalConnect services. May 07 16:01:58 rivo volumio[3442]: info: Executing endpoint tc_connect May 07 16:01:58 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 07 16:01:58 rivo volumio[3442]: info: Connecting to TidalConnect May 07 16:01:58 rivo volumio[3442]: info: CoreCommandRouter::servicePushState May 07 16:01:58 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:58 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:58 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:58 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:58 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:58 rivo volumio[3442]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect May 07 16:01:58 rivo volumio[3442]: info: CoreCommandRouter::servicePushState May 07 16:01:58 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:58 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:58 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:58 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:58 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:01:58 rivo volumio[3442]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect May 07 16:01:58 rivo volumio[3442]: info: Updating RAAT Signal Path May 07 16:01:59 rivo volumio[3442]: info: Updating RAAT Signal Path May 07 16:01:59 rivo volumio[3442]: info: MCU Signalled Headphone Mode Disabled May 07 16:01:59 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 07 16:01:59 rivo volumio[3442]: info: Reporting Headphone State: false May 07 16:01:59 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:59 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:59 rivo volumio[3442]: info: Updating RAAT Signal Path May 07 16:01:59 rivo volumio[3442]: info: RAAT: Requesting Headphone Status May 07 16:01:59 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 07 16:01:59 rivo volumio[3442]: info: MCU Signalled Headphone Mode Disabled May 07 16:01:59 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 07 16:01:59 rivo volumio[3442]: info: Reporting Headphone State: false May 07 16:01:59 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:01:59 rivo volumio[3442]: info: Updating RAAT Signal Path May 07 16:01:59 rivo volumio[3442]: info: CoreCommandRouter::volumioRetrieveVolumeLevels May 07 16:01:59 rivo volumio[3442]: info: CoreStateMachine::getcurrentVolume May 07 16:01:59 rivo volumio[3442]: info: CoreCommandRouter::volumioRetrievevolume May 07 16:01:59 rivo volumio[3442]: info: VolumeController:: Volume=40 Mute =false May 07 16:01:59 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:59 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:59 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:59 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:59 rivo volumio[3442]: info: CoreStateMachine::updateTrackBlock May 07 16:01:59 rivo volumio[3442]: info: CorePlayQueue::getTrackBlock May 07 16:01:59 rivo volumio[3442]: info: CoreCommandRouter::volumioRetrievevolume May 07 16:01:59 rivo volumio[3442]: info: Updating RAAT Signal Path May 07 16:01:59 rivo volumio[3442]: info: VolumeController:: Volume=40 Mute =false May 07 16:01:59 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:01:59 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:01:59 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:01:59 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:01:59 rivo volumio[3442]: info: Updating RAAT Signal Path May 07 16:01:59 rivo volumio[3442]: info: TidalConnect service stoped! May 07 16:01:59 rivo volumio[3442]: info: TidalConnect service stoped! May 07 16:01:59 rivo volumio[3442]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 07 16:01:59 rivo volumio[3442]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 07 16:01:59 rivo sudo[5230]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 07 16:01:59 rivo sudo[5230]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:01:59 rivo sudo[5230]: pam_unix(sudo:session): session closed for user root May 07 16:01:59 rivo volumio[3442]: info: RAAT: Requesting Headphone Status May 07 16:01:59 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 07 16:02:00 rivo volumio[3442]: info: MCU Signalled Headphone Mode Disabled May 07 16:02:00 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 07 16:02:00 rivo volumio[3442]: info: Reporting Headphone State: false May 07 16:02:00 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:00 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:00 rivo volumio[3442]: info: Updating RAAT Signal Path May 07 16:02:00 rivo volumio[3442]: error: Upnp client error: Error: This socket has been ended by the other party May 07 16:02:01 rivo volumio[3442]: info: TidalConnect service started! May 07 16:02:02 rivo volumio[3442]: info: TidalConnect service started! May 07 16:02:11 rivo kernel: usb 1-1.4.2: USB disconnect, device number 6 May 07 16:02:11 rivo volumio[3442]: info: May 07 16:02:11 rivo volumio[3442]: ---------------------------- USB Audio Device Detached May 07 16:02:11 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach May 07 16:02:11 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 07 16:02:11 rivo volumio[3442]: No protocol specified May 07 16:02:11 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:02:11 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , onStop May 07 16:02:11 rivo volumio[3442]: info: Stopping RAAT Plugin May 07 16:02:11 rivo sudo[5265]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop raat-daemon.service May 07 16:02:11 rivo sudo[5265]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:11 rivo systemd[1]: Stopping RAAT DAEMON... May 07 16:02:11 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 07 16:02:11 rivo systemd[1]: raat-daemon.service: Succeeded. May 07 16:02:11 rivo systemd[1]: Stopped RAAT DAEMON. May 07 16:02:11 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: running May 07 16:02:11 rivo sudo[5265]: pam_unix(sudo:session): session closed for user root May 07 16:02:11 rivo volumio[3442]: info: Raat Daemon stopped successfully May 07 16:02:17 rivo kernel: usb 1-1.4.2: new high-speed USB device number 7 using xhci-hcd May 07 16:02:17 rivo kernel: usb 1-1.4.2: New USB device found, idVendor=245f, idProduct=0815 May 07 16:02:17 rivo kernel: usb 1-1.4.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 May 07 16:02:17 rivo kernel: usb 1-1.4.2: Product: Qutest May 07 16:02:17 rivo kernel: usb 1-1.4.2: Manufacturer: Chord Electronics Ltd May 07 16:02:17 rivo kernel: usb 1-1.4.2: SerialNumber: 413-001 May 07 16:02:17 rivo kernel: usb 1-1.4.2: Unsupported device May 07 16:02:17 rivo kernel: usb 1-1.4.2: Warning! Unlikely big volume range (=32767), cval->res is probably wrong. May 07 16:02:17 rivo kernel: usb 1-1.4.2: [10] FU [PCM Playback Volume] ch = 2, val = -32767/0/1 May 07 16:02:17 rivo kernel: usb 1-1.4.2: Warning! Unlikely big volume range (=32767), cval->res is probably wrong. May 07 16:02:17 rivo kernel: usb 1-1.4.2: [10] FU [PCM Playback Volume] ch = 1, val = -32767/0/1 May 07 16:02:17 rivo volumio[3442]: info: May 07 16:02:17 rivo volumio[3442]: ---------------------------- USB Audio Device Attached May 07 16:02:17 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach May 07 16:02:17 rivo volumio[3442]: No protocol specified May 07 16:02:17 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:02:17 rivo volumio[3442]: info: CoreCommandRouter::Close All Modals sent May 07 16:02:17 rivo volumio[3442]: info: Preparing to save Alsa Options, stopping services first May 07 16:02:17 rivo volumio[3442]: info: CoreCommandRouter::volumioGetState May 07 16:02:17 rivo volumio[3442]: info: CoreCommandRouter::volumioPause May 07 16:02:17 rivo volumio[3442]: info: CoreStateMachine::pause May 07 16:02:17 rivo volumio[3442]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"Qutest","alsacard":"Qutest"},"i2s":false} May 07 16:02:17 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 07 16:02:17 rivo volumio[3442]: No protocol specified May 07 16:02:17 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:02:17 rivo volumio[3442]: No protocol specified May 07 16:02:17 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:02:17 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 07 16:02:17 rivo volumio[3442]: No protocol specified May 07 16:02:17 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:02:17 rivo volumio[3442]: info: Setting mixer PCM for card Qutest May 07 16:02:17 rivo volumio[3442]: info: Reconfiguring and Restarting RAAT Plugin due to audio path changes May 07 16:02:17 rivo vtcs[5196]: [2025-05-07 16:02:17.970] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected May 07 16:02:17 rivo vtcs[5196]: [2025-05-07 16:02:17.970] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE May 07 16:02:18 rivo sudo[5301]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 07 16:02:18 rivo sudo[5301]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:18 rivo systemd[1]: Stopping Volumio Tidal Connect Service... May 07 16:02:18 rivo systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM May 07 16:02:18 rivo systemd[1]: vtcs.service: Succeeded. May 07 16:02:18 rivo systemd[1]: Stopped Volumio Tidal Connect Service. May 07 16:02:18 rivo volumio[3442]: No protocol specified May 07 16:02:18 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:02:18 rivo sudo[5301]: pam_unix(sudo:session): session closed for user root May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 07 16:02:18 rivo volumio[3442]: info: Updating Volume Controller Parameters: Device: 5 Name: Qutest Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 07 16:02:18 rivo volumio[3442]: info: Disabling external Volume Control May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::getUIConfigOnPlugin May 07 16:02:18 rivo volumio[3442]: info: Preparing to generate the ALSA configuration file May 07 16:02:18 rivo volumio[3442]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 07 16:02:18 rivo volumio[3442]: info: Reading ALSA contributions from plugins. May 07 16:02:18 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: running May 07 16:02:18 rivo sudo[5308]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 07 16:02:18 rivo sudo[5308]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:18 rivo volumio[3442]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 07 16:02:18 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:02:18 rivo sudo[5308]: pam_unix(sudo:session): session closed for user root May 07 16:02:18 rivo volumio[3442]: No protocol specified May 07 16:02:18 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 07 16:02:18 rivo volumio[3442]: No protocol specified May 07 16:02:18 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection May 07 16:02:18 rivo volumio[3442]: info: VolumeController:: Volume=undefined Mute =false May 07 16:02:18 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:02:18 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:02:18 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:02:18 rivo volumio[3442]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined May 07 16:02:18 rivo volumio[3442]: info: Updating RAAT Signal Path May 07 16:02:18 rivo volumio[3442]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: Not Reporting Auto name since its the default one May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: Asound.conf file unchanged, so no further update is needed May 07 16:02:18 rivo volumio[3442]: info: Output device has changed, restarting MPD May 07 16:02:18 rivo sudo[5321]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 07 16:02:18 rivo sudo[5321]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:18 rivo volumio[3442]: info: Output device has changed, restarting Shairport Sync May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 07 16:02:18 rivo sudo[5321]: pam_unix(sudo:session): session closed for user root May 07 16:02:18 rivo sudo[5324]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 07 16:02:18 rivo sudo[5324]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:18 rivo systemd[1]: Stopping Music Player Daemon... May 07 16:02:18 rivo volumio[3442]: No protocol specified May 07 16:02:18 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:02:18 rivo volumio[3442]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 07 16:02:18 rivo volumio[3442]: No protocol specified May 07 16:02:18 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:02:18 rivo volumio[3442]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo systemd[1]: mpd.service: Succeeded. May 07 16:02:18 rivo systemd[1]: Stopped Music Player Daemon. May 07 16:02:18 rivo systemd[1]: Starting Music Player Daemon... May 07 16:02:18 rivo sudo[5334]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 07 16:02:18 rivo sudo[5334]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat May 07 16:02:18 rivo sudo[5334]: pam_unix(sudo:session): session closed for user root May 07 16:02:18 rivo sudo[5339]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 07 16:02:18 rivo sudo[5339]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: Not Reporting Auto name since its the default one May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 07 16:02:18 rivo sudo[5339]: pam_unix(sudo:session): session closed for user root May 07 16:02:18 rivo sudo[5333]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 07 16:02:18 rivo sudo[5333]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:18 rivo volumio[3442]: No protocol specified May 07 16:02:18 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:02:18 rivo sudo[5333]: pam_unix(sudo:session): session closed for user root May 07 16:02:18 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: running May 07 16:02:18 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 07 16:02:18 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: running May 07 16:02:18 rivo sudo[5352]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 07 16:02:18 rivo sudo[5352]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:18 rivo volumio[3442]: info: MPD Permissions set May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:18 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:19 rivo sudo[5352]: pam_unix(sudo:session): session closed for user root May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 07 16:02:19 rivo sudo[5356]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 07 16:02:19 rivo sudo[5356]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 07 16:02:19 rivo systemd[1]: Started RAAT DAEMON. May 07 16:02:19 rivo sudo[5356]: pam_unix(sudo:session): session closed for user root May 07 16:02:19 rivo volumio[3442]: No protocol specified May 07 16:02:19 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:02:19 rivo sudo[5380]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 07 16:02:19 rivo sudo[5380]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 07 16:02:19 rivo volumio[3442]: info: Not Reporting Auto name since its the default one May 07 16:02:19 rivo sudo[5380]: pam_unix(sudo:session): session closed for user root May 07 16:02:19 rivo volumio[3442]: info: Raat Daemon started successfully May 07 16:02:19 rivo volumio[3442]: info: Executing endpoint restartRAATSocket May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 07 16:02:19 rivo sudo[5386]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 07 16:02:19 rivo sudo[5386]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:19 rivo volumio[3442]: info: Starting Shairport Sync May 07 16:02:19 rivo systemd[1]: Stopping RAAT DAEMON... May 07 16:02:19 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 07 16:02:19 rivo systemd[1]: raat-daemon.service: Succeeded. May 07 16:02:19 rivo systemd[1]: Stopped RAAT DAEMON. May 07 16:02:19 rivo systemd[1]: Started RAAT DAEMON. May 07 16:02:19 rivo sudo[5386]: pam_unix(sudo:session): session closed for user root May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 07 16:02:19 rivo sudo[5391]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 07 16:02:19 rivo sudo[5391]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:19 rivo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 07 16:02:19 rivo systemd[1]: shairport-sync.service: Succeeded. May 07 16:02:19 rivo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 07 16:02:19 rivo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 07 16:02:19 rivo sudo[5391]: pam_unix(sudo:session): session closed for user root May 07 16:02:19 rivo volumio[3442]: No protocol specified May 07 16:02:19 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:02:19 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: running May 07 16:02:19 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 07 16:02:19 rivo sudo[5407]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service May 07 16:02:19 rivo sudo[5407]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:19 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: running May 07 16:02:19 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 07 16:02:19 rivo volumio[3442]: info: Raat Daemon started successfully May 07 16:02:19 rivo volumio[3442]: info: Shairport-Sync Started May 07 16:02:19 rivo volumio[3442]: info: Executing endpoint restartRAATSocket May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 07 16:02:19 rivo sudo[5407]: pam_unix(sudo:session): session closed for user root May 07 16:02:19 rivo volumio[3442]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 07 16:02:19 rivo sudo[5411]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 07 16:02:19 rivo sudo[5411]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:19 rivo systemd[1]: Stopping RAAT DAEMON... May 07 16:02:19 rivo volumio[3442]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 07 16:02:19 rivo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM May 07 16:02:19 rivo systemd[1]: raat-daemon.service: Succeeded. May 07 16:02:19 rivo systemd[1]: Stopped RAAT DAEMON. May 07 16:02:19 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: running May 07 16:02:19 rivo systemd[1]: Started RAAT DAEMON. May 07 16:02:19 rivo volumio[3442]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 07 16:02:19 rivo sudo[5411]: pam_unix(sudo:session): session closed for user root May 07 16:02:19 rivo volumio[3442]: info: Raat Daemon started successfully May 07 16:02:19 rivo volumio[3442]: info: Executing endpoint restartRAATSocket May 07 16:02:19 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 07 16:02:19 rivo volumio[3442]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 07 16:02:20 rivo mpd[5353]: May 07 16:02 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 07 16:02:21 rivo volumio[3442]: info: TidalConnect service stoped! May 07 16:02:21 rivo systemd[1]: Started Music Player Daemon. May 07 16:02:21 rivo sudo[5324]: pam_unix(sudo:session): session closed for user root May 07 16:02:21 rivo volumio[3442]: error: updateQueue error: null May 07 16:02:21 rivo volumio[3442]: info: TidalConnect service stoped! May 07 16:02:21 rivo volumio[3442]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 07 16:02:21 rivo volumio[3442]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 07 16:02:21 rivo sudo[5439]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 07 16:02:21 rivo sudo[5439]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:21 rivo systemd[1]: Started Volumio Tidal Connect Service. May 07 16:02:21 rivo sudo[5439]: pam_unix(sudo:session): session closed for user root May 07 16:02:21 rivo volumio[3442]: info: Executing endpoint tc_getconfig May 07 16:02:21 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 07 16:02:21 rivo vtcs[5441]: STARTING TidalConnect services, version: 1.4.0.34 May 07 16:02:21 rivo volumio[3442]: info: TidalConnect service stoped! May 07 16:02:21 rivo vtcs[5441]: STARTED TidalConnect services. May 07 16:02:21 rivo volumio[3442]: info: Executing endpoint tc_connect May 07 16:02:21 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 07 16:02:21 rivo volumio[3442]: info: Connecting to TidalConnect May 07 16:02:21 rivo volumio[3442]: info: CoreCommandRouter::servicePushState May 07 16:02:21 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:02:21 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:02:21 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:02:21 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:02:21 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:02:21 rivo volumio[3442]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect May 07 16:02:21 rivo volumio[3442]: info: CoreCommandRouter::servicePushState May 07 16:02:21 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:02:21 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:02:21 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:02:21 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:02:21 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:02:21 rivo volumio[3442]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect May 07 16:02:21 rivo volumio[3442]: info: Updating RAAT Signal Path May 07 16:02:21 rivo volumio[3442]: info: Updating RAAT Signal Path May 07 16:02:21 rivo volumio[3442]: info: TidalConnect service stoped! May 07 16:02:21 rivo volumio[3442]: info: RAAT: Requesting Headphone Status May 07 16:02:21 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 07 16:02:22 rivo volumio[3442]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 07 16:02:22 rivo volumio[3442]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect May 07 16:02:22 rivo volumio[3442]: info: MCU Signalled Headphone Mode Disabled May 07 16:02:22 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 07 16:02:22 rivo volumio[3442]: info: Reporting Headphone State: false May 07 16:02:22 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:22 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:22 rivo volumio[3442]: info: Updating RAAT Signal Path May 07 16:02:22 rivo sudo[5469]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 07 16:02:22 rivo sudo[5469]: pam_unix(sudo:session): session opened for user root by (uid=0) May 07 16:02:22 rivo sudo[5469]: pam_unix(sudo:session): session closed for user root May 07 16:02:22 rivo volumio[3442]: info: CoreCommandRouter::volumioRetrieveVolumeLevels May 07 16:02:22 rivo volumio[3442]: info: CoreStateMachine::getcurrentVolume May 07 16:02:22 rivo volumio[3442]: info: CoreCommandRouter::volumioRetrievevolume May 07 16:02:22 rivo volumio[3442]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: No protocol specified May 07 16:02:22 rivo volumio[3442]: xcb_connection_has_error() returned true May 07 16:02:22 rivo volumio[3442]: info: VolumeController:: Volume=undefined Mute =false May 07 16:02:22 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:02:22 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:02:22 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:02:22 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:02:22 rivo volumio[3442]: info: CoreStateMachine::updateTrackBlock May 07 16:02:22 rivo volumio[3442]: info: CorePlayQueue::getTrackBlock May 07 16:02:22 rivo volumio[3442]: info: CoreCommandRouter::volumioRetrievevolume May 07 16:02:22 rivo volumio[3442]: info: RAAT: Requesting Headphone Status May 07 16:02:22 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 07 16:02:22 rivo volumio[3442]: info: Updating RAAT Signal Path May 07 16:02:22 rivo volumio[3442]: info: MCU Signalled Headphone Mode Disabled May 07 16:02:22 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 07 16:02:22 rivo volumio[3442]: info: Reporting Headphone State: false May 07 16:02:22 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:22 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:22 rivo volumio[3442]: info: Updating RAAT Signal Path May 07 16:02:22 rivo volumio[3442]: info: VolumeController:: Volume=40 Mute =false May 07 16:02:22 rivo volumio[3442]: info: CoreStateMachine::pushState May 07 16:02:22 rivo volumio[3442]: info: CoreCommandRouter::volumioPushState May 07 16:02:22 rivo volumio[3442]: info: MRS: Pushing multiroomSync output update for this device May 07 16:02:22 rivo volumio[3442]: info: MRS: Pushing multiroomSync output May 07 16:02:22 rivo volumio[3442]: info: Updating RAAT Signal Path May 07 16:02:22 rivo volumio[3442]: info: RAAT: Requesting Headphone Status May 07 16:02:22 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus May 07 16:02:22 rivo volumio[3442]: info: MCU Signalled Headphone Mode Disabled May 07 16:02:22 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState May 07 16:02:22 rivo volumio[3442]: info: Reporting Headphone State: false May 07 16:02:22 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:22 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 07 16:02:22 rivo volumio[3442]: info: Updating RAAT Signal Path May 07 16:02:24 rivo volumio[3442]: info: TidalConnect service started! May 07 16:02:25 rivo volumio[3442]: info: TidalConnect service started! May 07 16:02:31 rivo volumio[3442]: info: CoreCommandRouter::volumioPlay May 07 16:02:31 rivo volumio[3442]: info: CoreStateMachine::play index undefined May 07 16:02:31 rivo volumio[3442]: info: CoreStateMachine::setConsumeUpdateService undefined May 07 16:02:31 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:02:31 rivo volumio[3442]: info: CoreStateMachine::startPlaybackTimer May 07 16:02:31 rivo volumio[3442]: info: CorePlayQueue::getTrack 0 May 07 16:02:31 rivo volumio[3442]: info: [1746626551440] ControllerQobuz::resume May 07 16:02:31 rivo volumio[3442]: info: CoreStateMachine::setConsumeUpdateService mpd May 07 16:02:31 rivo volumio[3442]: info: ControllerMpd::resume May 07 16:02:31 rivo volumio[3442]: verbose: ControllerMpd::sendMpdCommand play May 07 16:02:31 rivo volumio[3442]: info: sendMpdCommand play took 2 milliseconds May 07 16:02:38 rivo volumio[3442]: info: Executing endpoint metavolumio May 07 16:02:38 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 07 16:02:38 rivo volumio[3442]: info: Executing endpoint metavolumio May 07 16:02:38 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 07 16:02:42 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 07 16:02:42 rivo volumio[3442]: info: Preload queue cleared May 07 16:02:43 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 07 16:02:43 rivo volumio[3442]: info: Preload queue cleared May 07 16:02:44 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 07 16:02:45 rivo volumio[3442]: info: Preload queue cleared May 07 16:02:45 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 07 16:02:48 rivo volumio[3442]: info: Preload queue cleared May 07 16:02:49 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 07 16:02:49 rivo volumio[3442]: info: Preload queue cleared May 07 16:02:50 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 07 16:02:51 rivo volumio[3442]: info: Preload queue cleared May 07 16:02:51 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 07 16:02:51 rivo volumio[3442]: info: Preload queue cleared May 07 16:02:52 rivo volumio[3442]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 07 16:02:52 rivo volumio[3442]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 07 16:02:52 rivo volumio[3442]: TypeError: Cannot read property 'length' of undefined May 07 16:02:52 rivo volumio[3442]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 May 07 16:02:52 rivo volumio[3442]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 May 07 16:02:52 rivo volumio[3442]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) May 07 16:02:52 rivo volumio[3442]: at Parser.emit (events.js:400:28) May 07 16:02:52 rivo volumio[3442]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) May 07 16:02:52 rivo volumio[3442]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) May 07 16:02:52 rivo volumio[3442]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) May 07 16:02:52 rivo volumio[3442]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) May 07 16:02:52 rivo volumio[3442]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) May 07 16:02:52 rivo volumio[3442]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) May 07 16:02:52 rivo volumio[3442]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) May 07 16:02:52 rivo volumio[3442]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) May 07 16:02:52 rivo volumio[3442]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) May 07 16:02:52 rivo volumio[3442]: at IncomingMessage.emit (events.js:412:35) May 07 16:02:52 rivo volumio[3442]: at endReadableNT (internal/streams/readable.js:1333:12) May 07 16:02:52 rivo volumio[3442]: at processTicksAndRejections (internal/process/task_queues.js:82:21) May 07 16:02:52 rivo volumio[3442]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 07 16:02:53 rivo sudo[5546]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-07 16:01 May 07 16:02:53 rivo sudo[5546]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 10:40:21 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="257abb5a10f96d014c189cf43ed95c4d"