-- 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"