Oct 15 16:02:05 volumio-2063 volumio[2335]: info: Preload queue cleared Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::ClearQueue Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::stop Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::stPlaybackTimer Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::updateTrackBlock Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrackBlock Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::pushState Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 1 Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushState Oct 15 16:02:05 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output update for this device Oct 15 16:02:05 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 1 Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::serviceStop Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 1 Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::serviceStop Oct 15 16:02:05 volumio-2063 volumio[2335]: info: [1792072925570] ControllerQobuz::stop Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 15 16:02:05 volumio-2063 volumio[2335]: info: ControllerMpd::stop Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand stop Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CorePlayQueue::clearPlayQueue Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CorePlayQueue::saveQueue Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushQueue Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::addQueueItems Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CorePlayQueue::addQueueItems Oct 15 16:02:05 volumio-2063 volumio[2335]: info: Preload queue cleared Oct 15 16:02:05 volumio-2063 volumio[2335]: info: Adding Item to queue: france-radio/france-info Oct 15 16:02:05 volumio-2063 volumio[2335]: info: Exploding uri france-radio/france-info in service radio_france Oct 15 16:02:05 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance explodeUri uri=france-radio/france-info Oct 15 16:02:05 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance explodeUri OK station=franceinfo Oct 15 16:02:05 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:05.573+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" state=STATUS_STOPPED positionMs=0 volume=100 Oct 15 16:02:05 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:05.573+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" id=qobuz://song/246315785 title="Douce mélancolie" Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushQueue Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CorePlayQueue::saveQueue Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::updateTrackBlock Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrackBlock Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPlay Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::play index 0 Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::stop Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::play index undefined Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::startPlaybackTimer Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetVisibleSources Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 15 16:02:05 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance clearAddPlayTrack station={"id":"france-info","title":"franceinfo","stream":"https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8","metadataId":2,"metadataType":"national"} Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand stop Oct 15 16:02:05 volumio-2063 volumio[2335]: info: FusionDsp - Volumio is not playing Oct 15 16:02:05 volumio-2063 volumio[2335]: info: FusionDsp - Clipped samples monitor stopped Oct 15 16:02:05 volumio-2063 volumio[2335]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] pushState: status=stop stream=qobuz service=qobuz uri=qobuz://song/246315785 [state=IDLE] Oct 15 16:02:05 volumio-2063 sudo[13122]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 15 16:02:05 volumio-2063 sudo[13122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:05 volumio-2063 volumio[2335]: info: Oct 15 16:02:05 volumio-2063 volumio[2335]: ---------------------------- MPD announces state update: player Oct 15 16:02:05 volumio-2063 volumio[2335]: info: sendMpdCommand stop took 21 milliseconds Oct 15 16:02:05 volumio-2063 volumio[2335]: info: ControllerMpd::getState Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand status Oct 15 16:02:05 volumio-2063 volumio[2335]: info: sendMpdCommand stop took 14 milliseconds Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand clear Oct 15 16:02:05 volumio-2063 volumio[2335]: info: Oct 15 16:02:05 volumio-2063 volumio[2335]: ---------------------------- MPD announces system playlist update Oct 15 16:02:05 volumio-2063 volumio[2335]: info: Ignoring MPD Status Update Oct 15 16:02:05 volumio-2063 volumio[2335]: info: sendMpdCommand status took 10 milliseconds Oct 15 16:02:05 volumio-2063 volumio[2335]: info: sendMpdCommand clear took 10 milliseconds Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseState Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand add "https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8" Oct 15 16:02:05 volumio-2063 volumio[2335]: error: updateQueue error: null Oct 15 16:02:05 volumio-2063 volumio[2335]: info: Oct 15 16:02:05 volumio-2063 volumio[2335]: ---------------------------- MPD announces system playlist update Oct 15 16:02:05 volumio-2063 systemd[1]: Stopping peppymeterbasic.service - peppymeterbasic Daemon... Oct 15 16:02:05 volumio-2063 volumio[2335]: info: Ignoring MPD Status Update Oct 15 16:02:05 volumio-2063 volumio[2335]: info: ------------------------------ 7ms Oct 15 16:02:05 volumio-2063 volumio[2335]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 15 16:02:05 volumio-2063 volumio[2335]: info: sendMpdCommand add "https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8" took 4 milliseconds Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseTrackInfo Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand play Oct 15 16:02:05 volumio-2063 volumio[2335]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Oct 15 16:02:05 volumio-2063 volumio[2335]: info: ------------------------------ 17ms Oct 15 16:02:05 volumio-2063 volumio[2335]: info: ------------------------------ 5ms Oct 15 16:02:05 volumio-2063 volumio[2335]: info: sendMpdCommand play took 2 milliseconds Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService radio_france Oct 15 16:02:05 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance BEFORE INITIAL PUSH={"status":"play","service":"radio_france","type":"track","trackType":"webradio","radioType":"Radio France","bitrate":"","title":"franceinfo","name":"franceinfo","artist":"","album":"","albumart":"/albumart?sourceicon=music_service/radio_france/images/radio-france-logo.png","uri":"https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8","streaming":true,"stream":"franceinfo","samplerate":"","bitdepth":"","channels":"","disableUiControls":true,"duration":0,"seek":0} Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::servicePushState Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: STATE SERVICE {"status":"play","service":"radio_france","type":"track","trackType":"webradio","radioType":"Radio France","bitrate":"","title":"franceinfo","name":"franceinfo","artist":"","album":"","albumart":"/albumart?sourceicon=music_service/radio_france/images/radio-france-logo.png","uri":"https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8","streaming":true,"stream":"franceinfo","samplerate":"","bitdepth":"","channels":"","disableUiControls":true,"duration":0,"seek":0} Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: CURRENT POSITION 0 Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::syncState stateService play Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::syncState currentStatus stop Oct 15 16:02:05 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance AFTER INITIAL PUSH={"status":"play","service":"radio_france","type":"track","trackType":"webradio","radioType":"Radio France","bitrate":"","title":"franceinfo","name":"franceinfo","artist":"","album":"","albumart":"/albumart?sourceicon=music_service/radio_france/images/radio-france-logo.png","uri":"https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8","streaming":true,"stream":"franceinfo","samplerate":"","bitdepth":"","channels":"","disableUiControls":true,"duration":0,"seek":0} Oct 15 16:02:05 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance startMetadataTimer franceinfo Oct 15 16:02:05 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance Metadata interval: 5 seconds Oct 15 16:02:05 volumio-2063 volumio[2335]: info: RadioFrance Metadata timer started Oct 15 16:02:05 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance Playback started station=franceinfo Oct 15 16:02:05 volumio-2063 systemd[1]: peppymeterbasic.service: Deactivated successfully. Oct 15 16:02:05 volumio-2063 systemd[1]: Stopped peppymeterbasic.service - peppymeterbasic Daemon. Oct 15 16:02:05 volumio-2063 systemd[1]: peppymeterbasic.service: Consumed 3.243s CPU time. Oct 15 16:02:05 volumio-2063 sudo[13122]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:05 volumio-2063 volumio[2335]: info: peppymeterbasic Daemon Stop Oct 15 16:02:05 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance - franceinfo : Vivons bien informés. Le réflexe info Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService radio_france Oct 15 16:02:05 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance METADATA PUSH station=franceinfo artist= title=franceinfo : Vivons bien informés. Le réflexe info Oct 15 16:02:05 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance BEFORE METADATA PUSH={"status":"play","service":"radio_france","type":"track","trackType":"webradio","radioType":"Radio France","bitrate":"","title":"franceinfo : Vivons bien informés. Le réflexe info","name":"franceinfo","artist":"","album":"","albumart":"https://www.radiofrance.fr/pikapi/images/52bb749e-f832-4dd1-ba0a-8c5d11e0aa3a/600x600?webp=false","uri":"https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8","streaming":true,"stream":"franceinfo","samplerate":"","bitdepth":"","channels":"","disableUiControls":true,"duration":0,"seek":0} Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::servicePushState Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: STATE SERVICE {"status":"play","service":"radio_france","type":"track","trackType":"webradio","radioType":"Radio France","bitrate":"","title":"franceinfo : Vivons bien informés. Le réflexe info","name":"franceinfo","artist":"","album":"","albumart":"https://www.radiofrance.fr/pikapi/images/52bb749e-f832-4dd1-ba0a-8c5d11e0aa3a/600x600?webp=false","uri":"https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8","streaming":true,"stream":"franceinfo","samplerate":"","bitdepth":"","channels":"","disableUiControls":true,"duration":0,"seek":0} Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: CURRENT POSITION 0 Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::syncState stateService play Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::syncState currentStatus play Oct 15 16:02:05 volumio-2063 volumio[2335]: info: Received an update from plugin. extracting info from payload Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::pushState Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushState Oct 15 16:02:05 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output update for this device Oct 15 16:02:05 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreStateMachine::pushState Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushState Oct 15 16:02:05 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output update for this device Oct 15 16:02:05 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:05 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance Metadata PUSH done Oct 15 16:02:05 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:05.892+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" state=STATUS_PLAYING positionMs=0 volume=100 Oct 15 16:02:05 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:05.892+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" id=https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 title="franceinfo : Vivons bien informés. Le réflexe info" Oct 15 16:02:05 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:05.892+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" state=STATUS_PLAYING positionMs=0 volume=100 Oct 15 16:02:05 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:05.893+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" id=https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 title="franceinfo : Vivons bien informés. Le réflexe info" Oct 15 16:02:05 volumio-2063 volumio[2335]: info: FusionDsp - Volumio is playing Oct 15 16:02:05 volumio-2063 volumio[2335]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Oct 15 16:02:05 volumio-2063 volumio[2335]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 15 16:02:05 volumio-2063 volumio[2335]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 15 16:02:05 volumio-2063 sudo[13141]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 15 16:02:05 volumio-2063 sudo[13141]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:05 volumio-2063 sudo[13149]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 15 16:02:05 volumio-2063 sudo[13149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:05 volumio-2063 volumio[2335]: info: [LastFM] Current track does not have sufficient metadata: Missing artist. Not a composite title! franceinfo : Vivons bien informés. Le réflexe info Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] pushState: status=play stream=true service=webradio uri=https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 [state=IDLE] Oct 15 16:02:05 volumio-2063 volumio[2335]: info: [StreamWatchdog] IDLE → WATCHING Oct 15 16:02:05 volumio-2063 volumio[2335]: info: [StreamWatchdog] Stream probe scheduled every 30s Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] pushState: status=play stream=true service=webradio uri=https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 [state=WATCHING] Oct 15 16:02:05 volumio-2063 volumio[2335]: info: FusionDsp - Clipping Monitor started Oct 15 16:02:05 volumio-2063 volumio[2335]: info: Oct 15 16:02:05 volumio-2063 volumio[2335]: ---------------------------- MPD announces state update: player Oct 15 16:02:05 volumio-2063 volumio[2335]: info: ControllerMpd::getState Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand status Oct 15 16:02:05 volumio-2063 volumio[2335]: info: Oct 15 16:02:05 volumio-2063 volumio[2335]: ---------------------------- MPD announces state update: player Oct 15 16:02:05 volumio-2063 volumio[2335]: info: sendMpdCommand status took 10 milliseconds Oct 15 16:02:05 volumio-2063 volumio[2335]: info: ControllerMpd::getState Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand status Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseState Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 16:02:05 volumio-2063 volumio[2335]: info: sendMpdCommand status took 0 milliseconds Oct 15 16:02:05 volumio-2063 volumio[2335]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseState Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseTrackInfo Oct 15 16:02:05 volumio-2063 volumio[2335]: info: ControllerMpd::pushState Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::servicePushState Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current radio_france Received mpd Oct 15 16:02:05 volumio-2063 volumio[2335]: info: ------------------------------ 12ms Oct 15 16:02:05 volumio-2063 volumio[2335]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 15 16:02:05 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseTrackInfo Oct 15 16:02:05 volumio-2063 volumio[2335]: info: ControllerMpd::pushState Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CoreCommandRouter::servicePushState Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:05 volumio-2063 volumio[2335]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current radio_france Received mpd Oct 15 16:02:05 volumio-2063 volumio[2335]: info: ------------------------------ 1ms Oct 15 16:02:05 volumio-2063 systemd[1]: Started peppymeterbasic.service - peppymeterbasic Daemon. Oct 15 16:02:05 volumio-2063 sudo[13141]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:05 volumio-2063 sudo[13149]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:05 volumio-2063 volumio[2335]: info: peppymeterbasic Daemon Started Oct 15 16:02:05 volumio-2063 volumio[2335]: info: peppymeterbasic Daemon Started Oct 15 16:02:06 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] Probe PASS (HTTP 200): https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 Oct 15 16:02:06 volumio-2063 volumio[2335]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Oct 15 16:02:06 volumio-2063 volumio[2335]: info: FusionDsp - ---- read samplerate from file: 48000 Oct 15 16:02:06 volumio-2063 volumio[2335]: info: camilladsp stopping service pid 12922... Oct 15 16:02:06 volumio-2063 volumio[13160]: libpng warning: iCCP: known incorrect sRGB profile Oct 15 16:02:06 volumio-2063 volumio[2335]: info: camilladsp service terminated, instance 1 Oct 15 16:02:06 volumio-2063 volumio[2335]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 15 16:02:06 volumio-2063 volumio[13160]: libpng warning: iCCP: known incorrect sRGB profile Oct 15 16:02:06 volumio-2063 volumio[2335]: info: camilladsp service started and running in background, instance 1 Oct 15 16:02:06 volumio-2063 volumio[2335]: info: FusionDsp - Clipping Monitor reconnecting in 2000ms Oct 15 16:02:06 volumio-2063 volumio[13160]: libpng warning: iCCP: known incorrect sRGB profile Oct 15 16:02:08 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService radio_france Oct 15 16:02:08 volumio-2063 volumio[2335]: info: CoreCommandRouter::servicePushState Oct 15 16:02:08 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:08 volumio-2063 volumio[2335]: verbose: STATE SERVICE {"status":"play","service":"radio_france","type":"track","trackType":"webradio","radioType":"Radio France","bitrate":"franceinfo","title":"franceinfo : Vivons bien informés. Le réflexe info","name":"franceinfo","artist":"","album":"","albumart":"https://www.radiofrance.fr/pikapi/images/52bb749e-f832-4dd1-ba0a-8c5d11e0aa3a/600x600?webp=false","uri":"https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8","streaming":true,"stream":"franceinfo","samplerate":"","bitdepth":"","channels":"","disableUiControls":true,"duration":0,"seek":0} Oct 15 16:02:08 volumio-2063 volumio[2335]: verbose: CURRENT POSITION 0 Oct 15 16:02:08 volumio-2063 volumio[2335]: info: CoreStateMachine::syncState stateService play Oct 15 16:02:08 volumio-2063 volumio[2335]: info: CoreStateMachine::syncState currentStatus play Oct 15 16:02:08 volumio-2063 volumio[2335]: info: Received an update from plugin. extracting info from payload Oct 15 16:02:08 volumio-2063 volumio[2335]: info: CoreStateMachine::pushState Oct 15 16:02:08 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 16:02:08 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushState Oct 15 16:02:08 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output update for this device Oct 15 16:02:08 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output Oct 15 16:02:08 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:08 volumio-2063 volumio[2335]: info: CoreStateMachine::pushState Oct 15 16:02:08 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushState Oct 15 16:02:08 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output update for this device Oct 15 16:02:08 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output Oct 15 16:02:08 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:08 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:08.622+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" state=STATUS_PLAYING positionMs=2531 volume=100 Oct 15 16:02:08 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:08.623+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" state=STATUS_PLAYING positionMs=2531 volume=100 Oct 15 16:02:08 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:08.623+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" id=https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 title="franceinfo : Vivons bien informés. Le réflexe info" Oct 15 16:02:08 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:08.623+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" id=https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 title="franceinfo : Vivons bien informés. Le réflexe info" Oct 15 16:02:08 volumio-2063 volumio[2335]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 15 16:02:08 volumio-2063 volumio[2335]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 15 16:02:08 volumio-2063 sudo[13181]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 15 16:02:08 volumio-2063 sudo[13181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:08 volumio-2063 sudo[13184]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 15 16:02:08 volumio-2063 sudo[13184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:08 volumio-2063 sudo[13181]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:08 volumio-2063 volumio[2335]: info: peppymeterbasic Daemon Started Oct 15 16:02:08 volumio-2063 sudo[13184]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:08 volumio-2063 volumio[2335]: info: peppymeterbasic Daemon Started Oct 15 16:02:08 volumio-2063 volumio[2335]: info: FusionDsp - Clipping Monitor started Oct 15 16:02:14 volumio-2063 volumio[2335]: info: Preload queue cleared Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreStateMachine::ClearQueue Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreStateMachine::stop Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreStateMachine::stPlaybackTimer Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreStateMachine::updateTrackBlock Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrackBlock Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreStateMachine::pushState Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushState Oct 15 16:02:14 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output update for this device Oct 15 16:02:14 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreStateMachine::serviceStop Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreCommandRouter::serviceStop Oct 15 16:02:14 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand stop Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CorePlayQueue::clearPlayQueue Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CorePlayQueue::saveQueue Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushQueue Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreStateMachine::addQueueItems Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CorePlayQueue::addQueueItems Oct 15 16:02:14 volumio-2063 volumio[2335]: info: Preload queue cleared Oct 15 16:02:14 volumio-2063 volumio[2335]: info: Adding Item to queue: france-radio/france-culture Oct 15 16:02:14 volumio-2063 volumio[2335]: info: Exploding uri france-radio/france-culture in service radio_france Oct 15 16:02:14 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance explodeUri uri=france-radio/france-culture Oct 15 16:02:14 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance explodeUri OK station=France Culture Oct 15 16:02:14 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:14.715+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" state=STATUS_STOPPED positionMs=0 volume=100 Oct 15 16:02:14 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:14.715+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" id=https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 title=franceinfo Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushQueue Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CorePlayQueue::saveQueue Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreStateMachine::updateTrackBlock Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrackBlock Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPlay Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreStateMachine::play index 0 Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreStateMachine::stop Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreStateMachine::play index undefined Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreStateMachine::startPlaybackTimer Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetVisibleSources Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 15 16:02:14 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 15 16:02:14 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance clearAddPlayTrack station={"id":"france-culture","title":"France Culture","stream":"https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8","metadataId":5,"metadataType":"national"} Oct 15 16:02:14 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand stop Oct 15 16:02:14 volumio-2063 volumio[2335]: info: FusionDsp - Volumio is not playing Oct 15 16:02:14 volumio-2063 volumio[2335]: info: FusionDsp - Clipped samples monitor stopped Oct 15 16:02:14 volumio-2063 volumio[2335]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 15 16:02:14 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] pushState: status=stop stream=webradio service=radio_france uri=https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 [state=WATCHING] Oct 15 16:02:14 volumio-2063 volumio[2335]: info: [StreamWatchdog] Unexpected stop while watching a stream — confirming via probe Oct 15 16:02:14 volumio-2063 volumio[2335]: info: [StreamWatchdog] WATCHING → SUSPECT Oct 15 16:02:14 volumio-2063 sudo[13194]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 15 16:02:14 volumio-2063 sudo[13194]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:14 volumio-2063 systemd[1]: Stopping peppymeterbasic.service - peppymeterbasic Daemon... Oct 15 16:02:14 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] Probe PASS (HTTP 200): https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 Oct 15 16:02:14 volumio-2063 volumio[2335]: info: [StreamWatchdog] Probe confirms the stream is reachable — false alarm Oct 15 16:02:14 volumio-2063 volumio[2335]: info: [StreamWatchdog] SUSPECT → WATCHING Oct 15 16:02:14 volumio-2063 systemd[1]: peppymeterbasic.service: Deactivated successfully. Oct 15 16:02:14 volumio-2063 systemd[1]: Stopped peppymeterbasic.service - peppymeterbasic Daemon. Oct 15 16:02:14 volumio-2063 systemd[1]: peppymeterbasic.service: Consumed 1.017s CPU time. Oct 15 16:02:14 volumio-2063 sudo[13194]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:14 volumio-2063 volumio[2335]: info: peppymeterbasic Daemon Stop Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:17 volumio-2063 volumio[2335]: warn: [StreamWatchdog] Stream is reachable but playback is stop — the queue died under us Oct 15 16:02:17 volumio-2063 volumio[2335]: info: [StreamWatchdog] restream_recovery_total reason=stopped_after_probe_pass count=1 Oct 15 16:02:17 volumio-2063 volumio[2335]: info: [StreamWatchdog] Light recovery 1/3 — reissuing https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreStateMachine::ClearQueue Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreStateMachine::stop Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CorePlayQueue::clearPlayQueue Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CorePlayQueue::saveQueue Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushQueue Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreStateMachine::addQueueItems Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CorePlayQueue::addQueueItems Oct 15 16:02:17 volumio-2063 volumio[2335]: info: Preload queue cleared Oct 15 16:02:17 volumio-2063 volumio[2335]: info: Adding Item to queue: https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushQueue Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CorePlayQueue::saveQueue Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreStateMachine::updateTrackBlock Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrackBlock Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPlay Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreStateMachine::play index 0 Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreStateMachine::stop Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreStateMachine::play index undefined Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreStateMachine::startPlaybackTimer Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetVisibleSources Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 15 16:02:17 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 15 16:02:17 volumio-2063 volumio[2335]: info: [1792072937824] ControllerWebradio::clearAddPlayTrack Oct 15 16:02:17 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand stop Oct 15 16:02:18 volumio-2063 volumio[2335]: info: sendMpdCommand stop took 3712 milliseconds Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreCommandRouter::servicePushState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreStateMachine::pushState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output update for this device Oct 15 16:02:18 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:18 volumio-2063 volumio[2335]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received radio_france Oct 15 16:02:18 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:18.429+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" state=STATUS_STOPPED positionMs=501 volume=100 Oct 15 16:02:18 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:18.429+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" id=https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 title="franceinfo : Vivons bien informés. Le réflexe info" Oct 15 16:02:18 volumio-2063 volumio[2335]: info: Oct 15 16:02:18 volumio-2063 volumio[2335]: ---------------------------- MPD announces state update: player Oct 15 16:02:18 volumio-2063 volumio[2335]: info: ControllerMpd::getState Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand status Oct 15 16:02:18 volumio-2063 volumio[2335]: info: sendMpdCommand stop took 3713 milliseconds Oct 15 16:02:18 volumio-2063 volumio[2335]: info: sendMpdCommand stop took 608 milliseconds Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand clear Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand clear Oct 15 16:02:18 volumio-2063 volumio[2335]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 15 16:02:18 volumio-2063 sudo[13214]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 15 16:02:18 volumio-2063 sudo[13214]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] pushState: status=stop stream=webradio service=webradio uri=https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 [state=WATCHING] Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] Stop is our own reissue — ignoring Oct 15 16:02:18 volumio-2063 volumio[2335]: info: Oct 15 16:02:18 volumio-2063 volumio[2335]: ---------------------------- MPD announces system playlist update Oct 15 16:02:18 volumio-2063 volumio[2335]: info: Ignoring MPD Status Update Oct 15 16:02:18 volumio-2063 volumio[2335]: info: sendMpdCommand status took 20 milliseconds Oct 15 16:02:18 volumio-2063 volumio[2335]: info: sendMpdCommand clear took 20 milliseconds Oct 15 16:02:18 volumio-2063 volumio[2335]: info: sendMpdCommand clear took 20 milliseconds Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseState Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand add "https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8" Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand add "https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8" Oct 15 16:02:18 volumio-2063 volumio[2335]: error: updateQueue error: null Oct 15 16:02:18 volumio-2063 volumio[2335]: info: Oct 15 16:02:18 volumio-2063 volumio[2335]: ---------------------------- MPD announces system playlist update Oct 15 16:02:18 volumio-2063 volumio[2335]: info: Ignoring MPD Status Update Oct 15 16:02:18 volumio-2063 volumio[2335]: info: ------------------------------ 2ms Oct 15 16:02:18 volumio-2063 volumio[2335]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 15 16:02:18 volumio-2063 volumio[2335]: info: sendMpdCommand add "https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8" took 2 milliseconds Oct 15 16:02:18 volumio-2063 volumio[2335]: info: sendMpdCommand add "https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8" took 2 milliseconds Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseTrackInfo Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand play Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand play Oct 15 16:02:18 volumio-2063 volumio[2335]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Oct 15 16:02:18 volumio-2063 volumio[2335]: info: ------------------------------ 25ms Oct 15 16:02:18 volumio-2063 volumio[2335]: info: ------------------------------ 2ms Oct 15 16:02:18 volumio-2063 volumio[2335]: info: sendMpdCommand play took 1 milliseconds Oct 15 16:02:18 volumio-2063 volumio[2335]: info: sendMpdCommand play took 1 milliseconds Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService radio_france Oct 15 16:02:18 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance BEFORE INITIAL PUSH={"status":"stop","service":"radio_france","type":"track","trackType":"webradio","radioType":"Radio France","bitrate":"","title":"France Culture","name":"France Culture","artist":"","album":"","albumart":"/albumart?sourceicon=music_service/radio_france/images/radio-france-logo.png","uri":"https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8","streaming":true,"stream":"France Culture","samplerate":"","bitdepth":"","channels":"","disableUiControls":true,"duration":0,"seek":0} Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreCommandRouter::servicePushState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreStateMachine::pushState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output update for this device Oct 15 16:02:18 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: STATE SERVICE {"status":"stop","service":"radio_france","type":"track","trackType":"webradio","radioType":"Radio France","bitrate":"","title":"France Culture","name":"France Culture","artist":"","album":"","albumart":"/albumart?sourceicon=music_service/radio_france/images/radio-france-logo.png","uri":"https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8","streaming":true,"stream":"France Culture","samplerate":"","bitdepth":"","channels":"","disableUiControls":true,"duration":0,"seek":0} Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: CURRENT POSITION 0 Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreStateMachine::syncState stateService stop Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreStateMachine::syncState currentStatus stop Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreStateMachine::pushState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output update for this device Oct 15 16:02:18 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: No code Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreStateMachine::pushState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output update for this device Oct 15 16:02:18 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance AFTER INITIAL PUSH={"status":"stop","service":"radio_france","type":"track","trackType":"webradio","radioType":"Radio France","bitrate":"","title":"France Culture","name":"France Culture","artist":"","album":"","albumart":"/albumart?sourceicon=music_service/radio_france/images/radio-france-logo.png","uri":"https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8","streaming":true,"stream":"France Culture","samplerate":"","bitdepth":"","channels":"","disableUiControls":true,"duration":0,"seek":0} Oct 15 16:02:18 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance startMetadataTimer France Culture Oct 15 16:02:18 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance Metadata interval: 5 seconds Oct 15 16:02:18 volumio-2063 volumio[2335]: info: RadioFrance Metadata timer started Oct 15 16:02:18 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance Playback started station=France Culture Oct 15 16:02:18 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:18.470+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" state=STATUS_PLAYING positionMs=608 volume=100 Oct 15 16:02:18 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:18.470+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" id=https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 title="franceinfo : Vivons bien informés. Le réflexe info" Oct 15 16:02:18 volumio-2063 sudo[13214]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:18 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:18.474+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" state=STATUS_PLAYING positionMs=608 volume=100 Oct 15 16:02:18 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:18.474+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" id=https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 title="franceinfo : Vivons bien informés. Le réflexe info" Oct 15 16:02:18 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:18.475+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" state=STATUS_PLAYING positionMs=608 volume=100 Oct 15 16:02:18 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:18.475+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" id=https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 title="franceinfo : Vivons bien informés. Le réflexe info" Oct 15 16:02:18 volumio-2063 volumio[2335]: info: FusionDsp - Volumio is playing Oct 15 16:02:18 volumio-2063 volumio[2335]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Oct 15 16:02:18 volumio-2063 volumio[2335]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 15 16:02:18 volumio-2063 volumio[2335]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 15 16:02:18 volumio-2063 sudo[13217]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 15 16:02:18 volumio-2063 sudo[13217]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:18 volumio-2063 volumio[2335]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 15 16:02:18 volumio-2063 sudo[13220]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 15 16:02:18 volumio-2063 sudo[13220]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:18 volumio-2063 sudo[13222]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 15 16:02:18 volumio-2063 sudo[13222]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] pushState: status=play stream=true service=webradio uri=https://stream.radiofrance.fr/franceinfo/franceinfo_hifi.m3u8 [state=WATCHING] Oct 15 16:02:18 volumio-2063 volumio[2335]: info: peppymeterbasic Daemon Stop Oct 15 16:02:18 volumio-2063 volumio[2335]: info: FusionDsp - Clipping Monitor started Oct 15 16:02:18 volumio-2063 systemd[1]: Started peppymeterbasic.service - peppymeterbasic Daemon. Oct 15 16:02:18 volumio-2063 sudo[13217]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:18 volumio-2063 volumio[2335]: info: peppymeterbasic Daemon Started Oct 15 16:02:18 volumio-2063 sudo[13220]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:18 volumio-2063 sudo[13222]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:18 volumio-2063 volumio[2335]: info: peppymeterbasic Daemon Started Oct 15 16:02:18 volumio-2063 volumio[2335]: info: peppymeterbasic Daemon Started Oct 15 16:02:18 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance - France Culture, l'esprit d'ouverture Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService radio_france Oct 15 16:02:18 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance METADATA PUSH station=France Culture artist= title=France Culture, l'esprit d'ouverture Oct 15 16:02:18 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance BEFORE METADATA PUSH={"status":"play","service":"radio_france","type":"track","trackType":"webradio","radioType":"Radio France","bitrate":"","title":"France Culture, l'esprit d'ouverture","name":"France Culture","artist":"","album":"","albumart":"https://www.radiofrance.fr/pikapi/images/0bae0a11-b29d-4d74-9844-40a11e51c219/600x600?webp=false","uri":"https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8","streaming":true,"stream":"France Culture","samplerate":"","bitdepth":"","channels":"","disableUiControls":true,"duration":0,"seek":0} Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreCommandRouter::servicePushState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: STATE SERVICE {"status":"play","service":"radio_france","type":"track","trackType":"webradio","radioType":"Radio France","bitrate":"","title":"France Culture, l'esprit d'ouverture","name":"France Culture","artist":"","album":"","albumart":"https://www.radiofrance.fr/pikapi/images/0bae0a11-b29d-4d74-9844-40a11e51c219/600x600?webp=false","uri":"https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8","streaming":true,"stream":"France Culture","samplerate":"","bitdepth":"","channels":"","disableUiControls":true,"duration":0,"seek":0} Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: CURRENT POSITION 0 Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreStateMachine::syncState stateService play Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreStateMachine::syncState currentStatus stop Oct 15 16:02:18 volumio-2063 volumio[2335]: info: RadioFrance[DEBUG] RadioFrance Metadata PUSH done Oct 15 16:02:18 volumio-2063 volumio[2335]: info: Oct 15 16:02:18 volumio-2063 volumio[2335]: ---------------------------- MPD announces state update: player Oct 15 16:02:18 volumio-2063 volumio[2335]: info: ControllerMpd::getState Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand status Oct 15 16:02:18 volumio-2063 volumio[2335]: info: Oct 15 16:02:18 volumio-2063 volumio[2335]: ---------------------------- MPD announces state update: player Oct 15 16:02:18 volumio-2063 volumio[2335]: info: ControllerMpd::getState Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand status Oct 15 16:02:18 volumio-2063 volumio[2335]: info: sendMpdCommand status took 1 milliseconds Oct 15 16:02:18 volumio-2063 volumio[2335]: info: sendMpdCommand status took 1 milliseconds Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseState Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseState Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 16:02:18 volumio-2063 volumio[2335]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 15 16:02:18 volumio-2063 volumio[2335]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseTrackInfo Oct 15 16:02:18 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseTrackInfo Oct 15 16:02:18 volumio-2063 volumio[2335]: info: ControllerMpd::pushState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreCommandRouter::servicePushState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current radio_france Received mpd Oct 15 16:02:18 volumio-2063 volumio[2335]: info: ControllerMpd::pushState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CoreCommandRouter::servicePushState Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:18 volumio-2063 volumio[2335]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current radio_france Received mpd Oct 15 16:02:18 volumio-2063 volumio[2335]: info: ------------------------------ 8ms Oct 15 16:02:18 volumio-2063 volumio[2335]: info: ------------------------------ 3ms Oct 15 16:02:18 volumio-2063 volumio[2335]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Oct 15 16:02:18 volumio-2063 volumio[2335]: info: FusionDsp - ---- read samplerate from file: 48000 Oct 15 16:02:19 volumio-2063 volumio[2335]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 15 16:02:19 volumio-2063 volumio[2335]: info: FusionDsp - Clipping Monitor reconnecting in 4000ms Oct 15 16:02:19 volumio-2063 volumio[2335]: info: camilladsp respawn in 100 ms (attempt 1/10) Oct 15 16:02:19 volumio-2063 volumio[13228]: libpng warning: iCCP: known incorrect sRGB profile Oct 15 16:02:19 volumio-2063 volumio[13228]: libpng warning: iCCP: known incorrect sRGB profile Oct 15 16:02:19 volumio-2063 volumio[13228]: libpng warning: iCCP: known incorrect sRGB profile Oct 15 16:02:21 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService radio_france Oct 15 16:02:21 volumio-2063 volumio[2335]: info: CoreCommandRouter::servicePushState Oct 15 16:02:21 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:02:21 volumio-2063 volumio[2335]: verbose: STATE SERVICE {"status":"play","service":"radio_france","type":"track","trackType":"webradio","radioType":"Radio France","bitrate":"France Culture","title":"France Culture, l'esprit d'ouverture","name":"France Culture","artist":"","album":"","albumart":"https://www.radiofrance.fr/pikapi/images/0bae0a11-b29d-4d74-9844-40a11e51c219/600x600?webp=false","uri":"https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8","streaming":true,"stream":"France Culture","samplerate":"","bitdepth":"","channels":"","disableUiControls":true,"duration":0,"seek":0} Oct 15 16:02:21 volumio-2063 volumio[2335]: verbose: CURRENT POSITION 0 Oct 15 16:02:21 volumio-2063 volumio[2335]: info: CoreStateMachine::syncState stateService play Oct 15 16:02:21 volumio-2063 volumio[2335]: info: CoreStateMachine::syncState currentStatus play Oct 15 16:02:21 volumio-2063 volumio[2335]: info: Received an update from plugin. extracting info from payload Oct 15 16:02:21 volumio-2063 volumio[2335]: info: CoreStateMachine::pushState Oct 15 16:02:21 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 16:02:21 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushState Oct 15 16:02:21 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output update for this device Oct 15 16:02:21 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output Oct 15 16:02:21 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:21 volumio-2063 volumio[2335]: info: CoreStateMachine::pushState Oct 15 16:02:21 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushState Oct 15 16:02:21 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output update for this device Oct 15 16:02:21 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output Oct 15 16:02:21 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:21 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:21.472+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" state=STATUS_PLAYING positionMs=2743 volume=100 Oct 15 16:02:21 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:21.472+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" state=STATUS_PLAYING positionMs=2743 volume=100 Oct 15 16:02:21 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:21.472+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" id=https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8 title="France Culture, l'esprit d'ouverture" Oct 15 16:02:21 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:21.472+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" id=https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8 title="France Culture, l'esprit d'ouverture" Oct 15 16:02:21 volumio-2063 volumio[2335]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 15 16:02:21 volumio-2063 volumio[2335]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 15 16:02:21 volumio-2063 sudo[13252]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 15 16:02:21 volumio-2063 sudo[13252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:21 volumio-2063 volumio[2335]: info: [LastFM] Current track does not have sufficient metadata: Missing artist. Not a composite title! France Culture, l'esprit d'ouverture Oct 15 16:02:21 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] pushState: status=play stream=true service=webradio uri=https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8 [state=WATCHING] Oct 15 16:02:21 volumio-2063 volumio[2335]: info: [StreamWatchdog] Watched stream URI updated: https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8 Oct 15 16:02:21 volumio-2063 sudo[13255]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 15 16:02:21 volumio-2063 sudo[13255]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:21 volumio-2063 sudo[13252]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:21 volumio-2063 volumio[2335]: info: peppymeterbasic Daemon Started Oct 15 16:02:21 volumio-2063 sudo[13255]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:21 volumio-2063 volumio[2335]: info: peppymeterbasic Daemon Started Oct 15 16:02:23 volumio-2063 volumio[2335]: info: FusionDsp - Clipping Monitor started Oct 15 16:02:25 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:25 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] Playback confirmed active after the probe passed Oct 15 16:02:26 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:26.691+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.178.109:49302 @ 0xc0003df920" latency=8.668898ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Oct 15 16:02:26 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:26.720+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.109:49302 @ 0xc0003df920" latency=925.802µs timeout=10s Oct 15 16:02:26 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:26.791+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.109:49302 @ 0xc0003df920" latency=925.802µs timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=70.129568ms Oct 15 16:02:26 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:26.803+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.109:49302 @ 0xc0003df920" latency=925.802µs timeout=10s endpoint=http://pushupdates.volumio.org duration=81.434737ms Oct 15 16:02:26 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:26.842+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.109:49302 @ 0xc0003df920" latency=925.802µs timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=121.204174ms Oct 15 16:02:26 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:26.844+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.109:49302 @ 0xc0003df920" latency=925.802µs timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=122.64414ms Oct 15 16:02:26 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:26.847+02:00 level=ERROR msg="endpoint is not reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.109:49302 @ 0xc0003df920" latency=925.802µs timeout=10s endpoint=http://cddb.volumio.org duration=126.491214ms error="Head \"http://gnudb.gnudb.org/~cddb/cddb.cgi/\": EOF" Oct 15 16:02:26 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:26.903+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.109:49302 @ 0xc0003df920" latency=925.802µs timeout=10s endpoint=https://www.googleapis.com duration=182.871383ms Oct 15 16:02:26 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:26.918+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.109:49302 @ 0xc0003df920" latency=925.802µs timeout=10s endpoint=https://functions.volumio.cloud duration=197.167195ms Oct 15 16:02:26 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:26.933+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.109:49302 @ 0xc0003df920" latency=925.802µs timeout=10s endpoint=https://functions.volumio.cloud duration=211.97892ms Oct 15 16:02:26 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:26.940+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.109:49302 @ 0xc0003df920" latency=925.802µs timeout=10s endpoint=https://google.com duration=218.790691ms Oct 15 16:02:26 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:26.943+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.109:49302 @ 0xc0003df920" latency=925.802µs timeout=10s endpoint=http://plugins.volumio.org duration=221.455431ms Oct 15 16:02:26 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:26.944+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.109:49302 @ 0xc0003df920" latency=925.802µs timeout=10s endpoint=https://securetoken.googleapis.com duration=223.832835ms Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 15 16:02:27 volumio-2063 volumio[2335]: verbose: New Socket.io Connection to 192.168.178.36 from 192.168.178.109 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 VolumioApp/6.260930.0 Engine version: 3 Transport: websocket Total Clients: 14 Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CALLMETHOD: user_interface artwork_one getSettings [object Object] Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: artwork_one , getSettings Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CALLMETHOD: miscellanea artwork_companion getSettings [object Object] Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: artwork_companion , getSettings Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:27 volumio-2063 volumio[2335]: info: Received Get System Info Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 15 16:02:27 volumio-2063 volumio[2335]: info: Discovery: Getting this device information Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetVisibleSources Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: alarm-clock , getSleep Oct 15 16:02:27 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:27.074+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.109:49302 @ 0xc0003df920" latency=925.802µs timeout=10s endpoint=https://myvolumio.firebaseio.com duration=353.68592ms Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetQueue Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreStateMachine::getQueue Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CorePlayQueue::getQueue Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 15 16:02:27 volumio-2063 volumio[2335]: info: Listing playlists Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Oct 15 16:02:27 volumio-2063 sudo[13280]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Oct 15 16:02:27 volumio-2063 sudo[13280]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:27 volumio-2063 sudo[13280]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:27 volumio-2063 sudo[13285]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 15 16:02:27 volumio-2063 sudo[13285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:27 volumio-2063 sudo[13294]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 15 16:02:27 volumio-2063 sudo[13294]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:27 volumio-2063 sudo[13300]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 15 16:02:27 volumio-2063 sudo[13300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:27 volumio-2063 sudo[13285]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CALLMETHOD: user_interface artwork_one getSettings [object Object] Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: artwork_one , getSettings Oct 15 16:02:27 volumio-2063 sudo[13310]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 15 16:02:27 volumio-2063 sudo[13310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:27 volumio-2063 sudo[13310]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CALLMETHOD: miscellanea artwork_companion getSettings [object Object] Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: artwork_companion , getSettings Oct 15 16:02:27 volumio-2063 sudo[13294]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:27 volumio-2063 sudo[13300]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetVisibleSources Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 15 16:02:27 volumio-2063 sudo[13318]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: last_100 , handleBrowseUri Oct 15 16:02:27 volumio-2063 sudo[13318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CURURI: albums:// Oct 15 16:02:27 volumio-2063 volumio[2335]: info: listAlbums - loading Albums from cache Oct 15 16:02:27 volumio-2063 sudo[13318]: pam_unix(sudo:session): session closed for user root Oct 15 16:02:27 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:02:27.148+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="192.168.178.109:49302 @ 0xc0003df920" latency=925.802µs timeout=10s endpoint=https://database.volumio.cloud duration=426.58913ms Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 15 16:02:27 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 15 16:02:32 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 15 16:02:32 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 15 16:02:32 volumio-2063 volumio[2335]: info: CURURI: albums:// Oct 15 16:02:32 volumio-2063 volumio[2335]: info: listAlbums - loading Albums from cache Oct 15 16:02:32 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 15 16:02:32 volumio-2063 volumio[2335]: info: CURURI: playlists Oct 15 16:02:32 volumio-2063 volumio[2335]: info: Listing playlists Oct 15 16:02:32 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 15 16:02:32 volumio-2063 volumio[2335]: info: CURURI: genres:// Oct 15 16:02:32 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 15 16:02:32 volumio-2063 volumio[2335]: info: CURURI: artists:// Oct 15 16:02:35 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] Probe PASS (HTTP 200): https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8 Oct 15 16:02:48 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 15 16:02:48 volumio-2063 volumio[2335]: info: CURURI: artists:// Oct 15 16:02:48 volumio-2063 volumio[2335]: info: Preload queue cleared Oct 15 16:03:06 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] Probe PASS (HTTP 200): https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8 Oct 15 16:03:07 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 15 16:03:07 volumio-2063 volumio[2335]: info: CURURI: artists://101%20Michael%20Bolton Oct 15 16:03:07 volumio-2063 volumio[2335]: info: Preload queue cleared Oct 15 16:03:07 volumio-2063 volumio[2335]: info: Preload queue cleared Oct 15 16:03:09 volumio-2063 volumio[2335]: info: Preload queue cleared Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreStateMachine::ClearQueue Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreStateMachine::stop Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreStateMachine::stPlaybackTimer Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreStateMachine::updateTrackBlock Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrackBlock Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreStateMachine::pushState Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushState Oct 15 16:03:09 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output update for this device Oct 15 16:03:09 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreStateMachine::serviceStop Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreCommandRouter::serviceStop Oct 15 16:03:09 volumio-2063 volumio[2335]: info: [1792072989689] ControllerWebradio::stop Oct 15 16:03:09 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand stop Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CorePlayQueue::clearPlayQueue Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CorePlayQueue::saveQueue Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushQueue Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreStateMachine::addQueueItems Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CorePlayQueue::addQueueItems Oct 15 16:03:09 volumio-2063 volumio[2335]: info: Preload queue cleared Oct 15 16:03:09 volumio-2063 volumio[2335]: info: Adding Item to queue: artists://101%20Michael%20Bolton Oct 15 16:03:09 volumio-2063 volumio[2335]: info: Exploding uri artists://101%20Michael%20Bolton in service mpd Oct 15 16:03:09 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:03:09.692+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" state=STATUS_STOPPED positionMs=0 volume=100 Oct 15 16:03:09 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:03:09.692+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" id=https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8 title="France Culture" Oct 15 16:03:09 volumio-2063 volumio[2335]: info: FusionDsp - Volumio is not playing Oct 15 16:03:09 volumio-2063 volumio[2335]: info: FusionDsp - Clipped samples monitor stopped Oct 15 16:03:09 volumio-2063 volumio[2335]: info: PeppyMeterBasic ---peppymeterbasic status stop Oct 15 16:03:09 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] pushState: status=stop stream=webradio service=webradio uri=https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8 [state=WATCHING] Oct 15 16:03:09 volumio-2063 volumio[2335]: info: [StreamWatchdog] Unexpected stop while watching a stream — confirming via probe Oct 15 16:03:09 volumio-2063 volumio[2335]: info: [StreamWatchdog] WATCHING → SUSPECT Oct 15 16:03:09 volumio-2063 sudo[13436]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushQueue Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CorePlayQueue::saveQueue Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreStateMachine::updateTrackBlock Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrackBlock Oct 15 16:03:09 volumio-2063 sudo[13436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPlay Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreStateMachine::play index 0 Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreStateMachine::stop Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreStateMachine::play index undefined Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreStateMachine::startPlaybackTimer Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetVisibleSources Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 15 16:03:09 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 15 16:03:09 volumio-2063 volumio[2335]: verbose: ControllerMpd::clearAddPlayTracks USB/Musik/101 Michael Bolton - Time, Love And Tenderness.flac Oct 15 16:03:09 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand stop Oct 15 16:03:09 volumio-2063 systemd[1]: Stopping peppymeterbasic.service - peppymeterbasic Daemon... Oct 15 16:03:09 volumio-2063 systemd[1]: peppymeterbasic.service: Deactivated successfully. Oct 15 16:03:09 volumio-2063 systemd[1]: Stopped peppymeterbasic.service - peppymeterbasic Daemon. Oct 15 16:03:09 volumio-2063 systemd[1]: peppymeterbasic.service: Consumed 2.479s CPU time. Oct 15 16:03:09 volumio-2063 sudo[13436]: pam_unix(sudo:session): session closed for user root Oct 15 16:03:09 volumio-2063 volumio[2335]: info: peppymeterbasic Daemon Stop Oct 15 16:03:09 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] Probe PASS (HTTP 200): https://stream.radiofrance.fr/franceculture/franceculture_hifi.m3u8 Oct 15 16:03:09 volumio-2063 volumio[2335]: info: [StreamWatchdog] Probe confirms the stream is reachable — false alarm Oct 15 16:03:09 volumio-2063 volumio[2335]: info: [StreamWatchdog] SUSPECT → WATCHING Oct 15 16:03:11 volumio-2063 volumio[2335]: info: Oct 15 16:03:11 volumio-2063 volumio[2335]: ---------------------------- MPD announces state update: player Oct 15 16:03:11 volumio-2063 volumio[2335]: info: sendMpdCommand stop took 2191 milliseconds Oct 15 16:03:11 volumio-2063 volumio[2335]: info: ControllerMpd::getState Oct 15 16:03:11 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand status Oct 15 16:03:11 volumio-2063 volumio[2335]: info: sendMpdCommand stop took 2162 milliseconds Oct 15 16:03:11 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand clear Oct 15 16:03:11 volumio-2063 volumio[2335]: info: Oct 15 16:03:11 volumio-2063 volumio[2335]: ---------------------------- MPD announces system playlist update Oct 15 16:03:11 volumio-2063 volumio[2335]: info: Ignoring MPD Status Update Oct 15 16:03:11 volumio-2063 volumio[2335]: info: sendMpdCommand status took 1 milliseconds Oct 15 16:03:11 volumio-2063 volumio[2335]: info: sendMpdCommand clear took 0 milliseconds Oct 15 16:03:11 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseState Oct 15 16:03:11 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 16:03:11 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand add "USB/Musik/101 Michael Bolton - Time, Love And Tenderness.flac" Oct 15 16:03:11 volumio-2063 volumio[2335]: error: updateQueue error: null Oct 15 16:03:11 volumio-2063 volumio[2335]: info: ------------------------------ 1ms Oct 15 16:03:11 volumio-2063 volumio[2335]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 15 16:03:11 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseTrackInfo Oct 15 16:03:11 volumio-2063 volumio[2335]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Oct 15 16:03:11 volumio-2063 volumio[2335]: info: ------------------------------ 2ms Oct 15 16:03:11 volumio-2063 volumio[2335]: info: Oct 15 16:03:11 volumio-2063 volumio[2335]: ---------------------------- MPD announces system playlist update Oct 15 16:03:11 volumio-2063 volumio[2335]: info: Ignoring MPD Status Update Oct 15 16:03:11 volumio-2063 volumio[2335]: info: sendMpdCommand add "USB/Musik/101 Michael Bolton - Time, Love And Tenderness.flac" took 1 milliseconds Oct 15 16:03:11 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand play Oct 15 16:03:11 volumio-2063 volumio[2335]: info: ------------------------------ 1ms Oct 15 16:03:11 volumio-2063 volumio[2335]: info: sendMpdCommand play took 1 milliseconds Oct 15 16:03:12 volumio-2063 volumio[2335]: info: Oct 15 16:03:12 volumio-2063 volumio[2335]: ---------------------------- MPD announces state update: player Oct 15 16:03:12 volumio-2063 volumio[2335]: info: ControllerMpd::getState Oct 15 16:03:12 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand status Oct 15 16:03:12 volumio-2063 volumio[2335]: info: sendMpdCommand status took 3 milliseconds Oct 15 16:03:12 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseState Oct 15 16:03:12 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 16:03:12 volumio-2063 volumio[2335]: info: Oct 15 16:03:12 volumio-2063 volumio[2335]: ---------------------------- MPD announces state update: player Oct 15 16:03:12 volumio-2063 volumio[2335]: info: ControllerMpd::getState Oct 15 16:03:12 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand status Oct 15 16:03:12 volumio-2063 volumio[2335]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 15 16:03:12 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseTrackInfo Oct 15 16:03:12 volumio-2063 volumio[2335]: info: ControllerMpd::pushState Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CoreCommandRouter::servicePushState Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:03:12 volumio-2063 volumio[2335]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":330,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Time, Love And Tenderness","artist":"101 Michael Bolton","album":"Best Hits 80s from ALEXnROCK part 3","uri":"USB/Musik/101 Michael Bolton - Time, Love And Tenderness.flac","trackType":"flac"} Oct 15 16:03:12 volumio-2063 volumio[2335]: verbose: CURRENT POSITION 0 Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CoreStateMachine::syncState stateService play Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CoreStateMachine::syncState currentStatus stop Oct 15 16:03:12 volumio-2063 volumio[2335]: info: ------------------------------ 5ms Oct 15 16:03:12 volumio-2063 volumio[2335]: info: sendMpdCommand status took 1 milliseconds Oct 15 16:03:12 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseState Oct 15 16:03:12 volumio-2063 volumio[2335]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 15 16:03:12 volumio-2063 volumio[2335]: info: sendMpdCommand playlistinfo took 0 milliseconds Oct 15 16:03:12 volumio-2063 volumio[2335]: verbose: ControllerMpd::parseTrackInfo Oct 15 16:03:12 volumio-2063 volumio[2335]: info: ControllerMpd::pushState Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CoreCommandRouter::servicePushState Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:03:12 volumio-2063 volumio[2335]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":330,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Time, Love And Tenderness","artist":"101 Michael Bolton","album":"Best Hits 80s from ALEXnROCK part 3","uri":"USB/Musik/101 Michael Bolton - Time, Love And Tenderness.flac","trackType":"flac"} Oct 15 16:03:12 volumio-2063 volumio[2335]: verbose: CURRENT POSITION 0 Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CoreStateMachine::syncState stateService play Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CoreStateMachine::syncState currentStatus play Oct 15 16:03:12 volumio-2063 volumio[2335]: info: Received an update from plugin. extracting info from payload Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CoreStateMachine::pushState Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushState Oct 15 16:03:12 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output update for this device Oct 15 16:03:12 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CoreStateMachine::pushState Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioPushState Oct 15 16:03:12 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output update for this device Oct 15 16:03:12 volumio-2063 volumio[2335]: info: MRS: Pushing multiroomSync output Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CoreCommandRouter::volumioGetState Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CorePlayQueue::getTrack 0 Oct 15 16:03:12 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:03:12.263+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" state=STATUS_PLAYING positionMs=0 volume=100 Oct 15 16:03:12 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:03:12.264+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" id="music-library/USB/Musik/101 Michael Bolton - Time, Love And Tenderness.flac" title="Time, Love And Tenderness" Oct 15 16:03:12 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:03:12.265+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" state=STATUS_PLAYING positionMs=0 volume=100 Oct 15 16:03:12 volumio-2063 volumio5-onboarding[1828]: time=2026-10-15T16:03:12.266+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.109:49302 @ 0xc0003df920" id="music-library/USB/Musik/101 Michael Bolton - Time, Love And Tenderness.flac" title="Time, Love And Tenderness" Oct 15 16:03:12 volumio-2063 volumio[2335]: info: ------------------------------ 11ms Oct 15 16:03:12 volumio-2063 volumio[2335]: info: FusionDsp - Volumio is playing Oct 15 16:03:12 volumio-2063 volumio[2335]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Oct 15 16:03:12 volumio-2063 volumio[2335]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 15 16:03:12 volumio-2063 volumio[2335]: info: PeppyMeterBasic ---peppymeterbasic status play Oct 15 16:03:12 volumio-2063 sudo[13451]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 15 16:03:12 volumio-2063 sudo[13453]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Oct 15 16:03:12 volumio-2063 sudo[13453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:03:12 volumio-2063 sudo[13451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 15 16:03:12 volumio-2063 volumio[2335]: info: [LastFM] Current track has sufficient metadata: title (Time, Love And Tenderness) and artist (101 Michael Bolton) passed on explicitly Oct 15 16:03:12 volumio-2063 volumio[2335]: error: [LastFM] plugin is not authenticated, please retry, or track info could not be determined (very rare) Oct 15 16:03:12 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] pushState: status=play stream=flac service=mpd uri=music-library/USB/Musik/101 Michael Bolton - Time, Love And Tenderness.flac [state=WATCHING] Oct 15 16:03:12 volumio-2063 volumio[2335]: info: [StreamWatchdog] Playback switched to a local source Oct 15 16:03:12 volumio-2063 volumio[2335]: info: [StreamWatchdog] WATCHING → IDLE Oct 15 16:03:12 volumio-2063 volumio[2335]: verbose: [StreamWatchdog] pushState: status=play stream=flac service=mpd uri=music-library/USB/Musik/101 Michael Bolton - Time, Love And Tenderness.flac [state=IDLE] Oct 15 16:03:12 volumio-2063 volumio[2335]: info: FusionDsp - Clipping Monitor started Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CURURI: albums://101 Michael Bolton/Best Hits 80s from ALEXnROCK part 3 Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 15 16:03:12 volumio-2063 volumio[2335]: info: CURURI: albums://101 Michael Bolton/Best Hits 80s from ALEXnROCK part 3 Oct 15 16:03:12 volumio-2063 systemd[1]: Started peppymeterbasic.service - peppymeterbasic Daemon. Oct 15 16:03:12 volumio-2063 sudo[13453]: pam_unix(sudo:session): session closed for user root Oct 15 16:03:12 volumio-2063 sudo[13451]: pam_unix(sudo:session): session closed for user root Oct 15 16:03:12 volumio-2063 volumio[2335]: info: peppymeterbasic Daemon Started Oct 15 16:03:12 volumio-2063 volumio[2335]: info: peppymeterbasic Daemon Started Oct 15 16:03:12 volumio-2063 volumio[2335]: info: FusionDsp - ---- read samplerate, raw: 192000,S32_LE,2,32 Oct 15 16:03:12 volumio-2063 volumio[2335]: info: FusionDsp - ---- read samplerate from file: 192000 Oct 15 16:03:12 volumio-2063 volumio[2335]: info: camilladsp stopping service pid 13240... Oct 15 16:03:12 volumio-2063 volumio[2335]: info: camilladsp service terminated, instance 1 Oct 15 16:03:12 volumio-2063 volumio[2335]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 15 16:03:12 volumio-2063 volumio[2335]: info: camilladsp service started and running in background, instance 1 Oct 15 16:03:13 volumio-2063 volumio[2335]: info: FusionDsp - Clipping Monitor reconnecting in 2000ms Oct 15 16:03:13 volumio-2063 volumio[13459]: libpng warning: iCCP: known incorrect sRGB profile Oct 15 16:03:13 volumio-2063 volumio[13459]: libpng warning: iCCP: known incorrect sRGB profile Oct 15 16:03:13 volumio-2063 volumio[13459]: libpng warning: iCCP: known incorrect sRGB profile Oct 15 16:03:15 volumio-2063 volumio[2335]: info: FusionDsp - Clipping Monitor started Oct 15 16:03:24 volumio-2063 volumio[2335]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 15 16:03:24 volumio-2063 volumio[2335]: TypeError: Cannot read properties of null (reading 'slice') Oct 15 16:03:24 volumio-2063 volumio[2335]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Oct 15 16:03:24 volumio-2063 volumio[2335]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Oct 15 16:03:24 volumio-2063 volumio[2335]: at Object.onceWrapper (node:events:629:26) Oct 15 16:03:24 volumio-2063 volumio[2335]: at ClientRequest.emit (node:events:514:28) Oct 15 16:03:24 volumio-2063 volumio[2335]: at HTTPParser.parserOnIncomingClient [as onIncoming] (node:_http_client:693:27) Oct 15 16:03:24 volumio-2063 volumio[2335]: at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17) Oct 15 16:03:24 volumio-2063 volumio[2335]: at TLSSocket.socketOnData (node:_http_client:535:22) Oct 15 16:03:24 volumio-2063 volumio[2335]: at TLSSocket.emit (node:events:514:28) Oct 15 16:03:24 volumio-2063 volumio[2335]: at addChunk (node:internal/streams/readable:343:12) Oct 15 16:03:24 volumio-2063 volumio[2335]: at readableAddChunk (node:internal/streams/readable:316:9) Oct 15 16:03:24 volumio-2063 volumio[2335]: at Readable.push (node:internal/streams/readable:253:10) Oct 15 16:03:24 volumio-2063 volumio[2335]: at TLSWrap.onStreamRead (node:internal/stream_base_commons:190:23) Oct 15 16:03:24 volumio-2063 volumio[2335]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 15 16:03:24 volumio-2063 sudo[13521]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-15 16:02' Oct 15 16:03:24 volumio-2063 sudo[13521]: 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"