Oct 13 10:54:06 rivo go-librespot[4134]: time="2026-10-13T10:54:06+02:00" level=debug msg="fetched chunk 12/17, size: 524288" uri="spotify:track:1oAs44xVvu4QaZpX9033S5" Oct 13 10:54:20 rivo go-librespot[4134]: time="2026-10-13T10:54:20+02:00" level=debug msg="fetched chunk 13/17, size: 524288" uri="spotify:track:1oAs44xVvu4QaZpX9033S5" Oct 13 10:54:27 rivo volumio[3456]: Searching all installed plugins Oct 13 10:54:27 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 10:54:27 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: , search Oct 13 10:54:27 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 13 10:54:27 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 13 10:54:27 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 13 10:54:27 rivo volumio[3456]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 13 10:54:27 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 13 10:54:27 rivo volumio[3456]: info: All search sources collected, pushing search results Oct 13 10:54:29 rivo volumio[3456]: Searching all installed plugins Oct 13 10:54:29 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 10:54:29 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: , search Oct 13 10:54:29 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 13 10:54:29 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 13 10:54:29 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 13 10:54:29 rivo volumio[3456]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 13 10:54:29 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 13 10:54:29 rivo volumio[3456]: info: All search sources collected, pushing search results Oct 13 10:54:31 rivo volumio[3456]: Searching all installed plugins Oct 13 10:54:31 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 10:54:31 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: , search Oct 13 10:54:31 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 13 10:54:31 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 13 10:54:31 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 13 10:54:31 rivo volumio[3456]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 13 10:54:31 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 13 10:54:31 rivo volumio[3456]: info: All search sources collected, pushing search results Oct 13 10:54:33 rivo go-librespot[4134]: time="2026-10-13T10:54:33+02:00" level=debug msg="fetched chunk 14/17, size: 524288" uri="spotify:track:1oAs44xVvu4QaZpX9033S5" Oct 13 10:54:39 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 10:54:39 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 13 10:54:46 rivo go-librespot[4134]: time="2026-10-13T10:54:46+02:00" level=debug msg="fetched chunk 15/17, size: 524288" uri="spotify:track:1oAs44xVvu4QaZpX9033S5" Oct 13 10:54:48 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 13 10:54:48 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 13 10:54:59 rivo go-librespot[4134]: time="2026-10-13T10:54:59+02:00" level=debug msg="fetched chunk 16/17, size: 524288" uri="spotify:track:1oAs44xVvu4QaZpX9033S5" Oct 13 10:55:11 rivo go-librespot[4134]: time="2026-10-13T10:55:11+02:00" level=debug msg="fetched chunk 17/17, size: 257944" uri="spotify:track:1oAs44xVvu4QaZpX9033S5" Oct 13 10:55:13 rivo volumio[3456]: info: Preload queue cleared Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::ClearQueue Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::stop Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::serviceStop Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::serviceStop Oct 13 10:55:13 rivo volumio[3456]: info: Spotify Stop Oct 13 10:55:13 rivo volumio[3456]: SPOTIFY: SPOTIFY STOP Oct 13 10:55:13 rivo volumio[3456]: SPOTIFY: {"status":"play","title":"I Only Want To Be With You","artist":"Shelby Lynne","album":"Just A Little Lovin'","albumart":"https://i.scdn.co/image/ab67616d00001e020b89978c9a35191ee57977f2","uri":"spotify:track:1oAs44xVvu4QaZpX9033S5","trackType":"spotify","codec":"ogg","seek":0,"duration":230,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":true,"stream":false,"volatile":true,"service":"spop"} Oct 13 10:55:13 rivo volumio[3456]: info: Sending Spotify command to local API: /player/pause Oct 13 10:55:13 rivo volumio[3456]: info: CorePlayQueue::clearPlayQueue Oct 13 10:55:13 rivo volumio[3456]: info: CorePlayQueue::saveQueue Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::addQueueItems Oct 13 10:55:13 rivo volumio[3456]: info: CorePlayQueue::addQueueItems Oct 13 10:55:13 rivo volumio[3456]: info: Preload queue cleared Oct 13 10:55:13 rivo volumio[3456]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s312325 Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 13 10:55:13 rivo go-librespot[4134]: time="2026-10-13T10:55:13+02:00" level=debug msg="pause track at 184871ms" Oct 13 10:55:13 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback disable Oct 13 10:55:13 rivo kernel: spdif_a keep clk continuous Oct 13 10:55:13 rivo kernel: aml_spdif_close Oct 13 10:55:13 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Oct 13 10:55:13 rivo go-librespot[4134]: time="2026-10-13T10:55:13+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 10:55:13 rivo go-librespot[4134]: time="2026-10-13T10:55:13+02:00" level=trace msg="emitting websocket event: paused" Oct 13 10:55:13 rivo volumio[3456]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:playlist:1ArE7ywoVF4RMBvTXU9jNJ","uri":"spotify:track:1oAs44xVvu4QaZpX9033S5","play_origin":"playlist"}} Oct 13 10:55:13 rivo volumio[3456]: SPOTIFY: PUSH STATE SPOTIFY Oct 13 10:55:13 rivo volumio[3456]: SPOTIFY: {"status":"pause","service":"spop","title":"I Only Want To Be With You","artist":"Shelby Lynne","album":"Just A Little Lovin'","albumart":"https://i.scdn.co/image/ab67616d00001e020b89978c9a35191ee57977f2","uri":"spotify:track:1oAs44xVvu4QaZpX9033S5","trackType":"spotify","seek":185000,"duration":230,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:13 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:13 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:13 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:13.231+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PAUSED positionMs=185000 volume=100 Oct 13 10:55:13 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:13.232+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id=spotify:track:1oAs44xVvu4QaZpX9033S5 title="I Only Want To Be With You" Oct 13 10:55:13 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::volumioPushQueue Oct 13 10:55:13 rivo volumio[3456]: info: CorePlayQueue::saveQueue Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::updateTrackBlock Oct 13 10:55:13 rivo volumio[3456]: info: CorePlayQueue::getTrackBlock Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::volumioPlay Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::play index 0 Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:55:13 rivo go-librespot[4134]: time="2026-10-13T10:55:13+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::stop Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::updateTrackBlock Oct 13 10:55:13 rivo volumio[3456]: info: CorePlayQueue::getTrackBlock Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::stPlaybackTimer Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:13 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:13 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:13 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:13 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::serviceStop Oct 13 10:55:13 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::serviceStop Oct 13 10:55:13 rivo volumio[3456]: info: [1791881713357] ControllerWebradio::stop Oct 13 10:55:13 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:55:13 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:13.362+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 13 10:55:13 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:13.363+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=Youtube Oct 13 10:55:13 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:13 rivo volumio[3456]: info: sendMpdCommand stop took 42 milliseconds Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::play index undefined Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:55:13 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:13 rivo volumio[3456]: info: CoreStateMachine::startPlaybackTimer Oct 13 10:55:13 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::volumioGetVisibleSources Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 13 10:55:13 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 13 10:55:13 rivo volumio[3456]: info: [1791881713410] ControllerWebradio::clearAddPlayTrack Oct 13 10:55:13 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:55:13 rivo volumio[3456]: info: sendMpdCommand stop took 2 milliseconds Oct 13 10:55:13 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand clear Oct 13 10:55:13 rivo volumio[3456]: info: Oct 13 10:55:13 rivo volumio[3456]: ---------------------------- MPD announces system playlist update Oct 13 10:55:13 rivo volumio[3456]: info: Ignoring MPD Status Update Oct 13 10:55:13 rivo volumio[3456]: info: sendMpdCommand clear took 8 milliseconds Oct 13 10:55:13 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand load "https://youtube.stream.laut.fm/youtube?ref=radiodns" Oct 13 10:55:13 rivo volumio[3456]: info: Oct 13 10:55:13 rivo volumio[3456]: ---------------------------- MPD announces system playlist update Oct 13 10:55:13 rivo volumio[3456]: info: Ignoring MPD Status Update Oct 13 10:55:13 rivo volumio[3456]: info: Oct 13 10:55:13 rivo volumio[3456]: ---------------------------- MPD announces system playlist update Oct 13 10:55:13 rivo volumio[3456]: info: Ignoring MPD Status Update Oct 13 10:55:13 rivo volumio[3456]: error: updateQueue error: null Oct 13 10:55:13 rivo volumio[3456]: info: ------------------------------ 12ms Oct 13 10:55:14 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand add "https://youtube.stream.laut.fm/youtube?ref=radiodns" Oct 13 10:55:14 rivo volumio[3456]: error: updateQueue error: null Oct 13 10:55:14 rivo volumio[3456]: error: updateQueue error: null Oct 13 10:55:14 rivo volumio[3456]: info: ------------------------------ 868ms Oct 13 10:55:14 rivo volumio[3456]: info: ------------------------------ 867ms Oct 13 10:55:14 rivo volumio[3456]: info: Oct 13 10:55:14 rivo volumio[3456]: ---------------------------- MPD announces system playlist update Oct 13 10:55:14 rivo volumio[3456]: info: Ignoring MPD Status Update Oct 13 10:55:14 rivo volumio[3456]: info: sendMpdCommand add "https://youtube.stream.laut.fm/youtube?ref=radiodns" took 4 milliseconds Oct 13 10:55:14 rivo volumio[3456]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 13 10:55:14 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand play Oct 13 10:55:14 rivo volumio[3456]: info: ------------------------------ 6ms Oct 13 10:55:14 rivo volumio[3456]: info: Oct 13 10:55:14 rivo volumio[3456]: ---------------------------- MPD announces system playlist update Oct 13 10:55:14 rivo volumio[3456]: info: Ignoring MPD Status Update Oct 13 10:55:14 rivo volumio[3456]: info: Oct 13 10:55:14 rivo volumio[3456]: ---------------------------- MPD announces system playlist update Oct 13 10:55:14 rivo volumio[3456]: info: Ignoring MPD Status Update Oct 13 10:55:14 rivo volumio[3456]: info: sendMpdCommand play took 15 milliseconds Oct 13 10:55:14 rivo volumio[3456]: info: ------------------------------ 9ms Oct 13 10:55:14 rivo volumio[3456]: info: ------------------------------ 9ms Oct 13 10:55:15 rivo volumio[3456]: info: Oct 13 10:55:15 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:15 rivo volumio[3456]: info: Oct 13 10:55:15 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:15 rivo volumio[3456]: info: Oct 13 10:55:15 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:15 rivo kernel: aml_spdif_open Oct 13 10:55:15 rivo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Oct 13 10:55:15 rivo kernel: set normal 512 fs /4 fs Oct 13 10:55:15 rivo kernel: set spdifout clk:5644800, mpll:22579200 Oct 13 10:55:15 rivo kernel: get spdifout clk:5644797, mpll:22579186 Oct 13 10:55:15 rivo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Oct 13 10:55:15 rivo kernel: set normal 512 fs /4 fs Oct 13 10:55:15 rivo kernel: set spdifout clk:5644800, mpll:22579200 Oct 13 10:55:15 rivo kernel: get spdifout clk:5644797, mpll:22579186 Oct 13 10:55:15 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Oct 13 10:55:15 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Oct 13 10:55:15 rivo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Oct 13 10:55:15 rivo kernel: aml_spdif_fifo_ctrl, bit depth:24, frddr type:4, toddr:type:4 Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand status took 25 milliseconds Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:15 rivo volumio[3456]: info: Oct 13 10:55:15 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:15 rivo volumio[3456]: info: Oct 13 10:55:15 rivo volumio[3456]: ---------------------------- MPD announces system playlist update Oct 13 10:55:15 rivo volumio[3456]: info: Ignoring MPD Status Update Oct 13 10:55:15 rivo volumio[3456]: info: Oct 13 10:55:15 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand status took 30 milliseconds Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand status took 29 milliseconds Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:15 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:15 rivo volumio[3456]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"lautfm","artist":"Verbraucherinformationen","album":"\"laut_transcoder__v0.1.0__2026-10-12_09:03:06","uri":"https://youtube.stream.laut.fm/youtube?ref=radiodns","trackType":""} Oct 13 10:55:15 rivo volumio[3456]: verbose: CURRENT POSITION 0 Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState stateService play Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState currentStatus stop Oct 13 10:55:15 rivo volumio[3456]: info: ------------------------------ 44ms Oct 13 10:55:15 rivo volumio[3456]: info: Oct 13 10:55:15 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:15 rivo volumio[3456]: info: Oct 13 10:55:15 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand status took 20 milliseconds Oct 13 10:55:15 rivo volumio[3456]: info: ------------------------------ 23ms Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand status took 20 milliseconds Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 18 milliseconds Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 18 milliseconds Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand status took 9 milliseconds Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:15 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:15 rivo volumio[3456]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"lautfm","artist":"Verbraucherinformationen","album":"\"laut_transcoder__v0.1.0__2026-10-12_09:03:06","uri":"https://youtube.stream.laut.fm/youtube?ref=radiodns","trackType":""} Oct 13 10:55:15 rivo volumio[3456]: verbose: CURRENT POSITION 0 Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState stateService play Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:55:15 rivo volumio[3456]: info: Received an update from plugin. extracting info from payload Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:15 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:15 rivo volumio[3456]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"lautfm","artist":"Verbraucherinformationen","album":"\"laut_transcoder__v0.1.0__2026-10-12_09:03:06","uri":"https://youtube.stream.laut.fm/youtube?ref=radiodns","trackType":""} Oct 13 10:55:15 rivo volumio[3456]: verbose: CURRENT POSITION 0 Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState stateService play Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:55:15 rivo volumio[3456]: info: Received an update from plugin. extracting info from payload Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.406+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.409+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.409+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=lautfm Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.409+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=lautfm Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.411+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.412+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=lautfm Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.413+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=0 volume=100 Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.413+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=lautfm Oct 13 10:55:15 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Oct 13 10:55:15 rivo volumio[3456]: info: ------------------------------ 162ms Oct 13 10:55:15 rivo volumio[3456]: info: ------------------------------ 162ms Oct 13 10:55:15 rivo volumio[3456]: info: Oct 13 10:55:15 rivo volumio[3456]: ---------------------------- MPD announces system playlist update Oct 13 10:55:15 rivo volumio[3456]: info: Ignoring MPD Status Update Oct 13 10:55:15 rivo volumio[3456]: info: Oct 13 10:55:15 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:15 rivo volumio[3456]: info: Oct 13 10:55:15 rivo volumio[3456]: ---------------------------- MPD announces system playlist update Oct 13 10:55:15 rivo volumio[3456]: info: Ignoring MPD Status Update Oct 13 10:55:15 rivo volumio[3456]: info: Oct 13 10:55:15 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand status took 135 milliseconds Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 128 milliseconds Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 129 milliseconds Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 128 milliseconds Oct 13 10:55:15 rivo volumio[3456]: info: ------------------------------ 21ms Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand status took 13 milliseconds Oct 13 10:55:15 rivo volumio[3456]: info: ------------------------------ 13ms Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand status took 10 milliseconds Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:15 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:15 rivo volumio[3456]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1236,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"lautfm","artist":"Verbraucherinformationen","album":"\"laut_transcoder__v0.1.0__2026-10-12_09:03:06","uri":"https://youtube.stream.laut.fm/youtube?ref=radiodns","trackType":""} Oct 13 10:55:15 rivo volumio[3456]: verbose: CURRENT POSITION 0 Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState stateService play Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:55:15 rivo volumio[3456]: info: Received an update from plugin. extracting info from payload Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:15 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:15 rivo volumio[3456]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1236,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"lautfm","artist":"Verbraucherinformationen","album":"\"laut_transcoder__v0.1.0__2026-10-12_09:03:06","uri":"https://youtube.stream.laut.fm/youtube?ref=radiodns","trackType":""} Oct 13 10:55:15 rivo volumio[3456]: verbose: CURRENT POSITION 0 Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState stateService play Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:55:15 rivo volumio[3456]: info: Received an update from plugin. extracting info from payload Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:15 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:15 rivo volumio[3456]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1236,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"lautfm","artist":"Verbraucherinformationen","album":"\"laut_transcoder__v0.1.0__2026-10-12_09:03:06","uri":"https://youtube.stream.laut.fm/youtube?ref=radiodns","trackType":""} Oct 13 10:55:15 rivo volumio[3456]: verbose: CURRENT POSITION 0 Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState stateService play Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:55:15 rivo volumio[3456]: info: Received an update from plugin. extracting info from payload Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.583+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=328 volume=100 Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.584+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=lautfm Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.589+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=328 volume=100 Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.590+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=lautfm Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.593+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=328 volume=100 Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.595+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=328 volume=100 Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.596+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=lautfm Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.597+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=lautfm Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.599+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=328 volume=100 Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.600+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=328 volume=100 Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.601+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=lautfm Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.602+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=lautfm Oct 13 10:55:15 rivo volumio[3456]: info: ------------------------------ 318ms Oct 13 10:55:15 rivo volumio[3456]: info: ------------------------------ 319ms Oct 13 10:55:15 rivo volumio[3456]: info: ------------------------------ 307ms Oct 13 10:55:15 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:15 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:15 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:15 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:15 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:15 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:15 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:15 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:15 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:15 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 284 milliseconds Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 280 milliseconds Oct 13 10:55:15 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 279 milliseconds Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:15 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:15 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:15 rivo volumio[3456]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1236,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"lautfm","artist":"Verbraucherinformationen","album":"\"laut_transcoder__v0.1.0__2026-10-12_09:03:06","uri":"https://youtube.stream.laut.fm/youtube?ref=radiodns","trackType":""} Oct 13 10:55:15 rivo volumio[3456]: verbose: CURRENT POSITION 0 Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState stateService play Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:55:15 rivo volumio[3456]: info: Received an update from plugin. extracting info from payload Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:15 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:15 rivo volumio[3456]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1477,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"lautfm","artist":"Verbraucherinformationen","album":"\"laut_transcoder__v0.1.0__2026-10-12_09:03:06","uri":"https://youtube.stream.laut.fm/youtube?ref=radiodns","trackType":""} Oct 13 10:55:15 rivo volumio[3456]: verbose: CURRENT POSITION 0 Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState stateService play Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:55:15 rivo volumio[3456]: info: Received an update from plugin. extracting info from payload Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:15 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:15 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:15 rivo volumio[3456]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1477,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"lautfm","artist":"Verbraucherinformationen","album":"\"laut_transcoder__v0.1.0__2026-10-12_09:03:06","uri":"https://youtube.stream.laut.fm/youtube?ref=radiodns","trackType":""} Oct 13 10:55:15 rivo volumio[3456]: verbose: CURRENT POSITION 0 Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState stateService play Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:55:15 rivo volumio[3456]: info: Received an update from plugin. extracting info from payload Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:15 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:15 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:15 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.829+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=620 volume=100 Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.830+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=lautfm Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.832+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=620 volume=100 Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.832+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=620 volume=100 Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.833+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=lautfm Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.834+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=lautfm Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.834+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=620 volume=100 Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.834+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=620 volume=100 Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.836+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=lautfm Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.840+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=lautfm Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.836+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=620 volume=100 Oct 13 10:55:15 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:15.845+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=lautfm Oct 13 10:55:15 rivo volumio[3456]: info: ------------------------------ 517ms Oct 13 10:55:15 rivo volumio[3456]: info: ------------------------------ 392ms Oct 13 10:55:15 rivo volumio[3456]: info: ------------------------------ 389ms Oct 13 10:55:15 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:15 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:15 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:15 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:15 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:15 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:17 rivo volumio[3456]: info: Oct 13 10:55:17 rivo volumio[3456]: ---------------------------- MPD announces system playlist update Oct 13 10:55:17 rivo volumio[3456]: info: Ignoring MPD Status Update Oct 13 10:55:17 rivo volumio[3456]: info: Oct 13 10:55:17 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:17 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:17 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:17 rivo volumio[3456]: info: Oct 13 10:55:17 rivo volumio[3456]: ---------------------------- MPD announces system playlist update Oct 13 10:55:17 rivo volumio[3456]: info: Ignoring MPD Status Update Oct 13 10:55:17 rivo volumio[3456]: info: Oct 13 10:55:17 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:17 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:17 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:17 rivo volumio[3456]: info: Oct 13 10:55:17 rivo volumio[3456]: ---------------------------- MPD announces system playlist update Oct 13 10:55:17 rivo volumio[3456]: info: Ignoring MPD Status Update Oct 13 10:55:17 rivo volumio[3456]: info: Oct 13 10:55:17 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:17 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:17 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:17 rivo volumio[3456]: info: ------------------------------ 15ms Oct 13 10:55:17 rivo volumio[3456]: info: sendMpdCommand status took 16 milliseconds Oct 13 10:55:17 rivo volumio[3456]: info: ------------------------------ 16ms Oct 13 10:55:17 rivo volumio[3456]: info: sendMpdCommand status took 14 milliseconds Oct 13 10:55:17 rivo volumio[3456]: info: ------------------------------ 14ms Oct 13 10:55:17 rivo volumio[3456]: info: sendMpdCommand status took 5 milliseconds Oct 13 10:55:17 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:17 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:17 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:17 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:17 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:17 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:17 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 13 10:55:17 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 13 10:55:17 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 13 10:55:17 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:17 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:17 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:17 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:17 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:17 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:17 rivo volumio[3456]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3481,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"shopify.com - ... schon fast die Hälfte geschafft ...","artist":"Verbraucherinformationen","album":"\"laut_transcoder__v0.1.0__2026-10-12_09:03:06","uri":"https://youtube.stream.laut.fm/youtube?ref=radiodns","trackType":""} Oct 13 10:55:17 rivo volumio[3456]: verbose: CURRENT POSITION 0 Oct 13 10:55:17 rivo volumio[3456]: info: CoreStateMachine::syncState stateService play Oct 13 10:55:17 rivo volumio[3456]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:55:17 rivo volumio[3456]: info: Received an update from plugin. extracting info from payload Oct 13 10:55:17 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:17 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:55:17 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:17 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:17 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:17 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:17 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:17 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:17 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:17 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:17 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:17 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:17 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:17 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:17 rivo volumio[3456]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3481,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"shopify.com - ... schon fast die Hälfte geschafft ...","artist":"Verbraucherinformationen","album":"\"laut_transcoder__v0.1.0__2026-10-12_09:03:06","uri":"https://youtube.stream.laut.fm/youtube?ref=radiodns","trackType":""} Oct 13 10:55:17 rivo volumio[3456]: verbose: CURRENT POSITION 0 Oct 13 10:55:17 rivo volumio[3456]: info: CoreStateMachine::syncState stateService play Oct 13 10:55:17 rivo volumio[3456]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:55:17 rivo volumio[3456]: info: Received an update from plugin. extracting info from payload Oct 13 10:55:17 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:17 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:17 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:17 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:17 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:17 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:17 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:17 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:17 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:17 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:17 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:17 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:17 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:17 rivo volumio[3456]: verbose: STATE SERVICE {"status":"play","position":0,"seek":3481,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"shopify.com - ... schon fast die Hälfte geschafft ...","artist":"Verbraucherinformationen","album":"\"laut_transcoder__v0.1.0__2026-10-12_09:03:06","uri":"https://youtube.stream.laut.fm/youtube?ref=radiodns","trackType":""} Oct 13 10:55:17 rivo volumio[3456]: verbose: CURRENT POSITION 0 Oct 13 10:55:17 rivo volumio[3456]: info: CoreStateMachine::syncState stateService play Oct 13 10:55:17 rivo volumio[3456]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:55:17 rivo volumio[3456]: info: Received an update from plugin. extracting info from payload Oct 13 10:55:17 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:17 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:17 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:17 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:17 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:17 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:17 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:17 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:17 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:17 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:17 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:17.407+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=2121 volume=100 Oct 13 10:55:17 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:17.408+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title="shopify.com - ... schon fast die Hälfte geschafft ..." Oct 13 10:55:17 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:17.409+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=2121 volume=100 Oct 13 10:55:17 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:17.410+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=2121 volume=100 Oct 13 10:55:17 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:17.411+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title="shopify.com - ... schon fast die Hälfte geschafft ..." Oct 13 10:55:17 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:17.412+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title="shopify.com - ... schon fast die Hälfte geschafft ..." Oct 13 10:55:17 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:17.413+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=2121 volume=100 Oct 13 10:55:17 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:17.414+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=2121 volume=100 Oct 13 10:55:17 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:17.415+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title="shopify.com - ... schon fast die Hälfte geschafft ..." Oct 13 10:55:17 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:17.416+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title="shopify.com - ... schon fast die Hälfte geschafft ..." Oct 13 10:55:17 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:17.417+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=2121 volume=100 Oct 13 10:55:17 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:17.418+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title="shopify.com - ... schon fast die Hälfte geschafft ..." Oct 13 10:55:17 rivo volumio[3456]: info: ------------------------------ 117ms Oct 13 10:55:17 rivo volumio[3456]: info: ------------------------------ 116ms Oct 13 10:55:17 rivo volumio[3456]: info: ------------------------------ 116ms Oct 13 10:55:17 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:17 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:17 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:17 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:17 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:17 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:27 rivo volumio[3456]: info: Oct 13 10:55:27 rivo volumio[3456]: ---------------------------- MPD announces system playlist update Oct 13 10:55:27 rivo volumio[3456]: info: Ignoring MPD Status Update Oct 13 10:55:27 rivo volumio[3456]: info: Oct 13 10:55:27 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:27 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:27 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:27 rivo volumio[3456]: info: Oct 13 10:55:27 rivo volumio[3456]: ---------------------------- MPD announces system playlist update Oct 13 10:55:27 rivo volumio[3456]: info: Ignoring MPD Status Update Oct 13 10:55:27 rivo volumio[3456]: info: Oct 13 10:55:27 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:27 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:27 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:27 rivo volumio[3456]: info: Oct 13 10:55:27 rivo volumio[3456]: ---------------------------- MPD announces system playlist update Oct 13 10:55:27 rivo volumio[3456]: info: Ignoring MPD Status Update Oct 13 10:55:27 rivo volumio[3456]: info: Oct 13 10:55:27 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:27 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:27 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:27 rivo volumio[3456]: info: ------------------------------ 9ms Oct 13 10:55:27 rivo volumio[3456]: info: sendMpdCommand status took 8 milliseconds Oct 13 10:55:27 rivo volumio[3456]: info: ------------------------------ 7ms Oct 13 10:55:27 rivo volumio[3456]: info: sendMpdCommand status took 6 milliseconds Oct 13 10:55:27 rivo volumio[3456]: info: ------------------------------ 6ms Oct 13 10:55:27 rivo volumio[3456]: info: sendMpdCommand status took 4 milliseconds Oct 13 10:55:27 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:27 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:27 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:27 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:27 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:27 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:27 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 13 10:55:27 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 13 10:55:27 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 13 10:55:27 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:27 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:27 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:27 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:27 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:27 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:27 rivo volumio[3456]: verbose: STATE SERVICE {"status":"play","position":0,"seek":13977,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"shopify.com - ... zweite Halbzeit ...","artist":"Verbraucherinformationen","album":"\"laut_transcoder__v0.1.0__2026-10-12_09:03:06","uri":"https://youtube.stream.laut.fm/youtube?ref=radiodns","trackType":""} Oct 13 10:55:27 rivo volumio[3456]: verbose: CURRENT POSITION 0 Oct 13 10:55:27 rivo volumio[3456]: info: CoreStateMachine::syncState stateService play Oct 13 10:55:27 rivo volumio[3456]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:55:27 rivo volumio[3456]: info: Received an update from plugin. extracting info from payload Oct 13 10:55:27 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:27 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:55:27 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:27 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:27 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:27 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:27 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:27 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:27 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:27 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:27 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:27 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:27 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:27 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:27 rivo volumio[3456]: verbose: STATE SERVICE {"status":"play","position":0,"seek":13977,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"shopify.com - ... zweite Halbzeit ...","artist":"Verbraucherinformationen","album":"\"laut_transcoder__v0.1.0__2026-10-12_09:03:06","uri":"https://youtube.stream.laut.fm/youtube?ref=radiodns","trackType":""} Oct 13 10:55:27 rivo volumio[3456]: verbose: CURRENT POSITION 0 Oct 13 10:55:27 rivo volumio[3456]: info: CoreStateMachine::syncState stateService play Oct 13 10:55:27 rivo volumio[3456]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:55:27 rivo volumio[3456]: info: Received an update from plugin. extracting info from payload Oct 13 10:55:27 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:27 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:27 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:27 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:27 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:27 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:27 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:27 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:27 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:27 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:27 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:27 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:27 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:27 rivo volumio[3456]: verbose: STATE SERVICE {"status":"play","position":0,"seek":13977,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"shopify.com - ... zweite Halbzeit ...","artist":"Verbraucherinformationen","album":"\"laut_transcoder__v0.1.0__2026-10-12_09:03:06","uri":"https://youtube.stream.laut.fm/youtube?ref=radiodns","trackType":""} Oct 13 10:55:27 rivo volumio[3456]: verbose: CURRENT POSITION 0 Oct 13 10:55:27 rivo volumio[3456]: info: CoreStateMachine::syncState stateService play Oct 13 10:55:27 rivo volumio[3456]: info: CoreStateMachine::syncState currentStatus play Oct 13 10:55:27 rivo volumio[3456]: info: Received an update from plugin. extracting info from payload Oct 13 10:55:27 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:27 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:27 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:27 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:27 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:27 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:27 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:27 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:27 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:27 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:27 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:27.905+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=12635 volume=100 Oct 13 10:55:27 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:27.907+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title="shopify.com - ... zweite Halbzeit ..." Oct 13 10:55:27 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:27.908+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=12635 volume=100 Oct 13 10:55:27 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:27.910+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title="shopify.com - ... zweite Halbzeit ..." Oct 13 10:55:27 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:27.910+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=12635 volume=100 Oct 13 10:55:27 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:27.912+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title="shopify.com - ... zweite Halbzeit ..." Oct 13 10:55:27 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:27.917+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=12635 volume=100 Oct 13 10:55:27 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:27.918+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title="shopify.com - ... zweite Halbzeit ..." Oct 13 10:55:27 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:27.920+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=12635 volume=100 Oct 13 10:55:27 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:27.922+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title="shopify.com - ... zweite Halbzeit ..." Oct 13 10:55:27 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:27.922+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_PLAYING positionMs=12635 volume=100 Oct 13 10:55:27 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:27.923+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title="shopify.com - ... zweite Halbzeit ..." Oct 13 10:55:27 rivo volumio[3456]: info: ------------------------------ 115ms Oct 13 10:55:27 rivo volumio[3456]: info: ------------------------------ 113ms Oct 13 10:55:27 rivo volumio[3456]: info: ------------------------------ 112ms Oct 13 10:55:28 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:28 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:28 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:28 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:28 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:28 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:31 rivo volumio[3456]: info: CoreCommandRouter::volumioNext Oct 13 10:55:31 rivo volumio[3456]: info: CoreStateMachine::next Oct 13 10:55:31 rivo volumio[3456]: info: CoreStateMachine::stop Oct 13 10:55:31 rivo volumio[3456]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:55:31 rivo volumio[3456]: info: CoreStateMachine::stPlaybackTimer Oct 13 10:55:31 rivo volumio[3456]: info: CoreStateMachine::updateTrackBlock Oct 13 10:55:31 rivo volumio[3456]: info: CorePlayQueue::getTrackBlock Oct 13 10:55:31 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:31 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:31 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 13 10:55:31 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:31 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:31 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:31 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:31 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:31 rivo volumio[3456]: info: CoreStateMachine::serviceStop Oct 13 10:55:31 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:31 rivo volumio[3456]: info: CoreCommandRouter::serviceStop Oct 13 10:55:31 rivo volumio[3456]: info: [1791881731457] ControllerWebradio::stop Oct 13 10:55:31 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand stop Oct 13 10:55:31 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:31.462+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 13 10:55:31 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:31.464+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=Youtube Oct 13 10:55:31 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:31 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback disable Oct 13 10:55:31 rivo kernel: spdif_a keep clk continuous Oct 13 10:55:31 rivo kernel: aml_spdif_close Oct 13 10:55:31 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Oct 13 10:55:31 rivo volumio[3456]: info: Oct 13 10:55:31 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:31 rivo volumio[3456]: info: sendMpdCommand stop took 40 milliseconds Oct 13 10:55:31 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:31 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:31 rivo volumio[3456]: info: CoreStateMachine::play index undefined Oct 13 10:55:31 rivo volumio[3456]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 13 10:55:31 rivo volumio[3456]: info: CorePlayQueue::getTrack 1 Oct 13 10:55:31 rivo volumio[3456]: info: sendMpdCommand status took 5 milliseconds Oct 13 10:55:31 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:31 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:31 rivo volumio[3456]: info: Oct 13 10:55:31 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:31 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:31 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:31 rivo volumio[3456]: info: Oct 13 10:55:31 rivo volumio[3456]: ---------------------------- MPD announces state update: player Oct 13 10:55:31 rivo volumio[3456]: info: ControllerMpd::getState Oct 13 10:55:31 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand status Oct 13 10:55:31 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 13 10:55:31 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:31 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:31 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:31 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:31 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:31 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:31 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:31 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:31 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:31 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:31 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:31 rivo volumio[3456]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 13 10:55:31 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:31.527+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 13 10:55:31 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:31.527+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=Youtube Oct 13 10:55:31 rivo volumio[3456]: info: ------------------------------ 39ms Oct 13 10:55:31 rivo volumio[3456]: info: sendMpdCommand status took 29 milliseconds Oct 13 10:55:31 rivo volumio[3456]: info: sendMpdCommand status took 28 milliseconds Oct 13 10:55:31 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:31 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:31 rivo volumio[3456]: verbose: ControllerMpd::parseState Oct 13 10:55:31 rivo volumio[3456]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 13 10:55:31 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:31 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 15 milliseconds Oct 13 10:55:31 rivo volumio[3456]: info: sendMpdCommand playlistinfo took 15 milliseconds Oct 13 10:55:31 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:31 rivo volumio[3456]: verbose: ControllerMpd::parseTrackInfo Oct 13 10:55:31 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:31 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:31 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:31 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:31 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:31 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:31 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:31 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:31 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:31 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:31 rivo volumio[3456]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 13 10:55:31 rivo volumio[3456]: info: ControllerMpd::pushState Oct 13 10:55:31 rivo volumio[3456]: info: CoreCommandRouter::servicePushState Oct 13 10:55:31 rivo volumio[3456]: info: CoreStateMachine::pushState Oct 13 10:55:31 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:31 rivo volumio[3456]: info: CoreCommandRouter::volumioPushState Oct 13 10:55:31 rivo volumio[3456]: info: CoreCommandRouter::volumioGetState Oct 13 10:55:31 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:31 rivo volumio[3456]: info: MRS: Pushing multiroomSync output update for this device Oct 13 10:55:31 rivo volumio[3456]: info: MRS: Pushing multiroomSync output Oct 13 10:55:31 rivo volumio[3456]: info: CorePlayQueue::getTrack 0 Oct 13 10:55:31 rivo volumio[3456]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Oct 13 10:55:31 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:31.578+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 13 10:55:31 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:31.579+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=Youtube Oct 13 10:55:31 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:31.580+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" state=STATUS_STOPPED positionMs=0 volume=100 Oct 13 10:55:31 rivo volumio5-onboarding[4008]: time=2026-10-13T10:55:31.581+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.214:53538,00:00:00:00:00:00%01 @ 0x21accc0" id="https://youtube.stream.laut.fm/youtube?ref=radiodns" title=Youtube Oct 13 10:55:31 rivo volumio[3456]: info: ------------------------------ 88ms Oct 13 10:55:31 rivo volumio[3456]: info: ------------------------------ 86ms Oct 13 10:55:31 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:31 rivo volumio[3456]: info: Updating RAAT Signal Path Oct 13 10:55:39 rivo volumio[3456]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Oct 13 10:55:39 rivo volumio[3456]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Oct 13 10:55:39 rivo volumio[3456]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 13 10:55:39 rivo volumio[3456]: TypeError: Cannot read properties of undefined (reading 'then') Oct 13 10:55:39 rivo volumio[3456]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Oct 13 10:55:39 rivo volumio[3456]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2279:30) Oct 13 10:55:39 rivo volumio[3456]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1467:26) Oct 13 10:55:39 rivo volumio[3456]: at Socket.emit (node:events:514:28) Oct 13 10:55:39 rivo volumio[3456]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Oct 13 10:55:39 rivo volumio[3456]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Oct 13 10:55:39 rivo volumio[3456]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 13 10:55:40 rivo sudo[5933]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-13 10:54' Oct 13 10:55:40 rivo sudo[5933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="8ed05bf20f96eb8557ed5652c420f84f39d66325" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0a52c1fb90959ba1872a2fb0225e56fe615b19ac" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed Sep 16 16:27:36 UTC 2026" VOLUMIO_VERSION="4.208" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="be0c94671215c2b1bf2440825a1e4211"