May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: Preload queue cleared May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioReplaceandPlayItems May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::ClearQueue May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::stop May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::stPlaybackTimer May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::updateTrackBlock May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrackBlock May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::serviceStop May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::serviceStop May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: [1780166460637] ControllerWebradio::stop May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand stop May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::clearPlayQueue May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::saveQueue May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushQueue May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::addQueueItems May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::addQueueItems May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: Preload queue cleared May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: Adding Item to queue: https://radiostream.pl/tuba9006-1.mp3 May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 30 20:41:00 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:00.641Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:41:00 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:00.641Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:41:00 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:00.642Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=https://media.wnet.fm/wnet.fm title="Radio Wnet" May 30 20:41:00 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:00.642Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=https://media.wnet.fm/wnet.fm title="Radio Wnet" May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushQueue May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::saveQueue May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::updateTrackBlock May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrackBlock May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPlay May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::play index 0 May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::stop May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::play index undefined May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::startPlaybackTimer May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: [1780166460651] ControllerWebradio::clearAddPlayTrack May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand stop May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand stop took 28 milliseconds May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand stop took 15 milliseconds May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand clear May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 3 milliseconds May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand clear took 3 milliseconds May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 2 milliseconds May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand load "https://radiostream.pl/tuba9006-1.mp3" May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd May 30 20:41:00 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:00.678Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:41:00 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:00.679Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:41:00 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:00.679Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=https://radiostream.pl/tuba9006-1.mp3 title="Rock Radio" May 30 20:41:00 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:00.680Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=https://radiostream.pl/tuba9006-1.mp3 title="Rock Radio" May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 12ms May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: error: updateQueue error: null May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 13ms May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 11 milliseconds May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 18ms May 30 20:41:00 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:01 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand add "https://radiostream.pl/tuba9006-1.mp3" May 30 20:41:01 mcpiv-rpi-volumio volumio[1253]: error: updateQueue error: null May 30 20:41:01 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:01 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:01 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:01 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 747ms May 30 20:41:01 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand add "https://radiostream.pl/tuba9006-1.mp3" took 1 milliseconds May 30 20:41:01 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 20:41:01 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand play May 30 20:41:01 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:01 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:01 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:01 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 6ms May 30 20:41:01 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand play took 5 milliseconds May 30 20:41:01 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 2ms May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 21 milliseconds May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 19 milliseconds May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 11 milliseconds May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 11 milliseconds May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"11.025 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"tuba9006-1.mp3","artist":null,"album":null,"uri":"https://radiostream.pl/tuba9006-1.mp3","trackType":"mp3"} May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: CURRENT POSITION 0 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState stateService play May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState currentStatus stop May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"tuba9006-1.mp3","artist":null,"album":null,"uri":"https://radiostream.pl/tuba9006-1.mp3","trackType":"mp3"} May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: CURRENT POSITION 0 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState stateService stop May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState currentStatus play May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::play index undefined May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 42ms May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.254Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=0 volume=100 May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.254Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs= volume=100 May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.256Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs= volume=100 May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.257Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=https://radiostream.pl/tuba9006-1.mp3 title="Rock Radio" May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.257Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=https://radiostream.pl/tuba9006-1.mp3 title="Rock Radio" May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::startPlaybackTimer May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: [1780166462258] ControllerWebradio::clearAddPlayTrack May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand stop May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 47ms May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.259Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=0 volume=100 May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.259Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=https://media.wnet.fm/wnet.fm title="Radio Wnet" May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.260Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=https://media.wnet.fm/wnet.fm title="Radio Wnet" May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.265Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.265Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.266Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=https://radiostream.pl/tuba9006-1.mp3 title="Rock Radio" May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.266Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=https://radiostream.pl/tuba9006-1.mp3 title="Rock Radio" May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 30 milliseconds May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 24 milliseconds May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 25 milliseconds May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand stop took 11 milliseconds May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 3 milliseconds May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand clear May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.284Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs=8 volume=100 May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.285Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs=8 volume=100 May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.285Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=https://radiostream.pl/tuba9006-1.mp3 title="Rock Radio" May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.285Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=https://radiostream.pl/tuba9006-1.mp3 title="Rock Radio" May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.286Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs=8 volume=100 May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.286Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs=8 volume=100 May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.287Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=https://radiostream.pl/tuba9006-1.mp3 title="Rock Radio" May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.287Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=https://radiostream.pl/tuba9006-1.mp3 title="Rock Radio" May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.288Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs=8 volume=100 May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.288Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs=8 volume=100 May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.288Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=https://radiostream.pl/tuba9006-1.mp3 title="Rock Radio" May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.289Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=https://radiostream.pl/tuba9006-1.mp3 title="Rock Radio" May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.289Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs=8 volume=100 May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.290Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs=8 volume=100 May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.290Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=https://radiostream.pl/tuba9006-1.mp3 title="Rock Radio" May 30 20:41:02 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:02.290Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=https://radiostream.pl/tuba9006-1.mp3 title="Rock Radio" May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 53ms May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 51ms May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 48ms May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 26ms May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: error: updateQueue error: null May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand clear took 41 milliseconds May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 2ms May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand load "https://radiostream.pl/tuba9006-1.mp3" May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: error: updateQueue error: null May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 4ms May 30 20:41:02 mcpiv-rpi-volumio volumio[1253]: info: Discovery: Restarting Browsing May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand add "https://radiostream.pl/tuba9006-1.mp3" May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand add "https://radiostream.pl/tuba9006-1.mp3" took 2 milliseconds May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand play May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 5ms May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand play took 4 milliseconds May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 2ms May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 17 milliseconds May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 17 milliseconds May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 5 milliseconds May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 5 milliseconds May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 4 milliseconds May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"THE CARS / YOU MIGHT THINK","artist":"Rock Radio Warszawa","album":null,"uri":"https://radiostream.pl/tuba9006-1.mp3","trackType":"mp3"} May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: CURRENT POSITION 0 May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState stateService play May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState currentStatus stop May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: STATE SERVICE {"status":"play","position":0,"seek":664,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"THE CARS / YOU MIGHT THINK","artist":"Rock Radio Warszawa","album":null,"uri":"https://radiostream.pl/tuba9006-1.mp3","trackType":"mp3"} May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: CURRENT POSITION 0 May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState stateService play May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState currentStatus play May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: Received an update from plugin. extracting info from payload May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 34ms May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.927Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=0 volume=100 May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.927Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=0 volume=100 May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.928Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=https://radiostream.pl/tuba9006-1.mp3 title="THE CARS / YOU MIGHT THINK" May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.928Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=https://radiostream.pl/tuba9006-1.mp3 title="THE CARS / YOU MIGHT THINK" May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.929Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=0 volume=100 May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.931Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=0 volume=100 May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.931Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=https://radiostream.pl/tuba9006-1.mp3 title="THE CARS / YOU MIGHT THINK" May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.932Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=https://radiostream.pl/tuba9006-1.mp3 title="THE CARS / YOU MIGHT THINK" May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 40ms May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 20 milliseconds May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 21ms May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 22 milliseconds May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"THE CARS / YOU MIGHT THINK","artist":"Rock Radio Warszawa","album":null,"uri":"https://radiostream.pl/tuba9006-1.mp3","trackType":"mp3"} May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: CURRENT POSITION 0 May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState stateService play May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState currentStatus play May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: Received an update from plugin. extracting info from payload May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.951Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=0 volume=100 May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.953Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=0 volume=100 May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.954Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=0 volume=100 May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 45ms May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.955Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=0 volume=100 May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.956Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=https://radiostream.pl/tuba9006-1.mp3 title="THE CARS / YOU MIGHT THINK" May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.956Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=https://radiostream.pl/tuba9006-1.mp3 title="THE CARS / YOU MIGHT THINK" May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.959Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=https://radiostream.pl/tuba9006-1.mp3 title="THE CARS / YOU MIGHT THINK" May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.960Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=https://radiostream.pl/tuba9006-1.mp3 title="THE CARS / YOU MIGHT THINK" May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 26 milliseconds May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 12ms May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: STATE SERVICE {"status":"play","position":0,"seek":871,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"THE CARS / YOU MIGHT THINK","artist":"Rock Radio Warszawa","album":null,"uri":"https://radiostream.pl/tuba9006-1.mp3","trackType":"mp3"} May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: verbose: CURRENT POSITION 0 May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState stateService play May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState currentStatus play May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: Received an update from plugin. extracting info from payload May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.974Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=63 volume=100 May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.974Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=63 volume=100 May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.974Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=63 volume=100 May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.974Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=63 volume=100 May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.975Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=https://radiostream.pl/tuba9006-1.mp3 title="THE CARS / YOU MIGHT THINK" May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.975Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=https://radiostream.pl/tuba9006-1.mp3 title="THE CARS / YOU MIGHT THINK" May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.975Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=https://radiostream.pl/tuba9006-1.mp3 title="THE CARS / YOU MIGHT THINK" May 30 20:41:03 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:03.975Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=https://radiostream.pl/tuba9006-1.mp3 title="THE CARS / YOU MIGHT THINK" May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 63ms May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:03 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: Preload queue cleared May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioReplaceandPlayItems May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::ClearQueue May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::stop May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::stPlaybackTimer May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::updateTrackBlock May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrackBlock May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::serviceStop May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::serviceStop May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: [1780166465119] ControllerWebradio::stop May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand stop May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::clearPlayQueue May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::saveQueue May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushQueue May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::addQueueItems May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::addQueueItems May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: Preload queue cleared May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: Adding Item to queue: http://stream9.nadaje.com:8002/live May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 30 20:41:05 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:05.125Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:41:05 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:05.126Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:41:05 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:05.126Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=https://radiostream.pl/tuba9006-1.mp3 title="Rock Radio" May 30 20:41:05 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:05.127Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=https://radiostream.pl/tuba9006-1.mp3 title="Rock Radio" May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushQueue May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::saveQueue May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::updateTrackBlock May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrackBlock May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPlay May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::play index 0 May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::stop May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::play index undefined May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::startPlaybackTimer May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: [1780166465136] ControllerWebradio::clearAddPlayTrack May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand stop May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand stop took 29 milliseconds May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand stop took 16 milliseconds May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand clear May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 4 milliseconds May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand clear took 3 milliseconds May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand load "http://stream9.nadaje.com:8002/live" May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: error: updateQueue error: null May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 5 milliseconds May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 4ms May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 2 milliseconds May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 30 20:41:05 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:05.167Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs=20 volume=100 May 30 20:41:05 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:05.168Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs=20 volume=100 May 30 20:41:05 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:05.168Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=http://stream9.nadaje.com:8002/live title=Rockserwis.fm May 30 20:41:05 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:05.169Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=http://stream9.nadaje.com:8002/live title=Rockserwis.fm May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 16ms May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 20ms May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand add "http://stream9.nadaje.com:8002/live" May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: error: updateQueue error: null May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 442ms May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand add "http://stream9.nadaje.com:8002/live" took 3 milliseconds May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand play May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 8ms May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand play took 7 milliseconds May 30 20:41:05 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 7ms May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 19 milliseconds May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 31 milliseconds May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 11 milliseconds May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 9 milliseconds May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"live","artist":null,"album":null,"uri":"http://stream9.nadaje.com:8002/live","trackType":""} May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: CURRENT POSITION 0 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState stateService play May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState currentStatus stop May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 39ms May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 13 milliseconds May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 23ms May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 18 milliseconds May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 22ms May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 17 milliseconds May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 16 milliseconds May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 15 milliseconds May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 13ms May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 13 milliseconds May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 7 milliseconds May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"DOCTOR, DOCTOR - - 30/05/26","artist":"Rockserwis.fm [mp3]","album":null,"uri":"http://stream9.nadaje.com:8002/live","trackType":""} May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: CURRENT POSITION 0 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState stateService play May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState currentStatus play May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: Received an update from plugin. extracting info from payload May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: STATE SERVICE {"status":"play","position":0,"seek":987,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"DOCTOR, DOCTOR - - 30/05/26","artist":"Rockserwis.fm [mp3]","album":null,"uri":"http://stream9.nadaje.com:8002/live","trackType":""} May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: CURRENT POSITION 0 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState stateService play May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState currentStatus play May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: Received an update from plugin. extracting info from payload May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: STATE SERVICE {"status":"play","position":0,"seek":987,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"DOCTOR, DOCTOR - - 30/05/26","artist":"Rockserwis.fm [mp3]","album":null,"uri":"http://stream9.nadaje.com:8002/live","trackType":""} May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: CURRENT POSITION 0 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState stateService play May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState currentStatus play May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: Received an update from plugin. extracting info from payload May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.204Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=34 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.204Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=34 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.205Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.205Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.205Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=34 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.206Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=34 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.206Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.206Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.207Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=34 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.207Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=34 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.207Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=34 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.208Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.208Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.208Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=34 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.207Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=34 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.209Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.209Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=34 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.209Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=34 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.209Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=34 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.210Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.210Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.210Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.210Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.210Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 94ms May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 73ms May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 71ms May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 46 milliseconds May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 47 milliseconds May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 46 milliseconds May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: STATE SERVICE {"status":"play","position":0,"seek":987,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"DOCTOR, DOCTOR - - 30/05/26","artist":"Rockserwis.fm [mp3]","album":null,"uri":"http://stream9.nadaje.com:8002/live","trackType":""} May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: CURRENT POSITION 0 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState stateService play May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState currentStatus play May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: Received an update from plugin. extracting info from payload May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: STATE SERVICE {"status":"play","position":0,"seek":987,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"DOCTOR, DOCTOR - - 30/05/26","artist":"Rockserwis.fm [mp3]","album":null,"uri":"http://stream9.nadaje.com:8002/live","trackType":""} May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: CURRENT POSITION 0 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState stateService play May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState currentStatus play May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: Received an update from plugin. extracting info from payload May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: STATE SERVICE {"status":"play","position":0,"seek":987,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"DOCTOR, DOCTOR - - 30/05/26","artist":"Rockserwis.fm [mp3]","album":null,"uri":"http://stream9.nadaje.com:8002/live","trackType":""} May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: verbose: CURRENT POSITION 0 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState stateService play May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState currentStatus play May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: Received an update from plugin. extracting info from payload May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.248Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=90 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.249Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=90 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.249Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.250Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.251Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=90 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.251Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=90 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.252Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.252Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.253Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=90 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.253Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=90 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.254Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.254Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.255Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=90 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 100ms May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.256Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=90 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.256Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 99ms May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.256Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.257Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=90 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 91ms May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.258Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=90 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.258Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.259Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.250Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_PLAYING positionMs=90 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.260Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_PLAYING positionMs=90 volume=100 May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.260Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:41:06.261Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=http://stream9.nadaje.com:8002/live title="DOCTOR, DOCTOR - - 30/05/26" May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:06 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:41:07 mcpiv-rpi-volumio volumio[1253]: info: Discovery: Restarting Browsing May 30 20:41:10 mcpiv-rpi-volumio volumio[1253]: info: Saving local item radio-favourites May 30 20:41:10 mcpiv-rpi-volumio volumio[1253]: info: Pushing Favourites {"uri":"http://stream9.nadaje.com:8002/live","favourite":false} May 30 20:41:12 mcpiv-rpi-volumio volumio[1253]: info: Discovery: Restarting Browsing May 30 20:41:12 mcpiv-rpi-volumio volumio[1253]: info: Saving local item radio-favourites May 30 20:41:12 mcpiv-rpi-volumio volumio[1253]: info: Pushing Favourites {"uri":"https://radiostream.pl/tuba9006-1.mp3","favourite":false} May 30 20:41:14 mcpiv-rpi-volumio volumio[1253]: info: Saving local item radio-favourites May 30 20:41:14 mcpiv-rpi-volumio volumio[1253]: info: Pushing Favourites {"uri":"https://media.wnet.fm/wnet.fm","favourite":false} May 30 20:41:16 mcpiv-rpi-volumio volumio[1253]: info: Saving local item radio-favourites May 30 20:41:16 mcpiv-rpi-volumio volumio[1253]: info: Pushing Favourites {"uri":"http://sc8.radiocaroline.net/","favourite":false} May 30 20:41:17 mcpiv-rpi-volumio volumio[1253]: info: Discovery: Restarting Browsing May 30 20:41:17 mcpiv-rpi-volumio volumio[1253]: info: Saving local item radio-favourites May 30 20:41:17 mcpiv-rpi-volumio volumio[1253]: info: Pushing Favourites {"uri":"https://n-11-26.dcs.redcdn.pl/sc/o2/radio357/live/radio357_pr.livx?preroll=0","favourite":false} May 30 20:41:19 mcpiv-rpi-volumio volumio[1253]: info: Saving local item radio-favourites May 30 20:41:19 mcpiv-rpi-volumio volumio[1253]: info: Pushing Favourites {"uri":"https://an.cdn.eurozet.pl/ant-waw.mp3","favourite":false} May 30 20:41:21 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri May 30 20:41:21 mcpiv-rpi-volumio volumio[1253]: info: Preload queue cleared May 30 20:41:22 mcpiv-rpi-volumio go-librespot[4091]: time="2026-05-30T20:41:22+02:00" level=trace msg="sent dealer ping" May 30 20:41:22 mcpiv-rpi-volumio volumio[1253]: info: Discovery: Restarting Browsing May 30 20:41:22 mcpiv-rpi-volumio go-librespot[4091]: time="2026-05-30T20:41:22+02:00" level=trace msg="received dealer pong" May 30 20:41:27 mcpiv-rpi-volumio volumio[1253]: info: Discovery: Restarting Browsing May 30 20:41:29 mcpiv-rpi-volumio volumio[1253]: info: Removing uri https://n-11-26.dcs.redcdn.pl/sc/o2/radio357/live/radio357_pr.livx?preroll=0 from favourites May 30 20:41:29 mcpiv-rpi-volumio volumio[1253]: info: Saving local item radio-favourites May 30 20:41:32 mcpiv-rpi-volumio volumio[1253]: info: Discovery: Restarting Browsing May 30 20:41:36 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri May 30 20:41:36 mcpiv-rpi-volumio volumio[1253]: info: Preload queue cleared May 30 20:41:37 mcpiv-rpi-volumio volumio[1253]: info: Discovery: Restarting Browsing May 30 20:41:42 mcpiv-rpi-volumio volumio[1253]: info: Discovery: Restarting Browsing May 30 20:41:47 mcpiv-rpi-volumio volumio[1253]: info: Discovery: Restarting Browsing May 30 20:41:52 mcpiv-rpi-volumio go-librespot[4091]: time="2026-05-30T20:41:52+02:00" level=trace msg="received accesspoint ping" May 30 20:41:52 mcpiv-rpi-volumio go-librespot[4091]: time="2026-05-30T20:41:52+02:00" level=trace msg="received accesspoint pong ack" May 30 20:41:52 mcpiv-rpi-volumio go-librespot[4091]: time="2026-05-30T20:41:52+02:00" level=trace msg="sent dealer ping" May 30 20:41:52 mcpiv-rpi-volumio volumio[1253]: info: Discovery: Restarting Browsing May 30 20:41:52 mcpiv-rpi-volumio go-librespot[4091]: time="2026-05-30T20:41:52+02:00" level=trace msg="received dealer pong" May 30 20:41:57 mcpiv-rpi-volumio volumio[1253]: info: Discovery: Restarting Browsing May 30 20:42:02 mcpiv-rpi-volumio volumio[1253]: info: Discovery: Restarting Browsing May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: Preload queue cleared May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioReplaceandPlayItems May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::ClearQueue May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::stop May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::stPlaybackTimer May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::updateTrackBlock May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrackBlock May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::serviceStop May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::serviceStop May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: [1780166524785] ControllerWebradio::stop May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand stop May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::clearPlayQueue May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::saveQueue May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushQueue May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::addQueueItems May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::addQueueItems May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: Preload queue cleared May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s116012 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.790Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.790Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.791Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id=http://stream9.nadaje.com:8002/live title=Rockserwis.fm May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.791Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id=http://stream9.nadaje.com:8002/live title=Rockserwis.fm May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand stop took 49 milliseconds May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces state update: player May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::getState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand status May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 7 milliseconds May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand status took 6 milliseconds May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 2 milliseconds May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand playlistinfo took 2 milliseconds May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::parseTrackInfo May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"DOCTOR, DOCTOR - - 30/05/26","artist":"Rockserwis.fm [mp3]","album":null,"uri":"http://stream9.nadaje.com:8002/live","trackType":""} May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: verbose: CURRENT POSITION 0 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState stateService stop May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState currentStatus stop May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: No code May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:42:04 mcpiv-rpi-volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: ControllerMpd::pushState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::servicePushState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"DOCTOR, DOCTOR - - 30/05/26","artist":"Rockserwis.fm [mp3]","album":null,"uri":"http://stream9.nadaje.com:8002/live","trackType":""} May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: verbose: CURRENT POSITION 0 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState stateService stop May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::syncState currentStatus stop May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: No code May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::pushState May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushState May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.860Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.861Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.862Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id= title= May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.862Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id= title= May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.863Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.865Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.866Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.866Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id= title= May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.867Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id= title= May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.868Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.869Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.869Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id= title= May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.870Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id= title= May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.864Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.871Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.871Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 39ms May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.873Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id= title= May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.874Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id= title= May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.874Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.874Z level=INFO msg="emitting player state changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" state=STATUS_STOPPED positionMs=0 volume=100 May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.875Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id= title= May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.875Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id= title= May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.876Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.1.115:55210 @ 0x1dfe570" id= title= May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 40ms May 30 20:42:04 mcpiv-rpi-volumio volumio5-onboarding[1797]: time=2026-05-30T18:42:04.877Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.115:55210 @ 0x1eca3c0" id= title= May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:42:04 mcpiv-rpi-volumio volumio[1253]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPushQueue May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::saveQueue May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::updateTrackBlock May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrackBlock May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioPlay May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::play index 0 May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::stop May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::play index undefined May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService undefined May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::startPlaybackTimer May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: CorePlayQueue::getTrack 0 May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: [1780166525144] ControllerWebradio::clearAddPlayTrack May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand stop May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand stop took 4 milliseconds May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand clear May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand clear took 5 milliseconds May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand load "http://zetrok-02.cdn.eurozet.pl:8448" May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: error: updateQueue error: null May 30 20:42:05 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 4ms May 30 20:42:06 mcpiv-rpi-volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. May 30 20:42:06 mcpiv-rpi-volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. May 30 20:42:06 mcpiv-rpi-volumio systemd[1]: setdatetime-helper.service: Consumed 1.016s CPU time. May 30 20:42:07 mcpiv-rpi-volumio volumio[1253]: info: Discovery: Restarting Browsing May 30 20:42:12 mcpiv-rpi-volumio volumio[1253]: info: Discovery: Restarting Browsing May 30 20:42:15 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand add "http://zetrok-02.cdn.eurozet.pl:8448" May 30 20:42:15 mcpiv-rpi-volumio volumio[1253]: error: updateQueue error: null May 30 20:42:15 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 10526ms May 30 20:42:15 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:42:15 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:42:15 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:42:15 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand add "http://zetrok-02.cdn.eurozet.pl:8448" took 2 milliseconds May 30 20:42:15 mcpiv-rpi-volumio volumio[1253]: info: CoreStateMachine::setConsumeUpdateService mpd May 30 20:42:15 mcpiv-rpi-volumio volumio[1253]: verbose: ControllerMpd::sendMpdCommand play May 30 20:42:15 mcpiv-rpi-volumio volumio[1253]: info: May 30 20:42:15 mcpiv-rpi-volumio volumio[1253]: ---------------------------- MPD announces system playlist update May 30 20:42:15 mcpiv-rpi-volumio volumio[1253]: info: Ignoring MPD Status Update May 30 20:42:15 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 3ms May 30 20:42:15 mcpiv-rpi-volumio volumio[1253]: info: sendMpdCommand play took 3 milliseconds May 30 20:42:15 mcpiv-rpi-volumio volumio[1253]: info: ------------------------------ 2ms May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: Retrieving Cloud Streaming UI May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: Getting Tidal Cloud Configuration May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: Getting Qobuz Cloud Configuration May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: Asking plugin for UI Config May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: Getting Spotify Cloud Configuration May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: Asking plugin for UI Config May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: Saving Spotify Acccount May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: Got Tidal Cloud Configuration May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: Got it May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: Got it May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioGetBrowseSources May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioGetBrowseSources May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::volumioGetBrowseSources May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 30 20:42:16 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares May 30 20:42:17 mcpiv-rpi-volumio volumio[1253]: info: Discovery: Restarting Browsing May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: Error: dns service error: unknown May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: at new Browser (/volumio/node_modules/mdns/lib/browser.js:88:10) May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: at Object.create [as createBrowser] (/volumio/node_modules/mdns/lib/browser.js:116:10) May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: at ControllerVolumioDiscovery.browseForService (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:718:32) May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32) May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: at ControllerNetworkfs.discoverShares (/volumio/app/plugins/system_controller/networkfs/index.js:826:36) May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32) May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1614:45) May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: at Socket.emit (node:events:514:28) May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) { May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: errorCode: -65537 May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: } May 30 20:42:20 mcpiv-rpi-volumio volumio[1253]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 20:42:21 mcpiv-rpi-volumio sudo[11822]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-30 20:41' May 30 20:42:21 mcpiv-rpi-volumio sudo[11822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"