-- Logs begin at Fri 2026-04-10 21:48:51 HKT, end at Fri 2026-04-10 21:55:59 HKT. --
Apr 10 21:54:00 rivo volumio[3129]: info: Executing endpoint metavolumio
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 10 21:54:00 rivo volumio[3129]: STREAMING PROXY: Upstream status code: 200
Apr 10 21:54:00 rivo volumio[3129]: info:
Apr 10 21:54:00 rivo volumio[3129]: ---------------------------- MPD announces state update: player
Apr 10 21:54:00 rivo volumio[3129]: info: ControllerMpd::getState
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::sendMpdCommand status
Apr 10 21:54:00 rivo kernel: aml_spdif_open
Apr 10 21:54:00 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0
Apr 10 21:54:00 rivo kernel: set normal 512 fs /4 fs
Apr 10 21:54:00 rivo kernel: set spdifout clk:5644800, mpll:22579200
Apr 10 21:54:00 rivo kernel: get spdifout clk:5644797, mpll:22579186
Apr 10 21:54:00 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000
Apr 10 21:54:00 rivo kernel: set normal 512 fs /4 fs
Apr 10 21:54:00 rivo kernel: set spdifout clk:5644800, mpll:22579200
Apr 10 21:54:00 rivo kernel: get spdifout clk:5644797, mpll:22579186
Apr 10 21:54:00 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0
Apr 10 21:54:00 rivo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1
Apr 10 21:54:00 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0
Apr 10 21:54:00 rivo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1
Apr 10 21:54:00 rivo volumio[3129]: info:
Apr 10 21:54:00 rivo volumio[3129]: ---------------------------- MPD announces state update: player
Apr 10 21:54:00 rivo volumio[3129]: info: ControllerMpd::getState
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::sendMpdCommand status
Apr 10 21:54:00 rivo volumio[3129]: info:
Apr 10 21:54:00 rivo volumio[3129]: ---------------------------- MPD announces state update: player
Apr 10 21:54:00 rivo volumio[3129]: info: ControllerMpd::getState
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::sendMpdCommand status
Apr 10 21:54:00 rivo volumio[3129]: info:
Apr 10 21:54:00 rivo volumio[3129]: ---------------------------- MPD announces state update: player
Apr 10 21:54:00 rivo volumio[3129]: info: sendMpdCommand status took 12 milliseconds
Apr 10 21:54:00 rivo volumio[3129]: info: ControllerMpd::getState
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::sendMpdCommand status
Apr 10 21:54:00 rivo volumio[3129]: info: sendMpdCommand status took 11 milliseconds
Apr 10 21:54:00 rivo volumio[3129]: info: sendMpdCommand status took 10 milliseconds
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::parseState
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::parseState
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::parseState
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 10 21:54:00 rivo volumio[3129]: info: sendMpdCommand status took 10 milliseconds
Apr 10 21:54:00 rivo volumio[3129]: info: sendMpdCommand playlistinfo took 9 milliseconds
Apr 10 21:54:00 rivo volumio[3129]: info: sendMpdCommand playlistinfo took 7 milliseconds
Apr 10 21:54:00 rivo volumio[3129]: info: sendMpdCommand playlistinfo took 7 milliseconds
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::parseState
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::parseTrackInfo
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::parseTrackInfo
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::parseTrackInfo
Apr 10 21:54:00 rivo volumio[3129]: info: ControllerMpd::pushState
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Apr 10 21:54:00 rivo volumio[3129]: info: CorePlayQueue::getTrack 0
Apr 10 21:54:00 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":251,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"492889882&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/492889882&soundQuality=LOSSLESS","trackType":"tidal"}
Apr 10 21:54:00 rivo volumio[3129]: verbose: CURRENT POSITION 0
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus stop
Apr 10 21:54:00 rivo volumio[3129]: info: ControllerMpd::pushState
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Apr 10 21:54:00 rivo volumio[3129]: info: CorePlayQueue::getTrack 0
Apr 10 21:54:00 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":251,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"492889882&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/492889882&soundQuality=LOSSLESS","trackType":"tidal"}
Apr 10 21:54:00 rivo volumio[3129]: verbose: CURRENT POSITION 0
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Apr 10 21:54:00 rivo volumio[3129]: info: Received an update from plugin. extracting info from payload
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::pushState
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output update for this device
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::pushState
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output update for this device
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output
Apr 10 21:54:00 rivo volumio[3129]: info: ControllerMpd::pushState
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Apr 10 21:54:00 rivo volumio[3129]: info: CorePlayQueue::getTrack 0
Apr 10 21:54:00 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":251,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"492889882&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/492889882&soundQuality=LOSSLESS","trackType":"tidal"}
Apr 10 21:54:00 rivo volumio[3129]: verbose: CURRENT POSITION 0
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Apr 10 21:54:00 rivo volumio[3129]: info: Received an update from plugin. extracting info from payload
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::pushState
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output update for this device
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::pushState
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output update for this device
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output
Apr 10 21:54:00 rivo volumio[3129]: info: ------------------------------ 66ms
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.223+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" state=STATUS_PLAYING positionMs=0 volume=100
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.224+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" id=tidal://song/492889882 title=Magic
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.225+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" state=STATUS_PLAYING positionMs=0 volume=100
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.225+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" id=tidal://song/492889882 title=Magic
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.226+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" state=STATUS_PLAYING positionMs=0 volume=100
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.226+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" id=tidal://song/492889882 title=Magic
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.227+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" state=STATUS_PLAYING positionMs=0 volume=100
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.228+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" id=tidal://song/492889882 title=Magic
Apr 10 21:54:00 rivo volumio[3129]: info: ------------------------------ 88ms
Apr 10 21:54:00 rivo volumio[3129]: info: ------------------------------ 87ms
Apr 10 21:54:00 rivo volumio[3129]: info:
Apr 10 21:54:00 rivo volumio[3129]: ---------------------------- MPD announces state update: player
Apr 10 21:54:00 rivo volumio[3129]: info: ControllerMpd::getState
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::sendMpdCommand status
Apr 10 21:54:00 rivo volumio[3129]: info:
Apr 10 21:54:00 rivo volumio[3129]: ---------------------------- MPD announces state update: player
Apr 10 21:54:00 rivo volumio[3129]: info: ControllerMpd::getState
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::sendMpdCommand status
Apr 10 21:54:00 rivo volumio[3129]: info: sendMpdCommand playlistinfo took 71 milliseconds
Apr 10 21:54:00 rivo volumio[3129]: info: sendMpdCommand status took 5 milliseconds
Apr 10 21:54:00 rivo volumio[3129]: info: sendMpdCommand status took 3 milliseconds
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::parseTrackInfo
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::parseState
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::parseState
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Apr 10 21:54:00 rivo volumio[3129]: info: ControllerMpd::pushState
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Apr 10 21:54:00 rivo volumio[3129]: info: CorePlayQueue::getTrack 0
Apr 10 21:54:00 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":251,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"492889882&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/492889882&soundQuality=LOSSLESS","trackType":"tidal"}
Apr 10 21:54:00 rivo volumio[3129]: verbose: CURRENT POSITION 0
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Apr 10 21:54:00 rivo volumio[3129]: info: Received an update from plugin. extracting info from payload
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::pushState
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output update for this device
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::pushState
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output update for this device
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.276+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" state=STATUS_PLAYING positionMs=270 volume=100
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.277+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" id=tidal://song/492889882 title=Magic
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.278+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" state=STATUS_PLAYING positionMs=270 volume=100
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.279+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" id=tidal://song/492889882 title=Magic
Apr 10 21:54:00 rivo volumio[3129]: info: ------------------------------ 124ms
Apr 10 21:54:00 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable
Apr 10 21:54:00 rivo volumio[3129]: info: Signalling Playback active due to playback status change
Apr 10 21:54:00 rivo volumio[3129]: info: sendMpdCommand playlistinfo took 74 milliseconds
Apr 10 21:54:00 rivo volumio[3129]: info: sendMpdCommand playlistinfo took 74 milliseconds
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::parseTrackInfo
Apr 10 21:54:00 rivo volumio[3129]: verbose: ControllerMpd::parseTrackInfo
Apr 10 21:54:00 rivo volumio[3129]: info: ControllerMpd::pushState
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Apr 10 21:54:00 rivo volumio[3129]: info: CorePlayQueue::getTrack 0
Apr 10 21:54:00 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1349,"duration":251,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"513 Kbps","isStreaming":false,"title":"492889882&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/492889882&soundQuality=LOSSLESS","trackType":"tidal"}
Apr 10 21:54:00 rivo volumio[3129]: verbose: CURRENT POSITION 0
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Apr 10 21:54:00 rivo volumio[3129]: info: Received an update from plugin. extracting info from payload
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::pushState
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output update for this device
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::pushState
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output update for this device
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output
Apr 10 21:54:00 rivo volumio[3129]: info: ControllerMpd::pushState
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::servicePushState
Apr 10 21:54:00 rivo volumio[3129]: info: CorePlayQueue::getTrack 0
Apr 10 21:54:00 rivo volumio[3129]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1349,"duration":251,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"513 Kbps","isStreaming":false,"title":"492889882&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/492889882&soundQuality=LOSSLESS","trackType":"tidal"}
Apr 10 21:54:00 rivo volumio[3129]: verbose: CURRENT POSITION 0
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::syncState stateService play
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::syncState currentStatus play
Apr 10 21:54:00 rivo volumio[3129]: info: Received an update from plugin. extracting info from payload
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::pushState
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output update for this device
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output
Apr 10 21:54:00 rivo volumio[3129]: info: CoreStateMachine::pushState
Apr 10 21:54:00 rivo volumio[3129]: info: CoreCommandRouter::volumioPushState
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output update for this device
Apr 10 21:54:00 rivo volumio[3129]: info: MRS: Pushing multiroomSync output
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.360+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" state=STATUS_PLAYING positionMs=270 volume=100
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.360+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" id=tidal://song/492889882 title=Magic
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.362+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" state=STATUS_PLAYING positionMs=270 volume=100
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.362+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" state=STATUS_PLAYING positionMs=270 volume=100
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.362+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" id=tidal://song/492889882 title=Magic
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.363+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" id=tidal://song/492889882 title=Magic
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.363+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" state=STATUS_PLAYING positionMs=270 volume=100
Apr 10 21:54:00 rivo volumio5-onboarding[3897]: time=2026-04-10T21:54:00.364+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.2:60952,00:00:00:00:00:00%03 @ 0x1acd050" id=tidal://song/492889882 title=Magic
Apr 10 21:54:00 rivo volumio[3129]: info: ------------------------------ 132ms
Apr 10 21:54:00 rivo volumio[3129]: info: ------------------------------ 131ms
Apr 10 21:54:00 rivo volumio[3129]: info: MCU Signalled Playback Active
Apr 10 21:54:02 rivo volumio[3129]: info: Executing endpoint metavolumio
Apr 10 21:54:02 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 10 21:54:02 rivo volumio[3129]: info: Executing endpoint metavolumio
Apr 10 21:54:02 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 10 21:54:02 rivo volumio[3129]: info: Executing endpoint metavolumio
Apr 10 21:54:02 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 10 21:54:02 rivo volumio[3129]: info: Executing endpoint metavolumio
Apr 10 21:54:02 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 10 21:54:02 rivo volumio[3129]: info: Executing endpoint metavolumio
Apr 10 21:54:02 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 10 21:54:02 rivo volumio[3129]: info: Executing endpoint metavolumio
Apr 10 21:54:02 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Apr 10 21:54:15 rivo volumio[3129]: STREAMING PROXY: Upstream closed. Received 30447908 bytes
Apr 10 21:54:15 rivo volumio[3129]: STREAMING PROXY: Client closed connection
Apr 10 21:54:35 rivo volumio[3129]: verbose: New Socket.io Connection to 192.168.1.3 from 192.168.1.2 UA: Mozilla/5.0 (Linux; Android 16; PKH110 Build/AP3A.240617.008; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.177 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7
Apr 10 21:54:35 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Apr 10 21:54:35 rivo volumio[3129]: info: CoreCommandRouter::volumioGetVisibleSources
Apr 10 21:54:35 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 10 21:54:35 rivo volumio[3129]: info: CoreCommandRouter::volumioGetState
Apr 10 21:54:36 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Apr 10 21:54:36 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Apr 10 21:54:36 rivo volumio[3129]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom
Apr 10 21:54:36 rivo volumio[3129]: info: Received Get System Info
Apr 10 21:54:36 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 10 21:54:36 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 10 21:54:36 rivo volumio[3129]: info: Discovery: Getting this device information
Apr 10 21:54:36 rivo volumio[3129]: info: CoreCommandRouter::volumioGetState
Apr 10 21:54:36 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 10 21:54:36 rivo volumio[3129]: info: CoreCommandRouter::volumioGetState
Apr 10 21:54:36 rivo volumio[3129]: info: Listing playlists
Apr 10 21:54:36 rivo volumio[3129]: info: CoreCommandRouter::volumioGetQueue
Apr 10 21:54:36 rivo volumio[3129]: info: CoreStateMachine::getQueue
Apr 10 21:54:36 rivo volumio[3129]: info: CorePlayQueue::getQueue
Apr 10 21:54:36 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Apr 10 21:55:13 rivo volumio[3129]: verbose: New Socket.io Connection to 192.168.1.3 from 192.168.1.2 UA: Mozilla/5.0 (Linux; Android 16; PKH110 Build/AP3A.240617.008; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.177 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7
Apr 10 21:55:13 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Apr 10 21:55:13 rivo volumio[3129]: info: CoreCommandRouter::volumioGetVisibleSources
Apr 10 21:55:13 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 10 21:55:13 rivo volumio[3129]: info: CoreCommandRouter::volumioGetState
Apr 10 21:55:13 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Apr 10 21:55:13 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Apr 10 21:55:13 rivo volumio[3129]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom
Apr 10 21:55:13 rivo volumio[3129]: info: Received Get System Info
Apr 10 21:55:13 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 10 21:55:13 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 10 21:55:13 rivo volumio[3129]: info: Discovery: Getting this device information
Apr 10 21:55:13 rivo volumio[3129]: info: CoreCommandRouter::volumioGetState
Apr 10 21:55:13 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 10 21:55:13 rivo volumio[3129]: info: CoreCommandRouter::volumioGetState
Apr 10 21:55:13 rivo volumio[3129]: info: Listing playlists
Apr 10 21:55:13 rivo volumio[3129]: info: CoreCommandRouter::volumioGetQueue
Apr 10 21:55:13 rivo volumio[3129]: info: CoreStateMachine::getQueue
Apr 10 21:55:13 rivo volumio[3129]: info: CorePlayQueue::getQueue
Apr 10 21:55:13 rivo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Apr 10 21:55:58 rivo volumio[3129]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 10 21:55:58 rivo volumio[3129]: Error: connect ETIMEDOUT 158.69.210.98:443
Apr 10 21:55:58 rivo volumio[3129]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) {
Apr 10 21:55:58 rivo volumio[3129]: errno: -110,
Apr 10 21:55:58 rivo volumio[3129]: code: 'ETIMEDOUT',
Apr 10 21:55:58 rivo volumio[3129]: syscall: 'connect',
Apr 10 21:55:58 rivo volumio[3129]: address: '158.69.210.98',
Apr 10 21:55:58 rivo volumio[3129]: port: 443
Apr 10 21:55:58 rivo volumio[3129]: }
Apr 10 21:55:58 rivo volumio[3129]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 10 21:55:59 rivo sudo[5477]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-04-10 21:54
Apr 10 21:55:59 rivo sudo[5477]: 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="e9612ec5034fb2e958508aaefbca2962fd6f6654"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec"
VOLUMIO_ARCH="armv7"
VOLUMIO_VARIANT="rivo"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 11:38:48 AM CET"
VOLUMIO_VERSION="3.912"
VOLUMIO_HARDWARE="mp1"
VOLUMIO_DEVICENAME="Volumio MP1"
VOLUMIO_VENDOR_MODEL="Volumio Rivo"
VOLUMIO_VENDOR="Volumio"
VOLUMIO_MODEL="Rivo"
VOLUMIO_HASH="8e381701610c2a79deb52e712150c089"