May 31 10:19:00 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 10:19:09 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 10:19:13 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 10:19:16 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 10:19:20 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 31 10:19:29 volumio volumio[1246]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 10:19:29 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 31 10:19:29 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 10:19:29 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 31 10:19:29 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 10:19:29 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 10:19:29 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 10:19:29 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 10:19:29 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 10:19:29 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 10:19:29 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 10:19:29 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 31 10:19:29 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.472+03:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.147:43262 @ 0xc0004f34a0" latency=-356.501474ms timeout=3s volume=22 May 31 10:19:34 volumio volumio[1246]: info: VolumeController::SetAlsaVolume22 May 31 10:19:34 volumio volumio[1246]: info: CoreStateMachine::pushState May 31 10:19:34 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:19:34 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 10:19:34 volumio volumio[1246]: info: CoreCommandRouter::volumioPushState May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.488+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" state=STATUS_PLAYING positionMs=101755 volume=22 May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.488+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" id=motherearthradio/radio/flac96 title=Metzengerstein May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.888+03:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.147:43262 @ 0xc0004f34a0" latency=-213.011921ms timeout=3s volume=20 May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.889+03:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.147:43262 @ 0xc0004f34a0" latency=-257.941591ms timeout=3s volume=19 May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.890+03:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.147:43262 @ 0xc0004f34a0" latency=-359.728413ms timeout=3s volume=17 May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.891+03:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.147:43262 @ 0xc0004f34a0" latency=-311.014582ms timeout=3s volume=18 May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.888+03:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.147:43262 @ 0xc0004f34a0" latency=-172.984382ms timeout=3s volume=21 May 31 10:19:34 volumio volumio[1246]: info: VolumeController::SetAlsaVolume20 May 31 10:19:34 volumio volumio[1246]: info: CoreStateMachine::pushState May 31 10:19:34 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:19:34 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 10:19:34 volumio volumio[1246]: info: CoreCommandRouter::volumioPushState May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.906+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" state=STATUS_PLAYING positionMs=102256 volume=20 May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.906+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" id=motherearthradio/radio/flac96 title=Metzengerstein May 31 10:19:34 volumio volumio[1246]: info: VolumeController::SetAlsaVolume19 May 31 10:19:34 volumio volumio[1246]: info: VolumeController::SetAlsaVolume17 May 31 10:19:34 volumio volumio[1246]: info: VolumeController::SetAlsaVolume18 May 31 10:19:34 volumio volumio[1246]: info: VolumeController::SetAlsaVolume21 May 31 10:19:34 volumio volumio[1246]: info: CoreStateMachine::pushState May 31 10:19:34 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:19:34 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 10:19:34 volumio volumio[1246]: info: CoreCommandRouter::volumioPushState May 31 10:19:34 volumio volumio[1246]: info: CoreStateMachine::pushState May 31 10:19:34 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:19:34 volumio volumio[1246]: info: CoreCommandRouter::volumioPushState May 31 10:19:34 volumio volumio[1246]: info: CoreStateMachine::pushState May 31 10:19:34 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:19:34 volumio volumio[1246]: info: CoreCommandRouter::volumioPushState May 31 10:19:34 volumio volumio[1246]: info: CoreStateMachine::pushState May 31 10:19:34 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:19:34 volumio volumio[1246]: info: CoreCommandRouter::volumioPushState May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.963+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" state=STATUS_PLAYING positionMs=102256 volume=21 May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.964+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" state=STATUS_PLAYING positionMs=102256 volume=21 May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.965+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" id=motherearthradio/radio/flac96 title=Metzengerstein May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.964+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" id=motherearthradio/radio/flac96 title=Metzengerstein May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.966+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" state=STATUS_PLAYING positionMs=102256 volume=21 May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.966+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" id=motherearthradio/radio/flac96 title=Metzengerstein May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.966+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" state=STATUS_PLAYING positionMs=102256 volume=21 May 31 10:19:34 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:34.967+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" id=motherearthradio/radio/flac96 title=Metzengerstein May 31 10:19:35 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:35.629+03:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.147:43262 @ 0xc0004f34a0" latency=327.70885ms timeout=3s volume=16 May 31 10:19:35 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:35.630+03:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.147:43262 @ 0xc0004f34a0" latency=273.749015ms timeout=3s volume=15 May 31 10:19:35 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:35.632+03:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.147:43262 @ 0xc0004f34a0" latency=229.380424ms timeout=3s volume=14 May 31 10:19:35 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:35.633+03:00 level=INFO msg="set volume" component=server type=REQUEST_TYPE_SET_VOLUME peer="192.168.0.147:43262 @ 0xc0004f34a0" latency=176.306356ms timeout=3s volume=13 May 31 10:19:35 volumio volumio[1246]: info: VolumeController::SetAlsaVolume16 May 31 10:19:35 volumio volumio[1246]: info: VolumeController::SetAlsaVolume15 May 31 10:19:35 volumio volumio[1246]: info: CoreStateMachine::pushState May 31 10:19:35 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:19:35 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 10:19:35 volumio volumio[1246]: info: CoreCommandRouter::volumioPushState May 31 10:19:35 volumio volumio[1246]: info: CoreStateMachine::pushState May 31 10:19:35 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:19:35 volumio volumio[1246]: info: CoreCommandRouter::volumioPushState May 31 10:19:35 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:35.662+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" state=STATUS_PLAYING positionMs=103007 volume=15 May 31 10:19:35 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:35.662+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" id=motherearthradio/radio/flac96 title=Metzengerstein May 31 10:19:35 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:35.664+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" state=STATUS_PLAYING positionMs=103007 volume=15 May 31 10:19:35 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:35.665+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" id=motherearthradio/radio/flac96 title=Metzengerstein May 31 10:19:35 volumio volumio[1246]: info: VolumeController::SetAlsaVolume14 May 31 10:19:35 volumio volumio[1246]: info: VolumeController::SetAlsaVolume13 May 31 10:19:35 volumio volumio[1246]: info: CoreStateMachine::pushState May 31 10:19:35 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:19:35 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 10:19:35 volumio volumio[1246]: info: CoreCommandRouter::volumioPushState May 31 10:19:35 volumio volumio[1246]: info: CoreStateMachine::pushState May 31 10:19:35 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:19:35 volumio volumio[1246]: info: CoreCommandRouter::volumioPushState May 31 10:19:35 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:35.697+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" state=STATUS_PLAYING positionMs=103007 volume=13 May 31 10:19:35 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:35.697+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" id=motherearthradio/radio/flac96 title=Metzengerstein May 31 10:19:35 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:35.698+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" state=STATUS_PLAYING positionMs=103007 volume=13 May 31 10:19:35 volumio volumio5-onboarding[1938]: time=2026-05-31T10:19:35.698+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" id=motherearthradio/radio/flac96 title=Metzengerstein May 31 10:20:06 volumio volumio[1246]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions May 31 10:20:06 volumio volumio[1246]: info: Preparing to save Alsa Options, stopping services first May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::volumioGetState May 31 10:20:06 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::volumioPause May 31 10:20:06 volumio volumio[1246]: info: CoreStateMachine::pause May 31 10:20:06 volumio volumio[1246]: info: CoreStateMachine::stPlaybackTimer May 31 10:20:06 volumio volumio[1246]: info: CoreStateMachine::servicePause May 31 10:20:06 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::servicePause May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::servicePushState May 31 10:20:06 volumio volumio[1246]: info: CoreStateMachine::pushState May 31 10:20:06 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::volumioPushState May 31 10:20:06 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:20:06 volumio volumio[1246]: verbose: STATE SERVICE {"status":"stop","service":"motherearthradio"} May 31 10:20:06 volumio volumio[1246]: verbose: CURRENT POSITION 0 May 31 10:20:06 volumio volumio[1246]: info: CoreStateMachine::syncState stateService stop May 31 10:20:06 volumio volumio[1246]: info: CoreStateMachine::syncState currentStatus pause May 31 10:20:06 volumio volumio[1246]: info: CoreStateMachine::pushState May 31 10:20:06 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::volumioPushState May 31 10:20:06 volumio volumio[1246]: info: ControllerMpd::stop May 31 10:20:06 volumio volumio[1246]: verbose: ControllerMpd::sendMpdCommand stop May 31 10:20:06 volumio volumio[1246]: info: Saving Audio Output to: {"output_device":{"value":"0,1","label":"SPDIF"}} May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 31 10:20:06 volumio volumio[1246]: info: Found match in Cards Database: setting mixer for card SPDIF May 31 10:20:06 volumio volumio[1246]: info: Setting mixer Master for card SPDIF May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 31 10:20:06 volumio volumio[1246]: info: Updating Volume Controller Parameters: Device: 0,1 Name: SPDIF Mixer: Master Max Vol: 40 Vol Curve; logarithmic Vol Steps: 1 May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 31 10:20:06 volumio volumio[1246]: info: Disabling external Volume Control May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::getUIConfigOnPlugin May 31 10:20:06 volumio volumio5-onboarding[1938]: time=2026-05-31T10:20:06.421+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" state=STATUS_PAUSED positionMs=133538 volume=13 May 31 10:20:06 volumio volumio5-onboarding[1938]: time=2026-05-31T10:20:06.421+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" state=STATUS_PAUSED positionMs=133538 volume=13 May 31 10:20:06 volumio volumio5-onboarding[1938]: time=2026-05-31T10:20:06.421+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" id=motherearthradio/radio/flac96 title=Metzengerstein May 31 10:20:06 volumio volumio5-onboarding[1938]: time=2026-05-31T10:20:06.422+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" id=motherearthradio/radio/flac96 title=Metzengerstein May 31 10:20:06 volumio volumio[1246]: info: Preparing to generate the ALSA configuration file May 31 10:20:06 volumio volumio[1246]: info: May 31 10:20:06 volumio volumio[1246]: ---------------------------- MPD announces state update: player May 31 10:20:06 volumio volumio[1246]: info: sendMpdCommand stop took 141 milliseconds May 31 10:20:06 volumio volumio[1246]: info: ControllerMpd::getState May 31 10:20:06 volumio volumio[1246]: verbose: ControllerMpd::sendMpdCommand status May 31 10:20:06 volumio volumio[1246]: info: sendMpdCommand status took 21 milliseconds May 31 10:20:06 volumio volumio[1246]: verbose: ControllerMpd::parseState May 31 10:20:06 volumio volumio[1246]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 31 10:20:06 volumio volumio[1246]: info: sendMpdCommand playlistinfo took 2 milliseconds May 31 10:20:06 volumio volumio[1246]: verbose: ControllerMpd::parseTrackInfo May 31 10:20:06 volumio volumio[1246]: info: ControllerMpd::pushState May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::servicePushState May 31 10:20:06 volumio volumio[1246]: info: CoreStateMachine::pushState May 31 10:20:06 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::volumioPushState May 31 10:20:06 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:20:06 volumio volumio[1246]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received mpd May 31 10:20:06 volumio volumio[1246]: info: ------------------------------ 49ms May 31 10:20:06 volumio volumio5-onboarding[1938]: time=2026-05-31T10:20:06.500+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" state=STATUS_PAUSED positionMs=133824 volume=13 May 31 10:20:06 volumio volumio5-onboarding[1938]: time=2026-05-31T10:20:06.501+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" id=motherearthradio/radio/flac96 title=Metzengerstein May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 31 10:20:06 volumio volumio[1246]: info: VolumeController:: Volume=13 Mute =false May 31 10:20:06 volumio volumio[1246]: info: CoreStateMachine::pushState May 31 10:20:06 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::volumioPushState May 31 10:20:06 volumio volumio5-onboarding[1938]: time=2026-05-31T10:20:06.676+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" state=STATUS_PAUSED positionMs=133824 volume=13 May 31 10:20:06 volumio volumio5-onboarding[1938]: time=2026-05-31T10:20:06.676+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" id=motherearthradio/radio/flac96 title=Metzengerstein May 31 10:20:06 volumio volumio[1246]: info: Asound.conf file written May 31 10:20:06 volumio sudo[9812]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 31 10:20:06 volumio sudo[9812]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 10:20:06 volumio sudo[9812]: pam_unix(sudo:session): session closed for user root May 31 10:20:06 volumio volumio[1246]: info: Output device has changed, restarting MPD May 31 10:20:06 volumio volumio[1246]: info: Output device has changed, restarting Shairport Sync May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 10:20:06 volumio sudo[9819]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 10:20:06 volumio sudo[9819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 10:20:06 volumio sudo[9819]: pam_unix(sudo:session): session closed for user root May 31 10:20:06 volumio sudo[9821]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 10:20:06 volumio sudo[9821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 10:20:06 volumio volumio[1246]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 10:20:06 volumio volumio[1246]: info: Output device has changed, restarting MPD May 31 10:20:06 volumio volumio[1246]: info: Output device has changed, restarting Shairport Sync May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 10:20:06 volumio sudo[9829]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 31 10:20:06 volumio sudo[9829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 10:20:06 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... May 31 10:20:06 volumio sudo[9829]: pam_unix(sudo:session): session closed for user root May 31 10:20:06 volumio sudo[9832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 31 10:20:06 volumio sudo[9832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 10:20:06 volumio volumio[1246]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 31 10:20:06 volumio volumio[1246]: info: MPD Permissions set May 31 10:20:06 volumio volumio[1246]: info: MPD Permissions set May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio systemd[1]: mpd.service: Deactivated successfully. May 31 10:20:06 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. May 31 10:20:06 volumio systemd[1]: mpd.service: Consumed 39.026s CPU time. May 31 10:20:06 volumio systemd[1]: mpd.socket: Deactivated successfully. May 31 10:20:06 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 31 10:20:06 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 31 10:20:06 volumio systemd[1]: Starting mpd.service - Music Player Daemon... May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 31 10:20:06 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 31 10:20:06 volumio volumio[1246]: info: Starting Shairport Sync May 31 10:20:06 volumio volumio[1246]: info: Starting Shairport Sync May 31 10:20:07 volumio sudo[9858]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 10:20:07 volumio sudo[9858]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 10:20:07 volumio sudo[9860]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 31 10:20:07 volumio sudo[9860]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 31 10:20:07 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 31 10:20:07 volumio systemd[1]: shairport-sync.service: Deactivated successfully. May 31 10:20:07 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 31 10:20:07 volumio systemd[1]: shairport-sync.service: Consumed 3.920s CPU time. May 31 10:20:07 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 31 10:20:07 volumio sudo[9858]: pam_unix(sudo:session): session closed for user root May 31 10:20:07 volumio volumio[1246]: info: Shairport-Sync Started May 31 10:20:07 volumio sudo[9850]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 31 10:20:07 volumio sudo[9850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 31 10:20:07 volumio sudo[9850]: pam_unix(sudo:session): session closed for user root May 31 10:20:07 volumio sudo[9860]: pam_unix(sudo:session): session closed for user root May 31 10:20:07 volumio volumio[1246]: info: Shairport-Sync Started May 31 10:20:07 volumio kernel: perf: interrupt took too long (3927 > 3915), lowering kernel.perf_event_max_sample_rate to 50750 May 31 10:20:09 volumio mpd[9865]: 2026-05-31T10:20:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 31 10:20:09 volumio systemd[1]: Started mpd.service - Music Player Daemon. May 31 10:20:09 volumio sudo[9832]: pam_unix(sudo:session): session closed for user root May 31 10:20:09 volumio sudo[9821]: pam_unix(sudo:session): session closed for user root May 31 10:20:09 volumio volumio[1246]: error: MPD error: The expression evaluated to a falsy value: May 31 10:20:09 volumio volumio[1246]: assert.ok(self.idling) May 31 10:20:09 volumio volumio[1246]: error: The expression evaluated to a falsy value: May 31 10:20:09 volumio volumio[1246]: assert.ok(self.idling) May 31 10:20:09 volumio volumio[1246]: error: updateQueue error: null May 31 10:20:10 volumio volumio[1246]: info: CoreCommandRouter::volumioRetrieveVolumeLevels May 31 10:20:10 volumio volumio[1246]: info: CoreStateMachine::getcurrentVolume May 31 10:20:10 volumio volumio[1246]: info: CoreCommandRouter::volumioRetrievevolume May 31 10:20:10 volumio volumio[1246]: info: VolumeController:: Volume=50 Mute =false May 31 10:20:10 volumio volumio[1246]: info: CoreStateMachine::pushState May 31 10:20:10 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:20:10 volumio volumio[1246]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 31 10:20:10 volumio volumio[1246]: info: CoreCommandRouter::volumioPushState May 31 10:20:10 volumio volumio[1246]: info: CoreStateMachine::updateTrackBlock May 31 10:20:10 volumio volumio[1246]: info: CorePlayQueue::getTrackBlock May 31 10:20:10 volumio volumio[1246]: info: CoreCommandRouter::volumioRetrievevolume May 31 10:20:10 volumio volumio5-onboarding[1938]: time=2026-05-31T10:20:10.462+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" state=STATUS_PAUSED positionMs=133824 volume=50 May 31 10:20:10 volumio volumio5-onboarding[1938]: time=2026-05-31T10:20:10.464+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" id=motherearthradio/radio/flac96 title=Metzengerstein May 31 10:20:10 volumio volumio[1246]: info: VolumeController:: Volume=50 Mute =false May 31 10:20:10 volumio volumio[1246]: info: CoreStateMachine::pushState May 31 10:20:10 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:20:10 volumio volumio[1246]: info: CoreCommandRouter::volumioPushState May 31 10:20:10 volumio volumio5-onboarding[1938]: time=2026-05-31T10:20:10.502+03:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" state=STATUS_PAUSED positionMs=133824 volume=50 May 31 10:20:10 volumio volumio5-onboarding[1938]: time=2026-05-31T10:20:10.503+03:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.147:43262 @ 0xc0004f34a0" id=motherearthradio/radio/flac96 title=Metzengerstein May 31 10:20:18 volumio volumio[1246]: info: CoreCommandRouter::volumioPlay May 31 10:20:18 volumio volumio[1246]: info: CoreStateMachine::play index undefined May 31 10:20:18 volumio volumio[1246]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 10:20:18 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:20:18 volumio volumio[1246]: info: CoreStateMachine::startPlaybackTimer May 31 10:20:18 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:20:18 volumio volumio[1246]: info: [MER] ▶️ Playing: https://stream.motherearthradio.de/listen/motherearth/motherearth.flac-lo May 31 10:20:18 volumio volumio[1246]: info: [MER] 🔌 Starting SSE for Radio May 31 10:20:18 volumio volumio[1246]: verbose: ControllerMpd::sendMpdCommand stop May 31 10:20:18 volumio volumio[1246]: info: CoreCommandRouter::volumioPlay May 31 10:20:18 volumio volumio[1246]: info: CoreStateMachine::play index undefined May 31 10:20:18 volumio volumio[1246]: info: CoreStateMachine::setConsumeUpdateService undefined May 31 10:20:18 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:20:18 volumio volumio[1246]: info: CoreStateMachine::startPlaybackTimer May 31 10:20:18 volumio volumio[1246]: info: CorePlayQueue::getTrack 0 May 31 10:20:18 volumio volumio[1246]: info: [MER] ▶️ Playing: https://stream.motherearthradio.de/listen/motherearth/motherearth.flac-lo May 31 10:20:18 volumio volumio[1246]: info: [MER] 🔌 Starting SSE for Radio May 31 10:20:18 volumio volumio[1246]: verbose: ControllerMpd::sendMpdCommand stop May 31 10:20:18 volumio volumio[1246]: info: sendMpdCommand stop took 12 milliseconds May 31 10:20:18 volumio volumio[1246]: info: sendMpdCommand stop took 2 milliseconds May 31 10:20:18 volumio volumio[1246]: verbose: ControllerMpd::sendMpdCommand clear May 31 10:20:18 volumio volumio[1246]: verbose: ControllerMpd::sendMpdCommand clear May 31 10:20:18 volumio volumio[1246]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 10:20:18 volumio volumio[1246]: Error: socket hang up May 31 10:20:18 volumio volumio[1246]: at connResetException (node:internal/errors:720:14) May 31 10:20:18 volumio volumio[1246]: at TLSSocket.socketCloseListener (node:_http_client:468:25) May 31 10:20:18 volumio volumio[1246]: at TLSSocket.emit (node:events:526:35) May 31 10:20:18 volumio volumio[1246]: at node:net:337:12 May 31 10:20:18 volumio volumio[1246]: at TCP.done (node:_tls_wrap:631:7) { May 31 10:20:18 volumio volumio[1246]: code: 'ECONNRESET' May 31 10:20:18 volumio volumio[1246]: } May 31 10:20:18 volumio volumio[1246]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 31 10:20:18 volumio sudo[9925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-31 10:19' May 31 10:20:18 volumio sudo[9925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"