-- Logs begin at Thu 2019-02-14 18:11:58 CST, end at Sat 2026-04-11 13:40:16 CST. -- Apr 11 13:39:00 primo volumio[3091]: info: Preload queue cleared Apr 11 13:39:00 primo volumio[3091]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 11 13:39:00 primo volumio[3091]: info: CoreStateMachine::ClearQueue Apr 11 13:39:00 primo volumio[3091]: info: CoreStateMachine::stop Apr 11 13:39:00 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:00 primo volumio[3091]: info: CorePlayQueue::clearPlayQueue Apr 11 13:39:00 primo volumio[3091]: info: CorePlayQueue::saveQueue Apr 11 13:39:00 primo volumio[3091]: info: CoreCommandRouter::volumioPushQueue Apr 11 13:39:00 primo volumio[3091]: info: CoreStateMachine::addQueueItems Apr 11 13:39:00 primo volumio[3091]: info: CorePlayQueue::addQueueItems Apr 11 13:39:00 primo volumio[3091]: info: Preload queue cleared Apr 11 13:39:00 primo volumio[3091]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996 Apr 11 13:39:00 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Apr 11 13:39:00 primo volumio[3091]: info: CoreCommandRouter::volumioPushQueue Apr 11 13:39:00 primo volumio[3091]: info: CorePlayQueue::saveQueue Apr 11 13:39:00 primo volumio[3091]: info: CoreStateMachine::updateTrackBlock Apr 11 13:39:00 primo volumio[3091]: info: CorePlayQueue::getTrackBlock Apr 11 13:39:00 primo volumio[3091]: info: CoreCommandRouter::volumioPlay Apr 11 13:39:00 primo volumio[3091]: info: CoreStateMachine::play index 0 Apr 11 13:39:00 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:00 primo volumio[3091]: info: CoreStateMachine::stop Apr 11 13:39:00 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:00 primo volumio[3091]: info: CoreStateMachine::play index undefined Apr 11 13:39:00 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:00 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:00 primo volumio[3091]: info: CoreStateMachine::startPlaybackTimer Apr 11 13:39:00 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:00 primo volumio[3091]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 13:39:00 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 13:39:00 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 11 13:39:00 primo volumio[3091]: info: [1775885940848] ControllerWebradio::clearAddPlayTrack Apr 11 13:39:00 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 13:39:00 primo volumio[3091]: info: Apr 11 13:39:00 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:00 primo volumio[3091]: info: sendMpdCommand stop took 7 milliseconds Apr 11 13:39:00 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:00 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:00 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 13:39:00 primo volumio[3091]: info: Apr 11 13:39:00 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:00 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:00 primo volumio[3091]: info: sendMpdCommand status took 3 milliseconds Apr 11 13:39:00 primo volumio[3091]: info: sendMpdCommand clear took 3 milliseconds Apr 11 13:39:00 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:00 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:00 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" Apr 11 13:39:00 primo volumio[3091]: error: updateQueue error: null Apr 11 13:39:00 primo volumio[3091]: info: ------------------------------ 6ms Apr 11 13:39:00 primo volumio[3091]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 11 13:39:00 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:00 primo volumio[3091]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 11 13:39:00 primo volumio[3091]: info: ------------------------------ 12ms Apr 11 13:39:01 primo volumio[3091]: info: Apr 11 13:39:01 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:01 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:01 primo volumio[3091]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" took 206 milliseconds Apr 11 13:39:01 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 13:39:01 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand play Apr 11 13:39:01 primo volumio[3091]: info: ------------------------------ 3ms Apr 11 13:39:01 primo volumio[3091]: info: sendMpdCommand play took 2 milliseconds Apr 11 13:39:01 primo volumio[3091]: info: Executing endpoint metavolumio Apr 11 13:39:01 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 11 13:39:01 primo volumio[3091]: info: Executing endpoint metavolumio Apr 11 13:39:01 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 11 13:39:04 primo volumio[3091]: info: Apr 11 13:39:04 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:04 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:04 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:04 primo kernel: aml_spdif_open Apr 11 13:39:04 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Apr 11 13:39:04 primo kernel: set normal 512 fs /4 fs Apr 11 13:39:04 primo kernel: set spdifout clk:5644800, mpll:22579200 Apr 11 13:39:04 primo kernel: get spdifout clk:5644797, mpll:22579186 Apr 11 13:39:04 primo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Apr 11 13:39:04 primo kernel: set normal 512 fs /4 fs Apr 11 13:39:04 primo kernel: set spdifout clk:5644800, mpll:22579200 Apr 11 13:39:04 primo kernel: get spdifout clk:5644797, mpll:22579186 Apr 11 13:39:04 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Apr 11 13:39:04 primo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Apr 11 13:39:04 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Apr 11 13:39:04 primo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Apr 11 13:39:04 primo volumio[3091]: info: Apr 11 13:39:04 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:04 primo volumio[3091]: info: sendMpdCommand status took 11 milliseconds Apr 11 13:39:04 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:04 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:04 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:04 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:04 primo volumio[3091]: info: sendMpdCommand status took 3 milliseconds Apr 11 13:39:04 primo volumio[3091]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 11 13:39:04 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:04 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:04 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:04 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:39:04 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:04 primo volumio[3091]: 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":"antenne","artist":"(#1 - 4908/500000) ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:39:04 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:39:04 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:39:04 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus stop Apr 11 13:39:04 primo volumio[3091]: info: ------------------------------ 22ms Apr 11 13:39:04 primo volumio[3091]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 11 13:39:04 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:04 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:39:04 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:04 primo volumio[3091]: 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":"antenne","artist":"(#1 - 4908/500000) ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:39:04 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:39:04 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:39:04 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:39:04 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:39:04 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:04 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:04 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:04 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:04 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:04 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:04 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.407+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.408+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.409+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="ANTENNE BAYERN" Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.409+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="ANTENNE BAYERN" Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.410+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.411+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.411+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="ANTENNE BAYERN" Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.412+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="ANTENNE BAYERN" Apr 11 13:39:04 primo volumio[3091]: info: ------------------------------ 61ms Apr 11 13:39:04 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:39:04 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:04 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:04 primo volumio[3091]: info: Apr 11 13:39:04 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:04 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:04 primo volumio[3091]: info: Apr 11 13:39:04 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:04 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:04 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:04 primo volumio[3091]: info: ------------------------------ 4ms Apr 11 13:39:04 primo volumio[3091]: info: sendMpdCommand status took 2 milliseconds Apr 11 13:39:04 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:04 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:04 primo volumio[3091]: info: Apr 11 13:39:04 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:04 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:04 primo volumio[3091]: info: Apr 11 13:39:04 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:04 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:04 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:04 primo volumio[3091]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 11 13:39:04 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:04 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:39:04 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:04 primo volumio[3091]: verbose: STATE SERVICE {"status":"play","position":0,"seek":331,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Elton John, Dua Lipa - Cold Heart (PNAU Remix)","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:39:04 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:39:04 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:39:04 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:39:04 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:39:04 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:04 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:04 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:04 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:04 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:04 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.652+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=252 volume=100 Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.652+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=252 volume=100 Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.653+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Elton John, Dua Lipa - Cold Heart (PNAU Remix)" Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.653+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Elton John, Dua Lipa - Cold Heart (PNAU Remix)" Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.653+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=252 volume=100 Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.654+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=252 volume=100 Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.654+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Elton John, Dua Lipa - Cold Heart (PNAU Remix)" Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.655+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Elton John, Dua Lipa - Cold Heart (PNAU Remix)" Apr 11 13:39:04 primo volumio[3091]: info: ------------------------------ 57ms Apr 11 13:39:04 primo volumio[3091]: info: ------------------------------ 53ms Apr 11 13:39:04 primo volumio[3091]: info: sendMpdCommand status took 52 milliseconds Apr 11 13:39:04 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:04 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:04 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:39:04 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:39:04 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:04 primo volumio[3091]: info: sendMpdCommand playlistinfo took 36 milliseconds Apr 11 13:39:04 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:04 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:39:04 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:04 primo volumio[3091]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1173,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Elton John, Dua Lipa - Cold Heart (PNAU Remix)","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:39:04 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:39:04 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:39:04 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:39:04 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:39:04 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:04 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:04 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:04 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:04 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:04 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:04 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:04 primo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.750+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=347 volume=100 Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.750+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=347 volume=100 Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.751+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Elton John, Dua Lipa - Cold Heart (PNAU Remix)" Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.751+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Elton John, Dua Lipa - Cold Heart (PNAU Remix)" Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.752+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=347 volume=100 Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.752+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=347 volume=100 Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.753+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Elton John, Dua Lipa - Cold Heart (PNAU Remix)" Apr 11 13:39:04 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:04.753+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Elton John, Dua Lipa - Cold Heart (PNAU Remix)" Apr 11 13:39:04 primo volumio[3091]: info: ------------------------------ 151ms Apr 11 13:39:04 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:39:04 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:39:04 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:04 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:05 primo volumio[3091]: info: Apr 11 13:39:05 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:05 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:05 primo volumio[3091]: info: Apr 11 13:39:05 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:05 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:05 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:05 primo volumio[3091]: info: ------------------------------ 4ms Apr 11 13:39:05 primo volumio[3091]: info: sendMpdCommand status took 2 milliseconds Apr 11 13:39:05 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:05 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:05 primo volumio[3091]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 11 13:39:05 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:05 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:39:05 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:39:05 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:05 primo volumio[3091]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1985,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Elton John, Dua Lipa - Cold Heart (PNAU Remix)","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:39:05 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:39:05 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:39:05 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:39:05 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:39:05 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:39:05 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:05 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:39:05 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:05 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:05 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:05 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:05 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:05 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:05 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:05 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:05 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:05.164+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=752 volume=100 Apr 11 13:39:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:05.165+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=752 volume=100 Apr 11 13:39:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:05.165+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Elton John, Dua Lipa - Cold Heart (PNAU Remix)" Apr 11 13:39:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:05.166+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Elton John, Dua Lipa - Cold Heart (PNAU Remix)" Apr 11 13:39:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:05.167+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=752 volume=100 Apr 11 13:39:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:05.167+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=752 volume=100 Apr 11 13:39:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:05.168+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Elton John, Dua Lipa - Cold Heart (PNAU Remix)" Apr 11 13:39:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:05.168+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Elton John, Dua Lipa - Cold Heart (PNAU Remix)" Apr 11 13:39:05 primo volumio[3091]: info: ------------------------------ 54ms Apr 11 13:39:05 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:39:05 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:39:05 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:05 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:05 primo volumio[3091]: info: Apr 11 13:39:05 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:05 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:05 primo volumio[3091]: info: Apr 11 13:39:05 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:05 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:05 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:05 primo volumio[3091]: info: ------------------------------ 4ms Apr 11 13:39:05 primo volumio[3091]: info: sendMpdCommand status took 2 milliseconds Apr 11 13:39:05 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:05 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:05 primo volumio[3091]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 11 13:39:05 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:05 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:39:05 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:39:05 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:05 primo volumio[3091]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2736,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Elton John, Dua Lipa - Cold Heart (PNAU Remix)","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:39:05 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:39:05 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:39:05 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:39:05 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:39:05 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:39:05 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:05 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:39:05 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:05 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:05 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:05 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:05 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:05 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:05 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:05 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:05 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:05.905+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=1501 volume=100 Apr 11 13:39:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:05.905+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=1501 volume=100 Apr 11 13:39:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:05.906+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Elton John, Dua Lipa - Cold Heart (PNAU Remix)" Apr 11 13:39:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:05.907+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Elton John, Dua Lipa - Cold Heart (PNAU Remix)" Apr 11 13:39:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:05.908+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=1501 volume=100 Apr 11 13:39:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:05.909+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=1501 volume=100 Apr 11 13:39:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:05.909+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Elton John, Dua Lipa - Cold Heart (PNAU Remix)" Apr 11 13:39:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:05.910+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Elton John, Dua Lipa - Cold Heart (PNAU Remix)" Apr 11 13:39:05 primo volumio[3091]: info: ------------------------------ 51ms Apr 11 13:39:05 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:39:05 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:39:05 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:05 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:06 primo volumio[3091]: info: Executing endpoint metavolumio Apr 11 13:39:06 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 11 13:39:06 primo volumio[3091]: info: Executing endpoint metavolumio Apr 11 13:39:06 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 11 13:39:07 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:07.714+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:39:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:11.021+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:39:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:14.331+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:39:17 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:17.639+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:39:20 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:20.952+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:39:24 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:24.260+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:39:27 primo volumio[3091]: info: CoreCommandRouter::volumioStop Apr 11 13:39:27 primo volumio[3091]: info: CoreStateMachine::stop Apr 11 13:39:27 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:27 primo volumio[3091]: info: CoreStateMachine::stPlaybackTimer Apr 11 13:39:27 primo volumio[3091]: info: CoreStateMachine::updateTrackBlock Apr 11 13:39:27 primo volumio[3091]: info: CorePlayQueue::getTrackBlock Apr 11 13:39:27 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:27 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:27 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:39:27 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:27 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:27 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:27 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:27 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:27 primo volumio[3091]: info: CoreStateMachine::serviceStop Apr 11 13:39:27 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:27 primo volumio[3091]: info: CoreCommandRouter::serviceStop Apr 11 13:39:27 primo volumio[3091]: info: [1775885967276] ControllerWebradio::stop Apr 11 13:39:27 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 13:39:27 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:27.278+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_STOPPED positionMs=0 volume=100 Apr 11 13:39:27 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:27.278+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_STOPPED positionMs=0 volume=100 Apr 11 13:39:27 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:27.279+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" title="ANTENNE BAYERN" Apr 11 13:39:27 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:27.279+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" title="ANTENNE BAYERN" Apr 11 13:39:27 primo kernel: asoc-aml-card auge_sound: S/PDIF Playback disable Apr 11 13:39:27 primo kernel: spdif_a keep clk continuous Apr 11 13:39:27 primo kernel: aml_spdif_close Apr 11 13:39:27 primo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Apr 11 13:39:27 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:27 primo volumio[3091]: info: Apr 11 13:39:27 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:27 primo volumio[3091]: info: sendMpdCommand stop took 28 milliseconds Apr 11 13:39:27 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:27 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:27 primo volumio[3091]: info: sendMpdCommand status took 3 milliseconds Apr 11 13:39:27 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:27 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:27 primo volumio[3091]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 11 13:39:27 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:27 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:39:27 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:39:27 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:27 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:27 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:27 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:27 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:27 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:27 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:27 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:27 primo volumio[3091]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Apr 11 13:39:27 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:27.335+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_STOPPED positionMs=0 volume=100 Apr 11 13:39:27 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:27.335+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_STOPPED positionMs=0 volume=100 Apr 11 13:39:27 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:27.336+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" title="ANTENNE BAYERN" Apr 11 13:39:27 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:27.336+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" title="ANTENNE BAYERN" Apr 11 13:39:27 primo volumio[3091]: info: ------------------------------ 43ms Apr 11 13:39:27 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:27 primo volumio[3091]: info: MCU Signalled Playback Inactive Apr 11 13:39:27 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:27.569+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:39:28 primo volumio[3091]: info: CoreCommandRouter::volumioPlay Apr 11 13:39:28 primo volumio[3091]: info: CoreStateMachine::play index undefined Apr 11 13:39:28 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:28 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:28 primo volumio[3091]: info: CoreStateMachine::startPlaybackTimer Apr 11 13:39:28 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:28 primo volumio[3091]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 13:39:28 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 13:39:28 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 11 13:39:28 primo volumio[3091]: info: [1775885968613] ControllerWebradio::clearAddPlayTrack Apr 11 13:39:28 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 13:39:28 primo volumio[3091]: info: sendMpdCommand stop took 1 milliseconds Apr 11 13:39:28 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 13:39:28 primo volumio[3091]: info: Apr 11 13:39:28 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:28 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:28 primo volumio[3091]: info: sendMpdCommand clear took 2 milliseconds Apr 11 13:39:28 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" Apr 11 13:39:28 primo volumio[3091]: error: updateQueue error: null Apr 11 13:39:28 primo volumio[3091]: info: ------------------------------ 8ms Apr 11 13:39:28 primo volumio[3091]: info: Apr 11 13:39:28 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:28 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:28 primo volumio[3091]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" took 210 milliseconds Apr 11 13:39:28 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 13:39:28 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand play Apr 11 13:39:28 primo volumio[3091]: info: ------------------------------ 4ms Apr 11 13:39:28 primo volumio[3091]: info: sendMpdCommand play took 2 milliseconds Apr 11 13:39:29 primo volumio[3091]: info: Executing endpoint metavolumio Apr 11 13:39:29 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 11 13:39:29 primo volumio[3091]: info: Executing endpoint metavolumio Apr 11 13:39:29 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 11 13:39:29 primo volumio[3091]: info: CoreCommandRouter::volumioPlay Apr 11 13:39:29 primo volumio[3091]: info: CoreStateMachine::play index undefined Apr 11 13:39:29 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:29 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:29 primo volumio[3091]: info: CoreStateMachine::startPlaybackTimer Apr 11 13:39:29 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:29 primo volumio[3091]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 13:39:29 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 13:39:29 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 11 13:39:29 primo volumio[3091]: info: [1775885969588] ControllerWebradio::clearAddPlayTrack Apr 11 13:39:29 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 13:39:29 primo volumio[3091]: info: Apr 11 13:39:29 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:29 primo volumio[3091]: info: sendMpdCommand stop took 2 milliseconds Apr 11 13:39:29 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:29 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:29 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 13:39:29 primo volumio[3091]: info: Apr 11 13:39:29 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:29 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:29 primo volumio[3091]: info: sendMpdCommand status took 3 milliseconds Apr 11 13:39:29 primo volumio[3091]: info: sendMpdCommand clear took 3 milliseconds Apr 11 13:39:29 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:29 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:29 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" Apr 11 13:39:29 primo volumio[3091]: error: updateQueue error: null Apr 11 13:39:29 primo volumio[3091]: info: ------------------------------ 5ms Apr 11 13:39:29 primo volumio[3091]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 11 13:39:29 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:29 primo volumio[3091]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 11 13:39:29 primo volumio[3091]: info: ------------------------------ 10ms Apr 11 13:39:29 primo volumio[3091]: info: Apr 11 13:39:29 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:29 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:29 primo volumio[3091]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" took 214 milliseconds Apr 11 13:39:29 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 13:39:29 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand play Apr 11 13:39:29 primo volumio[3091]: info: ------------------------------ 3ms Apr 11 13:39:29 primo volumio[3091]: info: sendMpdCommand play took 2 milliseconds Apr 11 13:39:30 primo volumio[3091]: info: CoreCommandRouter::volumioPlay Apr 11 13:39:30 primo volumio[3091]: info: CoreStateMachine::play index undefined Apr 11 13:39:30 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:30 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:30 primo volumio[3091]: info: CoreStateMachine::startPlaybackTimer Apr 11 13:39:30 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:30 primo volumio[3091]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 13:39:30 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 13:39:30 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 11 13:39:30 primo volumio[3091]: info: [1775885970030] ControllerWebradio::clearAddPlayTrack Apr 11 13:39:30 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 13:39:30 primo volumio[3091]: info: Apr 11 13:39:30 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:30 primo volumio[3091]: info: sendMpdCommand stop took 3 milliseconds Apr 11 13:39:30 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:30 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:30 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 13:39:30 primo volumio[3091]: info: Apr 11 13:39:30 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:30 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:30 primo volumio[3091]: info: sendMpdCommand status took 3 milliseconds Apr 11 13:39:30 primo volumio[3091]: info: sendMpdCommand clear took 3 milliseconds Apr 11 13:39:30 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:30 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:30 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" Apr 11 13:39:30 primo volumio[3091]: error: updateQueue error: null Apr 11 13:39:30 primo volumio[3091]: info: ------------------------------ 5ms Apr 11 13:39:30 primo volumio[3091]: info: sendMpdCommand playlistinfo took 3 milliseconds Apr 11 13:39:30 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:30 primo volumio[3091]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 11 13:39:30 primo volumio[3091]: info: ------------------------------ 11ms Apr 11 13:39:30 primo volumio[3091]: info: Apr 11 13:39:30 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:30 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:30 primo volumio[3091]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" took 217 milliseconds Apr 11 13:39:30 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 13:39:30 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand play Apr 11 13:39:30 primo volumio[3091]: info: ------------------------------ 3ms Apr 11 13:39:30 primo volumio[3091]: info: sendMpdCommand play took 2 milliseconds Apr 11 13:39:30 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:30.876+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:39:30 primo volumio[3091]: info: CoreCommandRouter::volumioPlay Apr 11 13:39:30 primo volumio[3091]: info: CoreStateMachine::play index undefined Apr 11 13:39:30 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:30 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:30 primo volumio[3091]: info: CoreStateMachine::startPlaybackTimer Apr 11 13:39:30 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:30 primo volumio[3091]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 13:39:30 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 13:39:30 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 11 13:39:30 primo volumio[3091]: info: [1775885970906] ControllerWebradio::clearAddPlayTrack Apr 11 13:39:30 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 13:39:30 primo volumio[3091]: info: Apr 11 13:39:30 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:30 primo volumio[3091]: info: sendMpdCommand stop took 2 milliseconds Apr 11 13:39:30 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:30 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:30 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 13:39:30 primo volumio[3091]: info: Apr 11 13:39:30 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:30 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:30 primo volumio[3091]: info: sendMpdCommand status took 3 milliseconds Apr 11 13:39:30 primo volumio[3091]: info: sendMpdCommand clear took 2 milliseconds Apr 11 13:39:30 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:30 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:30 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" Apr 11 13:39:30 primo volumio[3091]: error: updateQueue error: null Apr 11 13:39:30 primo volumio[3091]: info: ------------------------------ 11ms Apr 11 13:39:30 primo volumio[3091]: info: sendMpdCommand playlistinfo took 9 milliseconds Apr 11 13:39:30 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:30 primo volumio[3091]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 11 13:39:30 primo volumio[3091]: info: ------------------------------ 16ms Apr 11 13:39:31 primo volumio[3091]: info: Apr 11 13:39:31 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:31 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:31 primo volumio[3091]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" took 211 milliseconds Apr 11 13:39:31 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 13:39:31 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand play Apr 11 13:39:31 primo volumio[3091]: info: ------------------------------ 4ms Apr 11 13:39:31 primo volumio[3091]: info: sendMpdCommand play took 3 milliseconds Apr 11 13:39:33 primo volumio[3091]: info: Preload queue cleared Apr 11 13:39:33 primo volumio[3091]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 11 13:39:33 primo volumio[3091]: info: CoreStateMachine::ClearQueue Apr 11 13:39:33 primo volumio[3091]: info: CoreStateMachine::stop Apr 11 13:39:33 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:33 primo volumio[3091]: info: CorePlayQueue::clearPlayQueue Apr 11 13:39:33 primo volumio[3091]: info: CorePlayQueue::saveQueue Apr 11 13:39:33 primo volumio[3091]: info: CoreCommandRouter::volumioPushQueue Apr 11 13:39:33 primo volumio[3091]: info: CoreStateMachine::addQueueItems Apr 11 13:39:33 primo volumio[3091]: info: CorePlayQueue::addQueueItems Apr 11 13:39:33 primo volumio[3091]: info: Preload queue cleared Apr 11 13:39:33 primo volumio[3091]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99623166 Apr 11 13:39:33 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Apr 11 13:39:33 primo volumio[3091]: info: CoreCommandRouter::volumioPushQueue Apr 11 13:39:33 primo volumio[3091]: info: CorePlayQueue::saveQueue Apr 11 13:39:33 primo volumio[3091]: info: CoreStateMachine::updateTrackBlock Apr 11 13:39:33 primo volumio[3091]: info: CorePlayQueue::getTrackBlock Apr 11 13:39:33 primo volumio[3091]: info: CoreCommandRouter::volumioPlay Apr 11 13:39:33 primo volumio[3091]: info: CoreStateMachine::play index 0 Apr 11 13:39:33 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:33 primo volumio[3091]: info: CoreStateMachine::stop Apr 11 13:39:33 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:33 primo volumio[3091]: info: CoreStateMachine::play index undefined Apr 11 13:39:33 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:33 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:33 primo volumio[3091]: info: CoreStateMachine::startPlaybackTimer Apr 11 13:39:33 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:33 primo volumio[3091]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 13:39:33 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 13:39:33 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 11 13:39:33 primo volumio[3091]: info: [1775885973224] ControllerWebradio::clearAddPlayTrack Apr 11 13:39:33 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 13:39:34 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:34.184+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:39:37 primo volumio[3091]: info: Apr 11 13:39:37 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:37 primo volumio[3091]: info: sendMpdCommand stop took 4118 milliseconds Apr 11 13:39:37 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:37 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:37 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 13:39:37 primo volumio[3091]: info: Apr 11 13:39:37 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:37 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:37 primo volumio[3091]: info: sendMpdCommand status took 3 milliseconds Apr 11 13:39:37 primo volumio[3091]: info: sendMpdCommand clear took 3 milliseconds Apr 11 13:39:37 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:37 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:37 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99623166" Apr 11 13:39:37 primo volumio[3091]: error: updateQueue error: null Apr 11 13:39:37 primo volumio[3091]: info: ------------------------------ 5ms Apr 11 13:39:37 primo volumio[3091]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 11 13:39:37 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:37 primo volumio[3091]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 11 13:39:37 primo volumio[3091]: info: ------------------------------ 15ms Apr 11 13:39:37 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:37.493+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:39:37 primo volumio[3091]: info: Apr 11 13:39:37 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:37 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:37 primo volumio[3091]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99623166" took 209 milliseconds Apr 11 13:39:37 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 13:39:37 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand play Apr 11 13:39:37 primo volumio[3091]: info: ------------------------------ 4ms Apr 11 13:39:37 primo volumio[3091]: info: sendMpdCommand play took 3 milliseconds Apr 11 13:39:39 primo volumio[3091]: info: Preload queue cleared Apr 11 13:39:39 primo volumio[3091]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 11 13:39:39 primo volumio[3091]: info: CoreStateMachine::ClearQueue Apr 11 13:39:39 primo volumio[3091]: info: CoreStateMachine::stop Apr 11 13:39:39 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:39 primo volumio[3091]: info: CorePlayQueue::clearPlayQueue Apr 11 13:39:39 primo volumio[3091]: info: CorePlayQueue::saveQueue Apr 11 13:39:39 primo volumio[3091]: info: CoreCommandRouter::volumioPushQueue Apr 11 13:39:39 primo volumio[3091]: info: CoreStateMachine::addQueueItems Apr 11 13:39:39 primo volumio[3091]: info: CorePlayQueue::addQueueItems Apr 11 13:39:39 primo volumio[3091]: info: Preload queue cleared Apr 11 13:39:39 primo volumio[3091]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996 Apr 11 13:39:39 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Apr 11 13:39:39 primo volumio[3091]: info: CoreCommandRouter::volumioPushQueue Apr 11 13:39:39 primo volumio[3091]: info: CorePlayQueue::saveQueue Apr 11 13:39:39 primo volumio[3091]: info: CoreStateMachine::updateTrackBlock Apr 11 13:39:39 primo volumio[3091]: info: CorePlayQueue::getTrackBlock Apr 11 13:39:39 primo volumio[3091]: info: CoreCommandRouter::volumioPlay Apr 11 13:39:39 primo volumio[3091]: info: CoreStateMachine::play index 0 Apr 11 13:39:39 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:39 primo volumio[3091]: info: CoreStateMachine::stop Apr 11 13:39:39 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:39 primo volumio[3091]: info: CoreStateMachine::play index undefined Apr 11 13:39:39 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:39 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:39 primo volumio[3091]: info: CoreStateMachine::startPlaybackTimer Apr 11 13:39:39 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:39 primo volumio[3091]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 13:39:39 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 13:39:39 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 11 13:39:39 primo volumio[3091]: info: [1775885979892] ControllerWebradio::clearAddPlayTrack Apr 11 13:39:39 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 13:39:40 primo volumio[3091]: info: sendMpdCommand stop took 109 milliseconds Apr 11 13:39:40 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 13:39:40 primo volumio[3091]: info: Apr 11 13:39:40 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:40 primo volumio[3091]: info: Apr 11 13:39:40 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:40 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:40 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:40 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:40 primo volumio[3091]: info: sendMpdCommand clear took 3 milliseconds Apr 11 13:39:40 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" Apr 11 13:39:40 primo volumio[3091]: error: updateQueue error: null Apr 11 13:39:40 primo volumio[3091]: info: sendMpdCommand status took 3 milliseconds Apr 11 13:39:40 primo volumio[3091]: info: ------------------------------ 5ms Apr 11 13:39:40 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:40 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:39:40 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:39:40 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:40 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:40 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:39:40 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:40 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:40 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:40 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:40 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:40 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:40 primo volumio[3091]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Apr 11 13:39:40 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:40.023+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_STOPPED positionMs=89 volume=100 Apr 11 13:39:40 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:40.023+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_STOPPED positionMs=89 volume=100 Apr 11 13:39:40 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:40.024+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" title="ANTENNE BAYERN" Apr 11 13:39:40 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:40.024+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" title="ANTENNE BAYERN" Apr 11 13:39:40 primo volumio[3091]: info: ------------------------------ 28ms Apr 11 13:39:40 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:40 primo volumio[3091]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" took 215 milliseconds Apr 11 13:39:40 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 13:39:40 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand play Apr 11 13:39:40 primo volumio[3091]: info: Apr 11 13:39:40 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:40 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:40 primo volumio[3091]: info: sendMpdCommand play took 3 milliseconds Apr 11 13:39:40 primo volumio[3091]: info: ------------------------------ 2ms Apr 11 13:39:40 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:40.801+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:39:42 primo volumio[3091]: info: CoreCommandRouter::volumioPlay Apr 11 13:39:42 primo volumio[3091]: info: CoreStateMachine::play index undefined Apr 11 13:39:42 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:42 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:42 primo volumio[3091]: info: CoreStateMachine::startPlaybackTimer Apr 11 13:39:42 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:42 primo volumio[3091]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 13:39:42 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 13:39:42 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 11 13:39:42 primo volumio[3091]: info: [1775885982374] ControllerWebradio::clearAddPlayTrack Apr 11 13:39:42 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 13:39:43 primo volumio[3091]: info: Preload queue cleared Apr 11 13:39:43 primo volumio[3091]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 11 13:39:43 primo volumio[3091]: info: CoreStateMachine::ClearQueue Apr 11 13:39:43 primo volumio[3091]: info: CoreStateMachine::stop Apr 11 13:39:43 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:43 primo volumio[3091]: info: CorePlayQueue::clearPlayQueue Apr 11 13:39:43 primo volumio[3091]: info: CorePlayQueue::saveQueue Apr 11 13:39:43 primo volumio[3091]: info: CoreCommandRouter::volumioPushQueue Apr 11 13:39:43 primo volumio[3091]: info: CoreStateMachine::addQueueItems Apr 11 13:39:43 primo volumio[3091]: info: CorePlayQueue::addQueueItems Apr 11 13:39:43 primo volumio[3091]: info: Preload queue cleared Apr 11 13:39:43 primo volumio[3091]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996 Apr 11 13:39:43 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Apr 11 13:39:43 primo volumio[3091]: info: CoreCommandRouter::volumioPushQueue Apr 11 13:39:43 primo volumio[3091]: info: CorePlayQueue::saveQueue Apr 11 13:39:43 primo volumio[3091]: info: CoreStateMachine::updateTrackBlock Apr 11 13:39:43 primo volumio[3091]: info: CorePlayQueue::getTrackBlock Apr 11 13:39:43 primo volumio[3091]: info: CoreCommandRouter::volumioPlay Apr 11 13:39:43 primo volumio[3091]: info: CoreStateMachine::play index 0 Apr 11 13:39:43 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:43 primo volumio[3091]: info: CoreStateMachine::stop Apr 11 13:39:43 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:43 primo volumio[3091]: info: CoreStateMachine::play index undefined Apr 11 13:39:43 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:39:43 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:43 primo volumio[3091]: info: CoreStateMachine::startPlaybackTimer Apr 11 13:39:43 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:43 primo volumio[3091]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 13:39:43 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 13:39:43 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 11 13:39:43 primo volumio[3091]: info: [1775885983995] ControllerWebradio::clearAddPlayTrack Apr 11 13:39:43 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 13:39:44 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:44.110+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:39:46 primo volumio[3091]: info: Apr 11 13:39:46 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:46 primo volumio[3091]: info: sendMpdCommand stop took 4359 milliseconds Apr 11 13:39:46 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:46 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:46 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 13:39:46 primo volumio[3091]: info: sendMpdCommand stop took 2740 milliseconds Apr 11 13:39:46 primo volumio[3091]: info: sendMpdCommand status took 2 milliseconds Apr 11 13:39:46 primo volumio[3091]: info: sendMpdCommand clear took 3 milliseconds Apr 11 13:39:46 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 13:39:46 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:46 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:46 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" Apr 11 13:39:46 primo volumio[3091]: info: Apr 11 13:39:46 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:46 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:46 primo volumio[3091]: info: Apr 11 13:39:46 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:46 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:46 primo volumio[3091]: info: sendMpdCommand clear took 4 milliseconds Apr 11 13:39:46 primo volumio[3091]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 11 13:39:46 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" Apr 11 13:39:46 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:46 primo volumio[3091]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 11 13:39:46 primo volumio[3091]: info: ------------------------------ 13ms Apr 11 13:39:46 primo volumio[3091]: info: Apr 11 13:39:46 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:46 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:46 primo volumio[3091]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" took 213 milliseconds Apr 11 13:39:46 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 13:39:46 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand play Apr 11 13:39:47 primo volumio[3091]: info: Apr 11 13:39:47 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:47 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:47 primo volumio[3091]: info: ------------------------------ 427ms Apr 11 13:39:47 primo volumio[3091]: info: ------------------------------ 426ms Apr 11 13:39:47 primo volumio[3091]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" took 424 milliseconds Apr 11 13:39:47 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 13:39:47 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand play Apr 11 13:39:47 primo volumio[3091]: info: ------------------------------ 220ms Apr 11 13:39:47 primo volumio[3091]: info: sendMpdCommand play took 218 milliseconds Apr 11 13:39:47 primo volumio[3091]: info: ------------------------------ 5ms Apr 11 13:39:47 primo volumio[3091]: info: sendMpdCommand play took 3 milliseconds Apr 11 13:39:47 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:47.417+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:39:49 primo volumio[3091]: info: Apr 11 13:39:49 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:49 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:49 primo kernel: aml_spdif_open Apr 11 13:39:49 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Apr 11 13:39:49 primo kernel: set normal 512 fs /4 fs Apr 11 13:39:49 primo kernel: set spdifout clk:5644800, mpll:22579200 Apr 11 13:39:49 primo kernel: get spdifout clk:5644797, mpll:22579186 Apr 11 13:39:49 primo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Apr 11 13:39:49 primo kernel: set normal 512 fs /4 fs Apr 11 13:39:49 primo kernel: set spdifout clk:5644800, mpll:22579200 Apr 11 13:39:49 primo kernel: get spdifout clk:5644797, mpll:22579186 Apr 11 13:39:49 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Apr 11 13:39:49 primo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Apr 11 13:39:49 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Apr 11 13:39:49 primo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Apr 11 13:39:49 primo volumio[3091]: info: Apr 11 13:39:49 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:49 primo volumio[3091]: info: sendMpdCommand status took 12 milliseconds Apr 11 13:39:49 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:49 primo volumio[3091]: info: sendMpdCommand status took 2 milliseconds Apr 11 13:39:49 primo volumio[3091]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:49 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:39:49 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:49 primo volumio[3091]: 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":"antenne","artist":"(#1 - 4895/500000) ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:39:49 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:39:49 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:39:49 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus stop Apr 11 13:39:49 primo volumio[3091]: info: ------------------------------ 22ms Apr 11 13:39:49 primo volumio[3091]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:49 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:39:49 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:49 primo volumio[3091]: 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":"antenne","artist":"(#1 - 4895/500000) ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:39:49 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:39:49 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:39:49 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:39:49 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:39:49 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:49 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:49 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:49 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:49 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:49 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:49 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.390+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.391+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.391+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="ANTENNE BAYERN" Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.392+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="ANTENNE BAYERN" Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.393+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.393+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.393+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="ANTENNE BAYERN" Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.393+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="ANTENNE BAYERN" Apr 11 13:39:49 primo volumio[3091]: info: ------------------------------ 59ms Apr 11 13:39:49 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:39:49 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:39:49 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:49 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:49 primo volumio[3091]: info: MCU Signalled Playback Active Apr 11 13:39:49 primo volumio[3091]: info: Apr 11 13:39:49 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:49 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:49 primo volumio[3091]: info: Apr 11 13:39:49 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:49 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:49 primo volumio[3091]: info: ------------------------------ 5ms Apr 11 13:39:49 primo volumio[3091]: info: sendMpdCommand status took 4 milliseconds Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:49 primo volumio[3091]: info: Apr 11 13:39:49 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:49 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:49 primo volumio[3091]: info: Apr 11 13:39:49 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:49 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:49 primo volumio[3091]: info: sendMpdCommand playlistinfo took 9 milliseconds Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:49 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:39:49 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:49 primo volumio[3091]: verbose: STATE SERVICE {"status":"play","position":0,"seek":285,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Myles Smith - Stay (If You Wanna Dance)","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:39:49 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:39:49 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:39:49 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:39:49 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:39:49 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:49 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:49 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:49 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:49 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:49 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.654+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=250 volume=100 Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.654+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=250 volume=100 Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.655+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.655+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.657+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=250 volume=100 Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.657+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=250 volume=100 Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.658+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.658+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:39:49 primo volumio[3091]: info: ------------------------------ 63ms Apr 11 13:39:49 primo volumio[3091]: info: ------------------------------ 54ms Apr 11 13:39:49 primo volumio[3091]: info: sendMpdCommand status took 51 milliseconds Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:49 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:39:49 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:49 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:49 primo volumio[3091]: info: sendMpdCommand playlistinfo took 37 milliseconds Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:49 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:39:49 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:49 primo volumio[3091]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1229,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Myles Smith - Stay (If You Wanna Dance)","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:39:49 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:39:49 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:39:49 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:39:49 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:39:49 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:49 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:49 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:49 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:49 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:49 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:49 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:49 primo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.741+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=331 volume=100 Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.741+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=331 volume=100 Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.741+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.742+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.742+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=331 volume=100 Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.742+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:39:49 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:49.743+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:39:49 primo volumio[3091]: info: ------------------------------ 136ms Apr 11 13:39:49 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:39:49 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:49 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:49 primo volumio[3091]: info: Apr 11 13:39:49 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:49 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:49 primo volumio[3091]: info: Apr 11 13:39:49 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:49 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:49 primo volumio[3091]: info: ------------------------------ 5ms Apr 11 13:39:49 primo volumio[3091]: info: sendMpdCommand status took 3 milliseconds Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:49 primo volumio[3091]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 11 13:39:49 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:50 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:39:50 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:39:50 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:50 primo volumio[3091]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1857,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Myles Smith - Stay (If You Wanna Dance)","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:39:50 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:39:50 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:39:50 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:39:50 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:39:50 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:39:50 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:50 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:39:50 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:50 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:50 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:50 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:50 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:50 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:50 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:50 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:50 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.022+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=581 volume=100 Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.022+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=581 volume=100 Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.022+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.023+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.024+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=581 volume=100 Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.024+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=581 volume=100 Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.028+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.029+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:39:50 primo volumio[3091]: info: ------------------------------ 50ms Apr 11 13:39:50 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:39:50 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:50 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.725+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:39:50 primo volumio[3091]: info: Apr 11 13:39:50 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:39:50 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:39:50 primo volumio[3091]: info: Apr 11 13:39:50 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:39:50 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:39:50 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:39:50 primo volumio[3091]: info: ------------------------------ 4ms Apr 11 13:39:50 primo volumio[3091]: info: sendMpdCommand status took 3 milliseconds Apr 11 13:39:50 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:39:50 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:39:50 primo volumio[3091]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 11 13:39:50 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:39:50 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:39:50 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:39:50 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:39:50 primo volumio[3091]: verbose: STATE SERVICE {"status":"play","position":0,"seek":2607,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Myles Smith - Stay (If You Wanna Dance)","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:39:50 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:39:50 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:39:50 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:39:50 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:39:50 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:39:50 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:50 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:39:50 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:50 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:50 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:50 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:50 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:39:50 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:39:50 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:39:50 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:39:50 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.779+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=1340 volume=100 Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.779+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=1340 volume=100 Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.780+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.780+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.780+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=1340 volume=100 Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.781+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=1340 volume=100 Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.781+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:39:50 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:50.781+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:39:50 primo volumio[3091]: info: ------------------------------ 54ms Apr 11 13:39:50 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:39:50 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:39:50 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:50 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:39:51 primo volumio[3091]: info: Executing endpoint metavolumio Apr 11 13:39:51 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 11 13:39:51 primo volumio[3091]: info: Executing endpoint metavolumio Apr 11 13:39:51 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Apr 11 13:39:53 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:53.831+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=115.912892ms timeout=3s volume=104 Apr 11 13:39:53 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:53.831+08:00 level=ERROR msg="failed to set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=115.912892ms timeout=3s volume=104 error="could not set volume to 104: volume must be between 0 and 100, got 104" Apr 11 13:39:54 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:54.035+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:39:56 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:56.772+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=114.050223ms timeout=3s volume=104 Apr 11 13:39:56 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:56.772+08:00 level=ERROR msg="failed to set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=114.050223ms timeout=3s volume=104 error="could not set volume to 104: volume must be between 0 and 100, got 104" Apr 11 13:39:57 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:57.343+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:39:57 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:57.611+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=114.891944ms timeout=3s volume=109 Apr 11 13:39:57 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:57.611+08:00 level=ERROR msg="failed to set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=114.891944ms timeout=3s volume=109 error="could not set volume to 109: volume must be between 0 and 100, got 109" Apr 11 13:39:57 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:57.910+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=115.929915ms timeout=3s volume=110 Apr 11 13:39:57 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:57.910+08:00 level=ERROR msg="failed to set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=115.929915ms timeout=3s volume=110 error="could not set volume to 110: volume must be between 0 and 100, got 110" Apr 11 13:39:58 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:58.010+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=113.684121ms timeout=3s volume=115 Apr 11 13:39:58 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:58.011+08:00 level=ERROR msg="failed to set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=113.684121ms timeout=3s volume=115 error="could not set volume to 115: volume must be between 0 and 100, got 115" Apr 11 13:39:58 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:58.111+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=113.798447ms timeout=3s volume=114 Apr 11 13:39:58 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:58.111+08:00 level=ERROR msg="failed to set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=113.798447ms timeout=3s volume=114 error="could not set volume to 114: volume must be between 0 and 100, got 114" Apr 11 13:39:58 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:58.212+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=114.141823ms timeout=3s volume=115 Apr 11 13:39:58 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:58.212+08:00 level=ERROR msg="failed to set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=114.141823ms timeout=3s volume=115 error="could not set volume to 115: volume must be between 0 and 100, got 115" Apr 11 13:39:58 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:58.309+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=113.552091ms timeout=3s volume=104 Apr 11 13:39:58 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:58.309+08:00 level=ERROR msg="failed to set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=113.552091ms timeout=3s volume=104 error="could not set volume to 104: volume must be between 0 and 100, got 104" Apr 11 13:39:59 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:59.981+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=113.58958ms timeout=3s volume=105 Apr 11 13:39:59 primo volumio5-onboarding[3759]: time=2026-04-11T13:39:59.981+08:00 level=ERROR msg="failed to set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=113.58958ms timeout=3s volume=105 error="could not set volume to 105: volume must be between 0 and 100, got 105" Apr 11 13:40:00 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:00.654+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:40:03 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:03.959+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:40:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:05.590+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=118.741446ms timeout=3s volume=95 Apr 11 13:40:05 primo volumio[3091]: info: VolumeController::SetAlsaVolume95 Apr 11 13:40:05 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:05 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:40:05 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:05 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:05 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:05 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:05.608+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=16101 volume=100 Apr 11 13:40:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:05.609+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=16101 volume=100 Apr 11 13:40:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:05.609+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:05 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:05.609+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:05 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:05 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:06 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:06.827+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=111.543284ms timeout=3s volume=96 Apr 11 13:40:06 primo volumio[3091]: info: VolumeController::SetAlsaVolume96 Apr 11 13:40:06 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:06 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:40:06 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:06 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:06 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:06 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:06 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:06.841+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=17354 volume=100 Apr 11 13:40:06 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:06.843+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=17354 volume=100 Apr 11 13:40:06 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:06.843+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:06 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:06.844+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:06 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:06 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:07 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:07.265+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:40:07 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:07.489+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=111.596576ms timeout=3s volume=90 Apr 11 13:40:07 primo volumio[3091]: info: VolumeController::SetAlsaVolume90 Apr 11 13:40:07 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:07 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:40:07 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:07 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:07 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:07 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:07 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:07.503+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=18104 volume=100 Apr 11 13:40:07 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:07.504+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=18104 volume=100 Apr 11 13:40:07 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:07.504+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:07 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:07.504+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:07 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:07 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:08 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:08.149+08:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.181:51007 @ 0x1800d80" latency=110.471647ms timeout=3s volume=95 Apr 11 13:40:08 primo volumio[3091]: info: VolumeController::SetAlsaVolume95 Apr 11 13:40:08 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:08 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:40:08 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:08 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:08 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:08 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:08 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:08.163+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=18776 volume=100 Apr 11 13:40:08 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:08.164+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=18776 volume=100 Apr 11 13:40:08 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:08.164+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:08 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:08.165+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:08 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:08 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:09 primo volumio[3091]: info: Preload queue cleared Apr 11 13:40:09 primo volumio[3091]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 11 13:40:09 primo volumio[3091]: info: CoreStateMachine::ClearQueue Apr 11 13:40:09 primo volumio[3091]: info: CoreStateMachine::stop Apr 11 13:40:09 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:40:09 primo volumio[3091]: info: CoreStateMachine::stPlaybackTimer Apr 11 13:40:09 primo volumio[3091]: info: CoreStateMachine::updateTrackBlock Apr 11 13:40:09 primo volumio[3091]: info: CorePlayQueue::getTrackBlock Apr 11 13:40:09 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:09 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:09 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:40:09 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:09 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:09 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:09 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:09 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:09 primo volumio[3091]: info: CoreStateMachine::serviceStop Apr 11 13:40:09 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:09 primo volumio[3091]: info: CoreCommandRouter::serviceStop Apr 11 13:40:09 primo volumio[3091]: info: [1775886009857] ControllerWebradio::stop Apr 11 13:40:09 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 13:40:09 primo volumio[3091]: info: CorePlayQueue::clearPlayQueue Apr 11 13:40:09 primo volumio[3091]: info: CorePlayQueue::saveQueue Apr 11 13:40:09 primo volumio[3091]: info: CoreCommandRouter::volumioPushQueue Apr 11 13:40:09 primo volumio[3091]: info: CoreStateMachine::addQueueItems Apr 11 13:40:09 primo volumio[3091]: info: CorePlayQueue::addQueueItems Apr 11 13:40:09 primo volumio[3091]: info: Preload queue cleared Apr 11 13:40:09 primo volumio[3091]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996 Apr 11 13:40:09 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Apr 11 13:40:09 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:09.861+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_STOPPED positionMs=0 volume=100 Apr 11 13:40:09 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:09.862+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_STOPPED positionMs=0 volume=100 Apr 11 13:40:09 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:09.863+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" title="ANTENNE BAYERN" Apr 11 13:40:09 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:09.863+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" title="ANTENNE BAYERN" Apr 11 13:40:09 primo kernel: asoc-aml-card auge_sound: S/PDIF Playback disable Apr 11 13:40:09 primo kernel: spdif_a keep clk continuous Apr 11 13:40:09 primo kernel: aml_spdif_close Apr 11 13:40:09 primo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Apr 11 13:40:09 primo volumio[3091]: info: CoreCommandRouter::volumioPushQueue Apr 11 13:40:09 primo volumio[3091]: info: CorePlayQueue::saveQueue Apr 11 13:40:09 primo volumio[3091]: info: CoreStateMachine::updateTrackBlock Apr 11 13:40:09 primo volumio[3091]: info: CorePlayQueue::getTrackBlock Apr 11 13:40:09 primo volumio[3091]: info: CoreCommandRouter::volumioPlay Apr 11 13:40:09 primo volumio[3091]: info: CoreStateMachine::play index 0 Apr 11 13:40:09 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:40:09 primo volumio[3091]: info: CoreStateMachine::stop Apr 11 13:40:09 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:40:09 primo volumio[3091]: info: CoreStateMachine::play index undefined Apr 11 13:40:09 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:40:09 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:09 primo volumio[3091]: info: CoreStateMachine::startPlaybackTimer Apr 11 13:40:09 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:09 primo volumio[3091]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 13:40:09 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 13:40:09 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 11 13:40:09 primo volumio[3091]: info: [1775886009889] ControllerWebradio::clearAddPlayTrack Apr 11 13:40:09 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 13:40:09 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:09 primo volumio[3091]: info: Apr 11 13:40:09 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:40:09 primo volumio[3091]: info: sendMpdCommand stop took 53 milliseconds Apr 11 13:40:09 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:40:09 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:40:09 primo volumio[3091]: info: sendMpdCommand stop took 22 milliseconds Apr 11 13:40:09 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 13:40:09 primo volumio[3091]: info: Apr 11 13:40:09 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:40:09 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:40:09 primo volumio[3091]: info: sendMpdCommand status took 4 milliseconds Apr 11 13:40:09 primo volumio[3091]: info: sendMpdCommand clear took 4 milliseconds Apr 11 13:40:09 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:40:09 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:40:09 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" Apr 11 13:40:09 primo volumio[3091]: info: MCU Signalled Playback Inactive Apr 11 13:40:10 primo volumio[3091]: error: updateQueue error: null Apr 11 13:40:10 primo volumio[3091]: info: Apr 11 13:40:10 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:40:10 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:40:10 primo volumio[3091]: info: ------------------------------ 211ms Apr 11 13:40:10 primo volumio[3091]: info: sendMpdCommand playlistinfo took 207 milliseconds Apr 11 13:40:10 primo volumio[3091]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" took 207 milliseconds Apr 11 13:40:10 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:40:10 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 13:40:10 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand play Apr 11 13:40:10 primo volumio[3091]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 11 13:40:10 primo volumio[3091]: info: ------------------------------ 228ms Apr 11 13:40:10 primo volumio[3091]: info: ------------------------------ 28ms Apr 11 13:40:10 primo volumio[3091]: info: sendMpdCommand play took 27 milliseconds Apr 11 13:40:10 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:10.574+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:40:11 primo volumio[3091]: info: Apr 11 13:40:11 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:40:11 primo kernel: aml_spdif_open Apr 11 13:40:11 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:40:11 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Apr 11 13:40:11 primo kernel: set normal 512 fs /4 fs Apr 11 13:40:11 primo kernel: set spdifout clk:5644800, mpll:22579200 Apr 11 13:40:11 primo kernel: get spdifout clk:5644797, mpll:22579186 Apr 11 13:40:11 primo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Apr 11 13:40:11 primo kernel: set normal 512 fs /4 fs Apr 11 13:40:11 primo kernel: set spdifout clk:5644800, mpll:22579200 Apr 11 13:40:11 primo kernel: get spdifout clk:5644797, mpll:22579186 Apr 11 13:40:11 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Apr 11 13:40:11 primo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Apr 11 13:40:11 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Apr 11 13:40:11 primo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Apr 11 13:40:11 primo volumio[3091]: info: Apr 11 13:40:11 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:40:11 primo volumio[3091]: info: sendMpdCommand status took 13 milliseconds Apr 11 13:40:11 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:40:11 primo volumio[3091]: info: sendMpdCommand status took 4 milliseconds Apr 11 13:40:11 primo volumio[3091]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:40:11 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:11 primo volumio[3091]: 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":"antenne","artist":"(#1 - 4908/500000) ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:40:11 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus stop Apr 11 13:40:11 primo volumio[3091]: info: ------------------------------ 37ms Apr 11 13:40:11 primo volumio[3091]: info: sendMpdCommand playlistinfo took 13 milliseconds Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:40:11 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:11 primo volumio[3091]: 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":"antenne","artist":"(#1 - 4908/500000) ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:40:11 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:40:11 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.377+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.378+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.378+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="ANTENNE BAYERN" Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.379+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="ANTENNE BAYERN" Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.380+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.380+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.381+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="ANTENNE BAYERN" Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.381+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="ANTENNE BAYERN" Apr 11 13:40:11 primo volumio[3091]: info: ------------------------------ 70ms Apr 11 13:40:11 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:11 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:11 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:11 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:11 primo volumio[3091]: info: MCU Signalled Playback Active Apr 11 13:40:11 primo volumio[3091]: info: Apr 11 13:40:11 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:40:11 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:40:11 primo volumio[3091]: info: Apr 11 13:40:11 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:40:11 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:40:11 primo volumio[3091]: info: Apr 11 13:40:11 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:40:11 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:40:11 primo volumio[3091]: info: Apr 11 13:40:11 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:40:11 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:40:11 primo volumio[3091]: info: Apr 11 13:40:11 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:40:11 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:40:11 primo volumio[3091]: info: Apr 11 13:40:11 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:40:11 primo volumio[3091]: info: ------------------------------ 13ms Apr 11 13:40:11 primo volumio[3091]: info: sendMpdCommand status took 12 milliseconds Apr 11 13:40:11 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:40:11 primo volumio[3091]: info: ------------------------------ 12ms Apr 11 13:40:11 primo volumio[3091]: info: sendMpdCommand status took 11 milliseconds Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:40:11 primo volumio[3091]: info: ------------------------------ 17ms Apr 11 13:40:11 primo volumio[3091]: info: sendMpdCommand status took 14 milliseconds Apr 11 13:40:11 primo volumio[3091]: info: sendMpdCommand playlistinfo took 13 milliseconds Apr 11 13:40:11 primo volumio[3091]: info: sendMpdCommand playlistinfo took 12 milliseconds Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:40:11 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:11 primo volumio[3091]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1059,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Myles Smith - Stay (If You Wanna Dance)","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:40:11 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:40:11 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:11 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:11 primo volumio[3091]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1071,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Myles Smith - Stay (If You Wanna Dance)","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:40:11 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:40:11 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.646+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=250 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.646+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=250 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.647+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.648+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.649+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=250 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.650+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=250 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.650+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=250 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.650+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.650+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.651+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=250 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.652+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.652+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.655+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=250 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.656+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=250 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.657+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.657+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:11 primo volumio[3091]: info: ------------------------------ 104ms Apr 11 13:40:11 primo volumio[3091]: info: ------------------------------ 102ms Apr 11 13:40:11 primo volumio[3091]: info: sendMpdCommand playlistinfo took 80 milliseconds Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:40:11 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:11 primo volumio[3091]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1231,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Myles Smith - Stay (If You Wanna Dance)","artist":"ANTENNE BAYERN","album":null,"uri":"http://stream.antenne.de:80/antenne","trackType":""} Apr 11 13:40:11 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:40:11 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:11 primo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.714+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=484 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.714+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=484 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.715+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.715+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.716+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_PLAYING positionMs=484 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.717+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=484 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.717+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.720+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=http://stream.antenne.de:80/antenne title="Myles Smith - Stay (If You Wanna Dance)" Apr 11 13:40:11 primo volumio[3091]: info: ------------------------------ 145ms Apr 11 13:40:11 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:11 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:11 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:11 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:11 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:11 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:11 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:11 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:11 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:11 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:11 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:11 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:11 primo volumio[3091]: info: Preload queue cleared Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioReplaceandPlayItems Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::ClearQueue Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::stop Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::stPlaybackTimer Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::updateTrackBlock Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::getTrackBlock Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:11 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::serviceStop Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::serviceStop Apr 11 13:40:11 primo volumio[3091]: info: [1775886011900] ControllerWebradio::stop Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::clearPlayQueue Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::saveQueue Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioPushQueue Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::addQueueItems Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::addQueueItems Apr 11 13:40:11 primo volumio[3091]: info: Preload queue cleared Apr 11 13:40:11 primo volumio[3091]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99568320 Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.905+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" state=STATUS_STOPPED positionMs=0 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.905+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_STOPPED positionMs=0 volume=100 Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.908+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842,00:00:00:00:00:00%01 @ 0x19b6b70" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" title="ANTENNE BAYERN" Apr 11 13:40:11 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:11.910+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99497996" title="ANTENNE BAYERN" Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioPushQueue Apr 11 13:40:11 primo kernel: asoc-aml-card auge_sound: S/PDIF Playback disable Apr 11 13:40:11 primo kernel: spdif_a keep clk continuous Apr 11 13:40:11 primo kernel: aml_spdif_close Apr 11 13:40:11 primo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::saveQueue Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::updateTrackBlock Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::getTrackBlock Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioPlay Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::play index 0 Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::stop Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::play index undefined Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:11 primo volumio[3091]: info: CoreStateMachine::startPlaybackTimer Apr 11 13:40:11 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::volumioGetVisibleSources Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 11 13:40:11 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 11 13:40:11 primo volumio[3091]: info: [1775886011931] ControllerWebradio::clearAddPlayTrack Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand stop Apr 11 13:40:11 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:11 primo volumio[3091]: info: Apr 11 13:40:11 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:40:11 primo volumio[3091]: info: sendMpdCommand stop took 59 milliseconds Apr 11 13:40:11 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:40:11 primo volumio[3091]: info: sendMpdCommand stop took 29 milliseconds Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand clear Apr 11 13:40:11 primo volumio[3091]: info: Apr 11 13:40:11 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:40:11 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:40:11 primo volumio[3091]: info: sendMpdCommand status took 9 milliseconds Apr 11 13:40:11 primo volumio[3091]: info: sendMpdCommand clear took 9 milliseconds Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99568320" Apr 11 13:40:11 primo volumio[3091]: error: updateQueue error: null Apr 11 13:40:11 primo volumio[3091]: info: ------------------------------ 15ms Apr 11 13:40:11 primo volumio[3091]: info: sendMpdCommand playlistinfo took 11 milliseconds Apr 11 13:40:11 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:40:11 primo volumio[3091]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Apr 11 13:40:11 primo volumio[3091]: info: ------------------------------ 27ms Apr 11 13:40:11 primo volumio[3091]: info: MCU Signalled Playback Inactive Apr 11 13:40:12 primo volumio[3091]: info: Apr 11 13:40:12 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:40:12 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:40:12 primo volumio[3091]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99568320" took 279 milliseconds Apr 11 13:40:12 primo volumio[3091]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 11 13:40:12 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand play Apr 11 13:40:12 primo volumio[3091]: info: ------------------------------ 11ms Apr 11 13:40:12 primo volumio[3091]: info: sendMpdCommand play took 5 milliseconds Apr 11 13:40:13 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:13.891+08:00 level=WARN msg="pending write exceeded maximum retries, dropping" component=ble/conn Apr 11 13:40:14 primo kernel: aml_spdif_open Apr 11 13:40:14 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:spdif@0 Apr 11 13:40:14 primo kernel: set normal 512 fs /4 fs Apr 11 13:40:14 primo kernel: set spdifout clk:5644800, mpll:22579200 Apr 11 13:40:14 primo kernel: get spdifout clk:5644797, mpll:22579186 Apr 11 13:40:14 primo kernel: aml_dai_set_spdif_fmt , fmt 0x4000 Apr 11 13:40:14 primo kernel: set normal 512 fs /4 fs Apr 11 13:40:14 primo kernel: set spdifout clk:5644800, mpll:22579200 Apr 11 13:40:14 primo kernel: get spdifout clk:5644797, mpll:22579186 Apr 11 13:40:14 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Apr 11 13:40:14 primo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Apr 11 13:40:14 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Apr 11 13:40:14 primo kernel: aml_spdif_fifo_ctrl, bit depth:16, frddr type:1, toddr:type:1 Apr 11 13:40:14 primo volumio[3091]: info: Apr 11 13:40:14 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:40:14 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:40:14 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:40:14 primo volumio[3091]: info: Apr 11 13:40:14 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:40:14 primo volumio[3091]: info: sendMpdCommand status took 7 milliseconds Apr 11 13:40:14 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:40:14 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:40:14 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:40:14 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:40:14 primo volumio[3091]: info: sendMpdCommand status took 3 milliseconds Apr 11 13:40:14 primo volumio[3091]: info: sendMpdCommand playlistinfo took 2 milliseconds Apr 11 13:40:14 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:40:14 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:40:14 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:40:14 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:40:14 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:14 primo volumio[3091]: 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":"dance.mp3","artist":"(#1 - 5518/32000) Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 11 13:40:14 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:40:14 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:40:14 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus stop Apr 11 13:40:14 primo volumio[3091]: info: ------------------------------ 17ms Apr 11 13:40:14 primo volumio[3091]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 11 13:40:14 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:40:14 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:40:14 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:14 primo volumio[3091]: 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":"dance.mp3","artist":"(#1 - 5518/32000) Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 11 13:40:14 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:40:14 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:40:14 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:40:14 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:40:14 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:14 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:14 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:14 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:14 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:14 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:14 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.141+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.142+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.142+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=https://dancewave.online:443/dance.mp3 title="Dance Wave!" Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.142+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=https://dancewave.online:443/dance.mp3 title="Dance Wave!" Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.144+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.144+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=0 volume=100 Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.144+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=https://dancewave.online:443/dance.mp3 title="Dance Wave!" Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.145+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=https://dancewave.online:443/dance.mp3 title="Dance Wave!" Apr 11 13:40:14 primo volumio[3091]: info: ------------------------------ 43ms Apr 11 13:40:14 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:14 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:14 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:14 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:14 primo volumio[3091]: info: MCU Signalled Playback Active Apr 11 13:40:14 primo volumio[3091]: info: Apr 11 13:40:14 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:40:14 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:40:14 primo volumio[3091]: info: Apr 11 13:40:14 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:40:14 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:40:14 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:40:14 primo volumio[3091]: info: ------------------------------ 4ms Apr 11 13:40:14 primo volumio[3091]: info: sendMpdCommand status took 3 milliseconds Apr 11 13:40:14 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:40:14 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:40:14 primo volumio[3091]: info: sendMpdCommand playlistinfo took 1 milliseconds Apr 11 13:40:14 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:40:14 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:40:14 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:14 primo volumio[3091]: verbose: STATE SERVICE {"status":"play","position":0,"seek":125,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"dance.mp3","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 11 13:40:14 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:40:14 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:40:14 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:40:14 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:40:14 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:14 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:14 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:14 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:14 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:14 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:14 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.465+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=249 volume=100 Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.466+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=249 volume=100 Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.466+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=https://dancewave.online:443/dance.mp3 title="Dance Wave!" Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.467+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=https://dancewave.online:443/dance.mp3 title="Dance Wave!" Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.468+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=249 volume=100 Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.470+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=249 volume=100 Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.471+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=https://dancewave.online:443/dance.mp3 title="Dance Wave!" Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.471+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=https://dancewave.online:443/dance.mp3 title="Dance Wave!" Apr 11 13:40:14 primo volumio[3091]: info: ------------------------------ 69ms Apr 11 13:40:14 primo volumio[3091]: info: Apr 11 13:40:14 primo volumio[3091]: ---------------------------- MPD announces system playlist update Apr 11 13:40:14 primo volumio[3091]: info: Ignoring MPD Status Update Apr 11 13:40:14 primo volumio[3091]: info: Apr 11 13:40:14 primo volumio[3091]: ---------------------------- MPD announces state update: player Apr 11 13:40:14 primo volumio[3091]: info: ControllerMpd::getState Apr 11 13:40:14 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand status Apr 11 13:40:14 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:14 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:14 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:14 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:14 primo volumio[3091]: info: ------------------------------ 44ms Apr 11 13:40:14 primo volumio[3091]: info: sendMpdCommand status took 42 milliseconds Apr 11 13:40:14 primo volumio[3091]: verbose: ControllerMpd::parseState Apr 11 13:40:14 primo volumio[3091]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 11 13:40:14 primo kernel: asoc-aml-card auge_sound: S/PDIF Playback enable Apr 11 13:40:14 primo volumio[3091]: info: sendMpdCommand playlistinfo took 21 milliseconds Apr 11 13:40:14 primo volumio[3091]: verbose: ControllerMpd::parseTrackInfo Apr 11 13:40:14 primo volumio[3091]: info: ControllerMpd::pushState Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::servicePushState Apr 11 13:40:14 primo volumio[3091]: info: CorePlayQueue::getTrack 0 Apr 11 13:40:14 primo volumio[3091]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1363,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"All about Dance from 2000 till today!","artist":"Dance Wave!","album":null,"uri":"https://dancewave.online:443/dance.mp3","trackType":"mp3"} Apr 11 13:40:14 primo volumio[3091]: verbose: CURRENT POSITION 0 Apr 11 13:40:14 primo volumio[3091]: info: CoreStateMachine::syncState stateService play Apr 11 13:40:14 primo volumio[3091]: info: CoreStateMachine::syncState currentStatus play Apr 11 13:40:14 primo volumio[3091]: info: Received an update from plugin. extracting info from payload Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Apr 11 13:40:14 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:14 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:14 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:14 primo volumio[3091]: info: CoreStateMachine::pushState Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::volumioPushState Apr 11 13:40:14 primo volumio[3091]: info: CoreCommandRouter::volumioGetState Apr 11 13:40:14 primo volumio[3091]: info: MRS: Pushing multiroomSync output update for this device Apr 11 13:40:14 primo volumio[3091]: info: MRS: Pushing multiroomSync output Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.596+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=519 volume=100 Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.596+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=519 volume=100 Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.596+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=https://dancewave.online:443/dance.mp3 title="All about Dance from 2000 till today!" Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.597+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=https://dancewave.online:443/dance.mp3 title="All about Dance from 2000 till today!" Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.597+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" state=STATUS_PLAYING positionMs=519 volume=100 Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.597+08:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" state=STATUS_PLAYING positionMs=519 volume=100 Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.597+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.239:59842 @ 0x19b6b70" id=https://dancewave.online:443/dance.mp3 title="All about Dance from 2000 till today!" Apr 11 13:40:14 primo volumio5-onboarding[3759]: time=2026-04-11T13:40:14.598+08:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.181:51007 @ 0x1800d80" id=https://dancewave.online:443/dance.mp3 title="All about Dance from 2000 till today!" Apr 11 13:40:14 primo volumio[3091]: info: ------------------------------ 113ms Apr 11 13:40:14 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:14 primo volumio[3091]: info: Signalling Playback active due to playback status change Apr 11 13:40:14 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:14 primo volumio[3091]: info: Updating RAAT Signal Path Apr 11 13:40:16 primo volumio[3091]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 13:40:16 primo volumio[3091]: TypeError: Cannot read property 'slice' of null Apr 11 13:40:16 primo volumio[3091]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Apr 11 13:40:16 primo volumio[3091]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Apr 11 13:40:16 primo volumio[3091]: at Object.onceWrapper (events.js:520:26) Apr 11 13:40:16 primo volumio[3091]: at ClientRequest.emit (events.js:400:28) Apr 11 13:40:16 primo volumio[3091]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:647:27) Apr 11 13:40:16 primo volumio[3091]: at HTTPParser.parserOnHeadersComplete (_http_common.js:127:17) Apr 11 13:40:16 primo volumio[3091]: at TLSSocket.socketOnData (_http_client.js:515:22) Apr 11 13:40:16 primo volumio[3091]: at TLSSocket.emit (events.js:400:28) Apr 11 13:40:16 primo volumio[3091]: at addChunk (internal/streams/readable.js:293:12) Apr 11 13:40:16 primo volumio[3091]: at readableAddChunk (internal/streams/readable.js:267:9) Apr 11 13:40:16 primo volumio[3091]: at TLSSocket.Readable.push (internal/streams/readable.js:206:10) Apr 11 13:40:16 primo volumio[3091]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:188:23) Apr 11 13:40:16 primo volumio[3091]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 11 13:40:16 primo sudo[17221]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-04-11 13:39 Apr 11 13:40:16 primo sudo[17221]: 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="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 12:16:07 PM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="88686576587e39571d6cf25f3920fbc0"