Feb 23 21:01:03 test volumio[1215]: info: CoreCommandRouter::volumioPause Feb 23 21:01:03 test volumio[1215]: info: CoreStateMachine::pause Feb 23 21:01:03 test volumio[1215]: info: CoreStateMachine::stPlaybackTimer Feb 23 21:01:03 test volumio[1215]: info: CoreStateMachine::servicePause Feb 23 21:01:03 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:03 test volumio[1215]: info: CoreCommandRouter::servicePause Feb 23 21:01:03 test volumio[1215]: info: ControllerMpd::pause Feb 23 21:01:03 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand pause Feb 23 21:01:06 test volumio[1215]: info: Feb 23 21:01:06 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:06 test volumio[1215]: info: sendMpdCommand pause took 2789 milliseconds Feb 23 21:01:06 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:06 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:06 test volumio[1215]: info: Feb 23 21:01:06 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:06 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:06 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:06 test volumio[1215]: info: Feb 23 21:01:06 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:06 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:06 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:06 test volumio[1215]: info: Feb 23 21:01:06 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:06 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:06 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:06 test volumio[1215]: info: Feb 23 21:01:06 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:06 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:06 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:06 test volumio[1215]: info: sendMpdCommand status took 110 milliseconds Feb 23 21:01:06 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:06 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:06 test volumio[1215]: info: sendMpdCommand status took 280 milliseconds Feb 23 21:01:06 test volumio[1215]: info: sendMpdCommand status took 279 milliseconds Feb 23 21:01:06 test volumio[1215]: info: sendMpdCommand status took 278 milliseconds Feb 23 21:01:06 test volumio[1215]: info: sendMpdCommand status took 278 milliseconds Feb 23 21:01:06 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:06 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:06 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:06 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:06 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:06 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:06 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:06 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:07 test volumio[1215]: info: sendMpdCommand playlistinfo took 242 milliseconds Feb 23 21:01:07 test volumio[1215]: info: sendMpdCommand playlistinfo took 200 milliseconds Feb 23 21:01:07 test volumio[1215]: info: sendMpdCommand playlistinfo took 201 milliseconds Feb 23 21:01:07 test volumio[1215]: info: sendMpdCommand playlistinfo took 201 milliseconds Feb 23 21:01:07 test volumio[1215]: info: sendMpdCommand playlistinfo took 201 milliseconds Feb 23 21:01:07 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:07 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:07 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:07 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:07 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:07 test volumio[1215]: info: ControllerMpd::pushState Feb 23 21:01:07 test volumio[1215]: info: CoreCommandRouter::servicePushState Feb 23 21:01:07 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:07 test volumio[1215]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":51813,"duration":371,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jericho (Re-record)","artist":"Simply Red","album":"Song Book","uri":"USB/DEMAG/Song book simply red/Jericho (Re-record).mp3","trackType":"mp3"} Feb 23 21:01:07 test volumio[1215]: verbose: CURRENT POSITION 22 Feb 23 21:01:07 test volumio[1215]: info: CoreStateMachine::syncState stateService pause Feb 23 21:01:07 test volumio[1215]: info: CoreStateMachine::syncState currentStatus pause Feb 23 21:01:07 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:07 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:07 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 21:01:07 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:07 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:07 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:07 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:07 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:07 test volumio[1215]: info: CoreStateMachine::stPlaybackTimer Feb 23 21:01:07 test volumio[1215]: info: ControllerMpd::pushState Feb 23 21:01:07 test volumio[1215]: info: CoreCommandRouter::servicePushState Feb 23 21:01:07 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:07 test volumio[1215]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":51813,"duration":371,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jericho (Re-record)","artist":"Simply Red","album":"Song Book","uri":"USB/DEMAG/Song book simply red/Jericho (Re-record).mp3","trackType":"mp3"} Feb 23 21:01:07 test volumio[1215]: verbose: CURRENT POSITION 22 Feb 23 21:01:07 test volumio[1215]: info: CoreStateMachine::syncState stateService pause Feb 23 21:01:07 test volumio[1215]: info: CoreStateMachine::syncState currentStatus pause Feb 23 21:01:07 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:07 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:07 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:07 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:07 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:07 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:07 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:07 test volumio[1215]: info: CoreStateMachine::stPlaybackTimer Feb 23 21:01:07 test volumio[1215]: info: ControllerMpd::pushState Feb 23 21:01:07 test volumio[1215]: info: CoreCommandRouter::servicePushState Feb 23 21:01:07 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:07 test volumio[1215]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":51813,"duration":371,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jericho (Re-record)","artist":"Simply Red","album":"Song Book","uri":"USB/DEMAG/Song book simply red/Jericho (Re-record).mp3","trackType":"mp3"} Feb 23 21:01:07 test volumio[1215]: verbose: CURRENT POSITION 22 Feb 23 21:01:07 test volumio[1215]: info: CoreStateMachine::syncState stateService pause Feb 23 21:01:07 test volumio[1215]: info: CoreStateMachine::syncState currentStatus pause Feb 23 21:01:07 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:07 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:07 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:07 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:07 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:07 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:07 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:07 test volumio[1215]: info: CoreStateMachine::stPlaybackTimer Feb 23 21:01:07 test volumio[1215]: info: ControllerMpd::pushState Feb 23 21:01:07 test volumio[1215]: info: CoreCommandRouter::servicePushState Feb 23 21:01:07 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:07 test volumio[1215]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":51813,"duration":371,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jericho (Re-record)","artist":"Simply Red","album":"Song Book","uri":"USB/DEMAG/Song book simply red/Jericho (Re-record).mp3","trackType":"mp3"} Feb 23 21:01:07 test volumio[1215]: verbose: CURRENT POSITION 22 Feb 23 21:01:07 test volumio[1215]: info: CoreStateMachine::syncState stateService pause Feb 23 21:01:07 test volumio[1215]: info: CoreStateMachine::syncState currentStatus pause Feb 23 21:01:07 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:07 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:07 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:07 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:08 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:08 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:08 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:08 test volumio[1215]: info: CoreStateMachine::stPlaybackTimer Feb 23 21:01:08 test volumio[1215]: info: ControllerMpd::pushState Feb 23 21:01:08 test volumio[1215]: info: CoreCommandRouter::servicePushState Feb 23 21:01:08 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:08 test volumio[1215]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":51813,"duration":371,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jericho (Re-record)","artist":"Simply Red","album":"Song Book","uri":"USB/DEMAG/Song book simply red/Jericho (Re-record).mp3","trackType":"mp3"} Feb 23 21:01:08 test volumio[1215]: verbose: CURRENT POSITION 22 Feb 23 21:01:08 test volumio[1215]: info: CoreStateMachine::syncState stateService pause Feb 23 21:01:08 test volumio[1215]: info: CoreStateMachine::syncState currentStatus pause Feb 23 21:01:08 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:08 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:08 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:08 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:08 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:08 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:08 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:08 test volumio[1215]: info: CoreStateMachine::stPlaybackTimer Feb 23 21:01:09 test volumio5-onboarding[1596]: time=2026-02-23T21:01:08.957Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PAUSED positionMs=52969 volume=86 Feb 23 21:01:09 test volumio5-onboarding[1596]: time=2026-02-23T21:01:08.958Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PAUSED positionMs=52969 volume=86 Feb 23 21:01:09 test volumio5-onboarding[1596]: time=2026-02-23T21:01:08.957Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PAUSED positionMs=52969 volume=86 Feb 23 21:01:09 test volumio5-onboarding[1596]: time=2026-02-23T21:01:08.987Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PAUSED positionMs=52969 volume=86 Feb 23 21:01:09 test volumio5-onboarding[1596]: time=2026-02-23T21:01:08.957Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PAUSED positionMs=52969 volume=86 Feb 23 21:01:09 test volumio5-onboarding[1596]: time=2026-02-23T21:01:09.072Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho (Re-record).mp3" title="Jericho (Re-record)" Feb 23 21:01:09 test volumio5-onboarding[1596]: time=2026-02-23T21:01:09.170Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho (Re-record).mp3" title="Jericho (Re-record)" Feb 23 21:01:09 test volumio5-onboarding[1596]: time=2026-02-23T21:01:09.072Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho (Re-record).mp3" title="Jericho (Re-record)" Feb 23 21:01:09 test volumio5-onboarding[1596]: time=2026-02-23T21:01:09.073Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho (Re-record).mp3" title="Jericho (Re-record)" Feb 23 21:01:09 test volumio5-onboarding[1596]: time=2026-02-23T21:01:09.071Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho (Re-record).mp3" title="Jericho (Re-record)" Feb 23 21:01:10 test volumio[1215]: info: ------------------------------ 3808ms Feb 23 21:01:10 test volumio[1215]: info: ------------------------------ 3541ms Feb 23 21:01:10 test volumio[1215]: info: ------------------------------ 3541ms Feb 23 21:01:10 test volumio[1215]: info: ------------------------------ 3540ms Feb 23 21:01:10 test volumio[1215]: info: ------------------------------ 3540ms Feb 23 21:01:13 test volumio[1215]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false Feb 23 21:01:13 test volumio[1215]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false Feb 23 21:01:13 test volumio[1215]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false Feb 23 21:01:13 test volumio[1215]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false Feb 23 21:01:13 test volumio[1215]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false Feb 23 21:01:13 test volumio[1215]: info: CoreCommandRouter::volumioPause Feb 23 21:01:13 test volumio[1215]: info: CoreStateMachine::pause Feb 23 21:01:13 test volumio[1215]: info: CoreCommandRouter::volumioNext Feb 23 21:01:13 test volumio[1215]: info: CoreStateMachine::next Feb 23 21:01:13 test volumio[1215]: info: CoreStateMachine::stop Feb 23 21:01:13 test volumio[1215]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 23 21:01:13 test volumio[1215]: info: CoreStateMachine::updateTrackBlock Feb 23 21:01:13 test volumio[1215]: info: CorePlayQueue::getTrackBlock Feb 23 21:01:13 test volumio[1215]: info: CoreStateMachine::stPlaybackTimer Feb 23 21:01:13 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:13 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:13 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 21:01:13 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:14 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:14 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:14 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:14 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:14 test volumio[1215]: info: CoreStateMachine::serviceStop Feb 23 21:01:14 test volumio[1215]: info: CorePlayQueue::getTrack 22 Feb 23 21:01:14 test volumio[1215]: info: CoreCommandRouter::serviceStop Feb 23 21:01:14 test volumio[1215]: info: ControllerMpd::stop Feb 23 21:01:14 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand stop Feb 23 21:01:15 test volumio5-onboarding[1596]: time=2026-02-23T21:01:15.326Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_STOPPED positionMs=0 volume=86 Feb 23 21:01:15 test volumio5-onboarding[1596]: time=2026-02-23T21:01:15.462Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho (Re-record).mp3" title="Jericho (Re-record)" Feb 23 21:01:15 test volumio[1215]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand stop took 2927 milliseconds Feb 23 21:01:17 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:17 test volumio[1215]: info: CoreStateMachine::play index undefined Feb 23 21:01:17 test volumio[1215]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 23 21:01:17 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:17 test volumio[1215]: info: CoreStateMachine::startPlaybackTimer Feb 23 21:01:17 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::clearAddPlayTracks USB/DEMAG/Song book simply red/Jericho.mp3 Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand stop Feb 23 21:01:17 test volumio[1215]: info: CoreStateMachine::updateTrackBlock Feb 23 21:01:17 test volumio[1215]: info: CorePlayQueue::getTrackBlock Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:17 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:17 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:17 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:17 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand status took 135 milliseconds Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand stop took 67 milliseconds Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand status took 66 milliseconds Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand status took 66 milliseconds Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand status took 65 milliseconds Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand status took 63 milliseconds Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand clear Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:17 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:17 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:17 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Feb 23 21:01:17 test volumio[1215]: info: CoreCommandRouter::volumioPlay Feb 23 21:01:17 test volumio[1215]: info: CoreStateMachine::play index undefined Feb 23 21:01:17 test volumio[1215]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 23 21:01:17 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:17 test volumio[1215]: info: CoreStateMachine::startPlaybackTimer Feb 23 21:01:17 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::clearAddPlayTracks USB/DEMAG/Song book simply red/Jericho.mp3 Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand stop Feb 23 21:01:17 test volumio[1215]: info: touch_display: Setting screensaver timeout to 120 seconds. Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces system playlist update Feb 23 21:01:17 test volumio[1215]: info: Ignoring MPD Status Update Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand playlistinfo took 192 milliseconds Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand clear took 192 milliseconds Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand playlistinfo took 191 milliseconds Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand playlistinfo took 191 milliseconds Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand playlistinfo took 191 milliseconds Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand playlistinfo took 191 milliseconds Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand stop took 188 milliseconds Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand add "USB/DEMAG/Song book simply red/Jericho.mp3" Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand clear Feb 23 21:01:17 test volumio[1215]: info: ControllerMpd::pushState Feb 23 21:01:17 test volumio[1215]: info: CoreCommandRouter::servicePushState Feb 23 21:01:17 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:17 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:17 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 21:01:17 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:17 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:17 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:17 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:17 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:17 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:17 test volumio[1215]: 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":"Jericho (Re-record)","artist":"Simply Red","album":"Song Book","uri":"USB/DEMAG/Song book simply red/Jericho (Re-record).mp3","trackType":"mp3"} Feb 23 21:01:17 test volumio[1215]: verbose: CURRENT POSITION 23 Feb 23 21:01:17 test volumio[1215]: info: CoreStateMachine::syncState stateService stop Feb 23 21:01:17 test volumio[1215]: info: CoreStateMachine::syncState currentStatus stop Feb 23 21:01:17 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:17 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:17 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:17 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:17 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:17 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:17 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:17 test volumio[1215]: info: No code Feb 23 21:01:17 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:17 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:17 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:17 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:17 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:17 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:17 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:17 test volumio[1215]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Feb 23 21:01:17 test volumio[1215]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Feb 23 21:01:17 test volumio[1215]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Feb 23 21:01:17 test volumio[1215]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Feb 23 21:01:17 test volumio5-onboarding[1596]: time=2026-02-23T21:01:17.546Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_STOPPED positionMs=187 volume=86 Feb 23 21:01:17 test volumio5-onboarding[1596]: time=2026-02-23T21:01:17.547Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_STOPPED positionMs=187 volume=86 Feb 23 21:01:17 test volumio5-onboarding[1596]: time=2026-02-23T21:01:17.547Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_STOPPED positionMs=187 volume=86 Feb 23 21:01:17 test volumio5-onboarding[1596]: time=2026-02-23T21:01:17.547Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:17 test volumio5-onboarding[1596]: time=2026-02-23T21:01:17.547Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:17 test volumio5-onboarding[1596]: time=2026-02-23T21:01:17.548Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:17 test volumio[1215]: info: ------------------------------ 466ms Feb 23 21:01:17 test volumio[1215]: info: ------------------------------ 355ms Feb 23 21:01:17 test volumio[1215]: info: ------------------------------ 354ms Feb 23 21:01:17 test volumio[1215]: info: ------------------------------ 353ms Feb 23 21:01:17 test volumio[1215]: info: ------------------------------ 352ms Feb 23 21:01:17 test volumio[1215]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false Feb 23 21:01:17 test volumio[1215]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false Feb 23 21:01:17 test volumio[1215]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces system playlist update Feb 23 21:01:17 test volumio[1215]: info: Ignoring MPD Status Update Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces system playlist update Feb 23 21:01:17 test volumio[1215]: info: Ignoring MPD Status Update Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces system playlist update Feb 23 21:01:17 test volumio[1215]: info: Ignoring MPD Status Update Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces system playlist update Feb 23 21:01:17 test volumio[1215]: info: Ignoring MPD Status Update Feb 23 21:01:17 test volumio[1215]: error: updateQueue error: null Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces system playlist update Feb 23 21:01:17 test volumio[1215]: info: Ignoring MPD Status Update Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces system playlist update Feb 23 21:01:17 test volumio[1215]: info: Ignoring MPD Status Update Feb 23 21:01:17 test volumio[1215]: error: updateQueue error: null Feb 23 21:01:17 test volumio[1215]: error: updateQueue error: null Feb 23 21:01:17 test volumio[1215]: error: updateQueue error: null Feb 23 21:01:17 test volumio[1215]: error: updateQueue error: null Feb 23 21:01:17 test volumio[1215]: info: ------------------------------ 491ms Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand add "USB/DEMAG/Song book simply red/Jericho.mp3" took 464 milliseconds Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand clear took 427 milliseconds Feb 23 21:01:17 test volumio[1215]: info: ------------------------------ 358ms Feb 23 21:01:17 test volumio[1215]: info: ------------------------------ 357ms Feb 23 21:01:17 test volumio[1215]: info: ------------------------------ 356ms Feb 23 21:01:17 test volumio[1215]: info: ------------------------------ 355ms Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand play Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand add "USB/DEMAG/Song book simply red/Jericho.mp3" Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces system playlist update Feb 23 21:01:17 test volumio[1215]: info: Ignoring MPD Status Update Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces system playlist update Feb 23 21:01:17 test volumio[1215]: info: Ignoring MPD Status Update Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces system playlist update Feb 23 21:01:17 test volumio[1215]: info: Ignoring MPD Status Update Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces system playlist update Feb 23 21:01:17 test volumio[1215]: info: Ignoring MPD Status Update Feb 23 21:01:17 test volumio[1215]: error: updateQueue error: null Feb 23 21:01:17 test volumio[1215]: error: updateQueue error: null Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces system playlist update Feb 23 21:01:17 test volumio[1215]: info: Ignoring MPD Status Update Feb 23 21:01:17 test volumio[1215]: info: ------------------------------ 47ms Feb 23 21:01:17 test volumio[1215]: info: ------------------------------ 38ms Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand play took 36 milliseconds Feb 23 21:01:17 test volumio[1215]: info: sendMpdCommand add "USB/DEMAG/Song book simply red/Jericho.mp3" took 35 milliseconds Feb 23 21:01:17 test volumio[1215]: info: ------------------------------ 34ms Feb 23 21:01:17 test volumio[1215]: info: ------------------------------ 33ms Feb 23 21:01:17 test volumio[1215]: info: ------------------------------ 32ms Feb 23 21:01:17 test volumio[1215]: info: ------------------------------ 31ms Feb 23 21:01:17 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand play Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces system playlist update Feb 23 21:01:17 test volumio[1215]: info: Ignoring MPD Status Update Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces system playlist update Feb 23 21:01:17 test volumio[1215]: info: Ignoring MPD Status Update Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces system playlist update Feb 23 21:01:17 test volumio[1215]: info: Ignoring MPD Status Update Feb 23 21:01:17 test volumio[1215]: info: Feb 23 21:01:17 test volumio[1215]: ---------------------------- MPD announces system playlist update Feb 23 21:01:17 test volumio[1215]: info: Ignoring MPD Status Update Feb 23 21:01:18 test volumio[1215]: info: ------------------------------ 31ms Feb 23 21:01:18 test volumio[1215]: info: sendMpdCommand play took 136 milliseconds Feb 23 21:01:18 test volumio[1215]: info: ------------------------------ 135ms Feb 23 21:01:18 test volumio[1215]: info: ------------------------------ 134ms Feb 23 21:01:18 test volumio[1215]: info: ------------------------------ 134ms Feb 23 21:01:18 test volumio[1215]: info: ------------------------------ 134ms Feb 23 21:01:18 test volumio[1215]: info: Feb 23 21:01:18 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:18 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:18 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:18 test volumio[1215]: info: Feb 23 21:01:18 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:18 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:18 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:18 test volumio[1215]: info: Feb 23 21:01:18 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:18 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:18 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:18 test volumio[1215]: info: Feb 23 21:01:18 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:18 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:18 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:18 test volumio[1215]: info: Feb 23 21:01:18 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:18 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:18 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:23 test volumio[1215]: info: Feb 23 21:01:23 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:23 test volumio[1215]: info: sendMpdCommand status took 5622 milliseconds Feb 23 21:01:23 test volumio[1215]: info: sendMpdCommand status took 5649 milliseconds Feb 23 21:01:23 test volumio[1215]: info: sendMpdCommand status took 5648 milliseconds Feb 23 21:01:23 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:23 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:23 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:23 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:23 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:23 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:23 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:23 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:23 test volumio[1215]: info: Feb 23 21:01:23 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:23 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:23 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:23 test volumio[1215]: info: Feb 23 21:01:23 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:23 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:23 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:23 test volumio[1215]: info: Feb 23 21:01:23 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:23 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:23 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:23 test volumio[1215]: info: sendMpdCommand status took 5791 milliseconds Feb 23 21:01:23 test volumio[1215]: info: sendMpdCommand status took 5790 milliseconds Feb 23 21:01:23 test volumio[1215]: info: sendMpdCommand status took 145 milliseconds Feb 23 21:01:23 test volumio[1215]: info: sendMpdCommand playlistinfo took 115 milliseconds Feb 23 21:01:23 test volumio[1215]: info: sendMpdCommand playlistinfo took 115 milliseconds Feb 23 21:01:23 test volumio[1215]: info: sendMpdCommand playlistinfo took 115 milliseconds Feb 23 21:01:23 test volumio[1215]: info: sendMpdCommand status took 98 milliseconds Feb 23 21:01:23 test volumio[1215]: info: sendMpdCommand status took 98 milliseconds Feb 23 21:01:23 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:24 test volumio[1215]: info: ControllerMpd::pushState Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::servicePushState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":413,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Jericho","artist":"Simply Red","album":"Song Book","uri":"USB/DEMAG/Song book simply red/Jericho.mp3","trackType":"mp3"} Feb 23 21:01:24 test volumio[1215]: verbose: CURRENT POSITION 23 Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::syncState stateService play Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::syncState currentStatus stop Feb 23 21:01:24 test volumio[1215]: info: ControllerMpd::pushState Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::servicePushState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":413,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jericho","artist":"Simply Red","album":"Song Book","uri":"USB/DEMAG/Song book simply red/Jericho.mp3","trackType":"mp3"} Feb 23 21:01:24 test volumio[1215]: verbose: CURRENT POSITION 23 Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::syncState stateService play Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::syncState currentStatus play Feb 23 21:01:24 test volumio[1215]: info: Received an update from plugin. extracting info from payload Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: ControllerMpd::pushState Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::servicePushState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":413,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jericho","artist":"Simply Red","album":"Song Book","uri":"USB/DEMAG/Song book simply red/Jericho.mp3","trackType":"mp3"} Feb 23 21:01:24 test volumio[1215]: verbose: CURRENT POSITION 23 Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::syncState stateService play Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::syncState currentStatus play Feb 23 21:01:24 test volumio[1215]: info: Received an update from plugin. extracting info from payload Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: ------------------------------ 6538ms Feb 23 21:01:24 test volumio5-onboarding[1596]: time=2026-02-23T21:01:24.818Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=0 volume=86 Feb 23 21:01:24 test volumio5-onboarding[1596]: time=2026-02-23T21:01:24.816Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=0 volume=86 Feb 23 21:01:24 test volumio5-onboarding[1596]: time=2026-02-23T21:01:24.815Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=0 volume=86 Feb 23 21:01:24 test volumio5-onboarding[1596]: time=2026-02-23T21:01:24.815Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=0 volume=86 Feb 23 21:01:24 test volumio5-onboarding[1596]: time=2026-02-23T21:01:24.835Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:24 test volumio5-onboarding[1596]: time=2026-02-23T21:01:24.835Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:24 test volumio5-onboarding[1596]: time=2026-02-23T21:01:24.835Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:24 test volumio5-onboarding[1596]: time=2026-02-23T21:01:24.835Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:24 test volumio[1215]: info: ------------------------------ 6756ms Feb 23 21:01:24 test volumio[1215]: info: ------------------------------ 6756ms Feb 23 21:01:24 test volumio[1215]: info: Feb 23 21:01:24 test volumio[1215]: ---------------------------- MPD announces state update: player Feb 23 21:01:24 test volumio[1215]: info: ControllerMpd::getState Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand status Feb 23 21:01:24 test volumio[1215]: info: sendMpdCommand status took 968 milliseconds Feb 23 21:01:24 test volumio[1215]: info: sendMpdCommand playlistinfo took 925 milliseconds Feb 23 21:01:24 test volumio[1215]: info: sendMpdCommand playlistinfo took 925 milliseconds Feb 23 21:01:24 test volumio[1215]: info: sendMpdCommand playlistinfo took 924 milliseconds Feb 23 21:01:24 test volumio[1215]: info: sendMpdCommand playlistinfo took 862 milliseconds Feb 23 21:01:24 test volumio[1215]: info: sendMpdCommand playlistinfo took 861 milliseconds Feb 23 21:01:24 test volumio[1215]: info: sendMpdCommand status took 3 milliseconds Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::parseState Feb 23 21:01:24 test volumio[1215]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 23 21:01:24 test volumio[1215]: info: ControllerMpd::pushState Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::servicePushState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: verbose: STATE SERVICE {"status":"play","position":0,"seek":63,"duration":413,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jericho","artist":"Simply Red","album":"Song Book","uri":"USB/DEMAG/Song book simply red/Jericho.mp3","trackType":"mp3"} Feb 23 21:01:24 test volumio[1215]: verbose: CURRENT POSITION 23 Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::syncState stateService play Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::syncState currentStatus play Feb 23 21:01:24 test volumio[1215]: info: Received an update from plugin. extracting info from payload Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: ControllerMpd::pushState Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::servicePushState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: verbose: STATE SERVICE {"status":"play","position":0,"seek":63,"duration":413,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jericho","artist":"Simply Red","album":"Song Book","uri":"USB/DEMAG/Song book simply red/Jericho.mp3","trackType":"mp3"} Feb 23 21:01:24 test volumio[1215]: verbose: CURRENT POSITION 23 Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::syncState stateService play Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::syncState currentStatus play Feb 23 21:01:24 test volumio[1215]: info: Received an update from plugin. extracting info from payload Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: ControllerMpd::pushState Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::servicePushState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: verbose: STATE SERVICE {"status":"play","position":0,"seek":905,"duration":413,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jericho","artist":"Simply Red","album":"Song Book","uri":"USB/DEMAG/Song book simply red/Jericho.mp3","trackType":"mp3"} Feb 23 21:01:24 test volumio[1215]: verbose: CURRENT POSITION 23 Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::syncState stateService play Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::syncState currentStatus play Feb 23 21:01:24 test volumio[1215]: info: Received an update from plugin. extracting info from payload Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:24 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:24 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:24 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:25 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:25 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:25 test volumio[1215]: info: ControllerMpd::pushState Feb 23 21:01:25 test volumio[1215]: info: CoreCommandRouter::servicePushState Feb 23 21:01:25 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:25 test volumio[1215]: verbose: STATE SERVICE {"status":"play","position":0,"seek":905,"duration":413,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jericho","artist":"Simply Red","album":"Song Book","uri":"USB/DEMAG/Song book simply red/Jericho.mp3","trackType":"mp3"} Feb 23 21:01:25 test volumio[1215]: verbose: CURRENT POSITION 23 Feb 23 21:01:25 test volumio[1215]: info: CoreStateMachine::syncState stateService play Feb 23 21:01:25 test volumio[1215]: info: CoreStateMachine::syncState currentStatus play Feb 23 21:01:25 test volumio[1215]: info: Received an update from plugin. extracting info from payload Feb 23 21:01:25 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:25 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:25 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:25 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:25 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:25 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:25 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:25 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:25 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:25 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:25 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:25 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:25 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:25 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:25 test volumio[1215]: info: ControllerMpd::pushState Feb 23 21:01:25 test volumio[1215]: info: CoreCommandRouter::servicePushState Feb 23 21:01:25 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:25 test volumio[1215]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1011,"duration":413,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jericho","artist":"Simply Red","album":"Song Book","uri":"USB/DEMAG/Song book simply red/Jericho.mp3","trackType":"mp3"} Feb 23 21:01:25 test volumio[1215]: verbose: CURRENT POSITION 23 Feb 23 21:01:25 test volumio[1215]: info: CoreStateMachine::syncState stateService play Feb 23 21:01:25 test volumio[1215]: info: CoreStateMachine::syncState currentStatus play Feb 23 21:01:25 test volumio[1215]: info: Received an update from plugin. extracting info from payload Feb 23 21:01:25 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:25 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:25 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 21:01:25 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:25 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:25 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:25 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:25 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:25 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:25 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:25 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:25 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:25 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:25 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:25 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.146Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=63 volume=86 Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.146Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.148Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=63 volume=86 Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.149Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=63 volume=86 Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.149Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=63 volume=86 Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.149Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.149Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.149Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.152Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=905 volume=86 Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.152Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.153Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=905 volume=86 Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.154Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.155Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=905 volume=86 Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.156Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.156Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=1011 volume=86 Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.157Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.157Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=905 volume=86 Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.157Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.158Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=1011 volume=86 Feb 23 21:01:25 test volumio5-onboarding[1596]: time=2026-02-23T21:01:25.159Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:25 test volumio[1215]: info: ------------------------------ 6990ms Feb 23 21:01:25 test volumio[1215]: info: ------------------------------ 6990ms Feb 23 21:01:25 test volumio[1215]: info: ------------------------------ 1386ms Feb 23 21:01:25 test volumio[1215]: info: ------------------------------ 1300ms Feb 23 21:01:25 test volumio[1215]: info: ------------------------------ 1300ms Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: sendMpdCommand playlistinfo took 1621 milliseconds Feb 23 21:01:26 test volumio[1215]: info: sendMpdCommand playlistinfo took 1621 milliseconds Feb 23 21:01:26 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:26 test volumio[1215]: verbose: ControllerMpd::parseTrackInfo Feb 23 21:01:26 test volumio[1215]: info: ControllerMpd::pushState Feb 23 21:01:26 test volumio[1215]: info: CoreCommandRouter::servicePushState Feb 23 21:01:26 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:26 test volumio[1215]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1011,"duration":413,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jericho","artist":"Simply Red","album":"Song Book","uri":"USB/DEMAG/Song book simply red/Jericho.mp3","trackType":"mp3"} Feb 23 21:01:26 test volumio[1215]: verbose: CURRENT POSITION 23 Feb 23 21:01:26 test volumio[1215]: info: CoreStateMachine::syncState stateService play Feb 23 21:01:26 test volumio[1215]: info: CoreStateMachine::syncState currentStatus play Feb 23 21:01:26 test volumio[1215]: info: Received an update from plugin. extracting info from payload Feb 23 21:01:26 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:26 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:26 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:26 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:26 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:26 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:26 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:26 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:26 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:26 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:26 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:26 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:26 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:26 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:26 test volumio[1215]: info: ControllerMpd::pushState Feb 23 21:01:26 test volumio[1215]: info: CoreCommandRouter::servicePushState Feb 23 21:01:26 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:26 test volumio[1215]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1937,"duration":413,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Jericho","artist":"Simply Red","album":"Song Book","uri":"USB/DEMAG/Song book simply red/Jericho.mp3","trackType":"mp3"} Feb 23 21:01:26 test volumio[1215]: verbose: CURRENT POSITION 23 Feb 23 21:01:26 test volumio[1215]: info: CoreStateMachine::syncState stateService play Feb 23 21:01:26 test volumio[1215]: info: CoreStateMachine::syncState currentStatus play Feb 23 21:01:26 test volumio[1215]: info: Received an update from plugin. extracting info from payload Feb 23 21:01:26 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:26 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:26 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 21:01:26 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:26 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:26 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:26 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:26 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:26 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:26 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:26 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:26 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:26 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:26 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:26 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:26 test volumio5-onboarding[1596]: time=2026-02-23T21:01:26.592Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=1011 volume=86 Feb 23 21:01:26 test volumio5-onboarding[1596]: time=2026-02-23T21:01:26.593Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:26 test volumio5-onboarding[1596]: time=2026-02-23T21:01:26.592Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=1011 volume=86 Feb 23 21:01:26 test volumio5-onboarding[1596]: time=2026-02-23T21:01:26.594Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:26 test volumio5-onboarding[1596]: time=2026-02-23T21:01:26.594Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=1937 volume=86 Feb 23 21:01:26 test volumio5-onboarding[1596]: time=2026-02-23T21:01:26.594Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:26 test volumio5-onboarding[1596]: time=2026-02-23T21:01:26.594Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=1937 volume=86 Feb 23 21:01:26 test volumio5-onboarding[1596]: time=2026-02-23T21:01:26.595Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:26 test volumio[1215]: info: ------------------------------ 2630ms Feb 23 21:01:26 test volumio[1215]: info: ------------------------------ 1665ms Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:26 test volumio[1215]: info: touch_display: Setting screensaver timeout to 0 seconds. Feb 23 21:01:29 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:29 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:31 test volumio[1215]: info: Executing endpoint metavolumio Feb 23 21:01:31 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 23 21:01:31 test volumio[1215]: info: Executing endpoint metavolumio Feb 23 21:01:31 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 23 21:01:31 test volumio[1215]: info: Executing endpoint metavolumio Feb 23 21:01:31 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 23 21:01:35 test volumio[1215]: info: VolumeController::SetAlsaVolume97 Feb 23 21:01:35 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:35 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:35 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 21:01:35 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:35 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:35 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:35 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:35 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:35 test volumio[1215]: info: VolumeController::SetAlsaVolume98 Feb 23 21:01:35 test volumio[1215]: info: CoreStateMachine::pushState Feb 23 21:01:35 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:35 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 21:01:35 test volumio[1215]: info: CoreCommandRouter::volumioPushState Feb 23 21:01:35 test volumio[1215]: info: MRS: Pushing multiroomSync output update for this device Feb 23 21:01:35 test volumio[1215]: info: MRS: Pushing multiroomSync output Feb 23 21:01:35 test volumio[1215]: info: CoreCommandRouter::volumioGetState Feb 23 21:01:35 test volumio[1215]: info: CorePlayQueue::getTrack 23 Feb 23 21:01:35 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:35 test volumio[1215]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Feb 23 21:01:36 test volumio5-onboarding[1596]: time=2026-02-23T21:01:36.476Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=10553 volume=97 Feb 23 21:01:36 test volumio5-onboarding[1596]: time=2026-02-23T21:01:36.475Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" state=STATUS_PLAYING positionMs=11098 volume=98 Feb 23 21:01:36 test volumio5-onboarding[1596]: time=2026-02-23T21:01:36.560Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:36 test volumio5-onboarding[1596]: time=2026-02-23T21:01:36.568Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.66:54684 @ 0x1d045d0" id="mnt/USB/DEMAG/Song book simply red/Jericho.mp3" title=Jericho Feb 23 21:01:48 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: multiroom , enableAudioOutput Feb 23 21:01:48 test volumio[1215]: info: MRS: Starting sonos device: [object Object] Feb 23 21:01:48 test volumio[1215]: info: Enabled audio output: RINCON_B8E9372FC2B801400:4256279089 Feb 23 21:01:48 test volumio[1215]: info: MRS: Setting this device as Streaming Server Feb 23 21:01:48 test volumio[1215]: info: Feb 23 21:01:48 test volumio[1215]: [1771880508214] ---------------------------- MRS: Setting Streaming Server Feb 23 21:01:48 test volumio[1215]: info: MRS: enable multiroom server output Feb 23 21:01:48 test volumio[1215]: info: MRS: Set multiroom target PCM to volumioMultiRoom Feb 23 21:01:48 test volumio[1215]: info: Changed audio target for /tmp/multiroom/server/switch.target to volumioMultiRoom Feb 23 21:01:48 test volumio[1215]: info: MRS: Set multiroom target PCM to volumioLocalPlayback Feb 23 21:01:48 test volumio[1215]: info: Changed audio target for /tmp/multiroom/client/switch.target to volumioLocalPlayback Feb 23 21:01:48 test volumio[1215]: info: MRS: STARTING volumioStreaming Feb 23 21:01:49 test sudo[12364]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumioStreaming Feb 23 21:01:49 test sudo[12362]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Feb 23 21:01:49 test sudo[12364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:01:49 test sudo[12362]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:01:49 test sudo[12362]: pam_unix(sudo:session): session closed for user root Feb 23 21:01:49 test systemd[1]: Started volumioStreaming.service - VolumioStreamingService. Feb 23 21:01:49 test sudo[12364]: pam_unix(sudo:session): session closed for user root Feb 23 21:01:49 test volumio[1215]: info: MRS: volumioStreaming STARTED Feb 23 21:01:50 test sudo[12368]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Feb 23 21:01:50 test sudo[12368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:01:50 test sudo[12368]: pam_unix(sudo:session): session closed for user root Feb 23 21:01:59 test volumio[1215]: info: MRS: Starting sonos device: uuid:RINCON_B8E9372FC2B801400 Feb 23 21:01:59 test volumio[1215]: info: Refreshing Cached IP Addresses Feb 23 21:01:59 test sudo[12390]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 21:01:59 test sudo[12392]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 21:01:59 test sudo[12390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:01:59 test sudo[12392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:01:59 test sudo[12392]: pam_unix(sudo:session): session closed for user root Feb 23 21:01:59 test sudo[12390]: pam_unix(sudo:session): session closed for user root Feb 23 21:02:00 test volumio[1215]: error: MRS: Error starting sonos device: uuid:RINCON_B8E9372FC2B801400:Error: upnp: statusCode 500 & upnpErrorCode s:ClientUPnPError800 Feb 23 21:02:04 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: multiroom , enableAudioOutput Feb 23 21:02:06 test volumio[1215]: info: MRS: Starting sonos device: [object Object] Feb 23 21:02:06 test volumio[1215]: info: Enabled audio output: uuid:RINCON_7828CA54C55D01400 Feb 23 21:02:07 test volumio[1215]: info: MRS: Setting this device as Streaming Server Feb 23 21:02:07 test volumio[1215]: info: Feb 23 21:02:07 test volumio[1215]: [1771880527863] ---------------------------- MRS: Setting Streaming Server Feb 23 21:02:07 test volumio[1215]: info: MRS: enable multiroom server output Feb 23 21:02:07 test volumio[1215]: info: MRS: Set multiroom target PCM to volumioMultiRoom Feb 23 21:02:09 test volumio[1215]: info: Changed audio target for /tmp/multiroom/server/switch.target to volumioMultiRoom Feb 23 21:02:12 test volumio[1215]: info: MRS: Stopping sonos device: uuid:RINCON_B8E9372FC2B801400 Feb 23 21:02:14 test volumio[1215]: info: MRS: Set multiroom target PCM to volumioLocalPlayback Feb 23 21:02:16 test volumio[1215]: info: Changed audio target for /tmp/multiroom/client/switch.target to volumioLocalPlayback Feb 23 21:02:16 test volumio[1215]: info: MRS: STARTING volumioStreaming Feb 23 21:02:17 test sudo[12434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Feb 23 21:02:17 test sudo[12433]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumioStreaming Feb 23 21:02:17 test sudo[12434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:02:17 test sudo[12433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:02:17 test sudo[12434]: pam_unix(sudo:session): session closed for user root Feb 23 21:02:17 test volumio[1215]: info: MRS: Starting sonos device: uuid:RINCON_7828CA54C55D01400 Feb 23 21:02:17 test volumio[1215]: info: Refreshing Cached IP Addresses Feb 23 21:02:18 test systemd[1]: Stopping volumioStreaming.service - VolumioStreamingService... Feb 23 21:02:18 test systemd[1]: volumioStreaming.service: Killing process 12370 (ffmpeg) with signal SIGKILL. Feb 23 21:02:18 test systemd[1]: volumioStreaming.service: Deactivated successfully. Feb 23 21:02:18 test systemd[1]: Stopped volumioStreaming.service - VolumioStreamingService. Feb 23 21:02:18 test systemd[1]: volumioStreaming.service: Consumed 7.469s CPU time. Feb 23 21:02:18 test sudo[12443]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 21:02:18 test sudo[12443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:02:18 test sudo[12444]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 21:02:18 test sudo[12444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:02:18 test sudo[12443]: pam_unix(sudo:session): session closed for user root Feb 23 21:02:18 test sudo[12444]: pam_unix(sudo:session): session closed for user root Feb 23 21:02:18 test systemd[1]: Started volumioStreaming.service - VolumioStreamingService. Feb 23 21:02:18 test sudo[12433]: pam_unix(sudo:session): session closed for user root Feb 23 21:02:18 test sudo[12448]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Feb 23 21:02:18 test sudo[12448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:02:18 test sudo[12448]: pam_unix(sudo:session): session closed for user root Feb 23 21:02:19 test volumio[1215]: info: MRS: volumioStreaming STARTED Feb 23 21:02:20 test volumio[1215]: error: MRS: Error starting sonos device: uuid:RINCON_7828CA54C55D01400:Error: upnp: statusCode 500 & upnpErrorCode s:ClientUPnPError800 Feb 23 21:02:23 test volumio[1215]: info: CoreCommandRouter::executeOnPlugin: multiroom , disableAudioOutput Feb 23 21:02:23 test volumio[1215]: info: MRS: Setting this device as single Feb 23 21:02:23 test volumio[1215]: info: Feb 23 21:02:23 test volumio[1215]: [1771880543838] ---------------------------- Setting Multiroom Single Feb 23 21:02:24 test volumio[1215]: info: MRS: disable multiroom output Feb 23 21:02:24 test volumio[1215]: info: MRS: Set multiroom target PCM to volumioDiscard Feb 23 21:02:24 test volumio[1215]: info: Changed audio target for /tmp/multiroom/client/switch.target to volumioDiscard Feb 23 21:02:26 test volumio[1215]: info: MRS: Set multiroom target PCM to volumioLocalPlayback Feb 23 21:02:26 test volumio[1215]: info: Changed audio target for /tmp/multiroom/server/switch.target to volumioLocalPlayback Feb 23 21:02:27 test volumio[1215]: info: MRS: STOPPING volumioStreaming Feb 23 21:02:27 test sudo[12475]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Feb 23 21:02:27 test sudo[12473]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Feb 23 21:02:27 test sudo[12473]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:02:28 test volumio[1215]: info: MRS: Removed streaming files Feb 23 21:02:27 test sudo[12475]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 21:02:27 test sudo[12475]: pam_unix(sudo:session): session closed for user root Feb 23 21:02:28 test systemd[1]: Stopping volumioStreaming.service - VolumioStreamingService... Feb 23 21:02:28 test systemd[1]: volumioStreaming.service: Killing process 12450 (ffmpeg) with signal SIGKILL. Feb 23 21:02:29 test systemd[1]: volumioStreaming.service: Deactivated successfully. Feb 23 21:02:29 test systemd[1]: Stopped volumioStreaming.service - VolumioStreamingService. Feb 23 21:02:29 test systemd[1]: volumioStreaming.service: Consumed 4.029s CPU time. Feb 23 21:02:29 test sudo[12473]: pam_unix(sudo:session): session closed for user root Feb 23 21:02:29 test volumio[1215]: info: MRS: Stopping sonos device: uuid:RINCON_7828CA54C55D01400 Feb 23 21:02:29 test volumio[1215]: info: MRS: volumioStreaming STOPPED Feb 23 21:02:29 test volumio[1215]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 21:02:29 test volumio[1215]: Error: upnp: statusCode 500 & upnpErrorCode s:ClientUPnPError701 Feb 23 21:02:29 test volumio[1215]: at /myvolumio/plugins/audio_interface/multiroom/node_modules/sonos/lib/services/Service.js:87:25 Feb 23 21:02:29 test volumio[1215]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Feb 23 21:02:29 test volumio[1215]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 21:02:32 test sudo[12492]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-23 21:01' Feb 23 21:02:32 test sudo[12492]: 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"