Reproducible alsa_output: Decoder is too slow; playing silence to avoid xrun while streaming HD Radio

[rschenk0]

I see this error reproducible while streaming some HD-Radio Streams. Really easy to reproduce on nearly each song end: SuperStero 1: http://198.204.228.202:8160/flac (see also http://www.superstereo24bit.com/) 24bit/96khz and also https://maggie.torontocast.com:8076/flac (JB Radio 2 FLAC, 16bit, 44,1khz).

I tested this with two different PI's (3B and 2B) running moode 8.3.0, latest mpd 0.23.12 and output tested to either SMSL DO100 USB DAC (USB 2.0) or HifiBerry Digi+ I2S HAT via TOSLINK or Coax. Internet Connection is 500Mbit, Cabled Networking, all BT/WIFI disabled on Pi...

In my opinion it has to do with http client or buffering. I setup a rtsp-stream-server in my local network (https://github.com/aler9/rtsp-simple-server) simply "proxying" above streams to RTSP and problem goes away - also no more metadata :-(....

The streaming server simply copies the real audio-stream, no processing:

From Config: SuperStereo1: runOnDemand: ffmpeg -loglevel error -i http://198.204.228.202:8160/flac -ignore_unknown -ar 96000 -ac 2 -content_type audio/ogg -f rtsp rtsp://localhost:$RTSP_PORT/$RTSP_PATH runOnDemandRestart: yes

I then use my internal URL to stream this in moode: "rtsp://my.localserver.de:8554/SuperStereo1" Works without problems on all outputs at bitperfect:

root@moode-office-office:~# grep '' /proc/asound/card*/pcmp/sub/hw_params /proc/asound/card3/pcm0p/sub0/hw_params:access: MMAP_INTERLEAVED /proc/asound/card3/pcm0p/sub0/hw_params:format: S24_LE /proc/asound/card3/pcm0p/sub0/hw_params:subformat: STD /proc/asound/card3/pcm0p/sub0/hw_params:channels: 2 /proc/asound/card3/pcm0p/sub0/hw_params:rate: 96000 (96000/1) /proc/asound/card3/pcm0p/sub0/hw_params:period_size: 12000 /proc/asound/card3/pcm0p/sub0/hw_params:buffer_size: 48000

Played in /etc/mpd.conf with buffer_time "XXXXXXX" period_time "XXXX"

as suggested in some threads - doesn't help at all.

Expected Behavior

Streaming uninterrupted...

Actual Behavior

Streaming interupted at nearly each song.

Version

Music Player Daemon 0.23.12 (0.23.12) (Included in moode 8.3.0)

Configuration

Done by moode:

#########################################

This file is automatically generated

by the MPD configuration page.

#########################################

music_directory "/var/lib/mpd/music" playlist_directory "/var/lib/mpd/playlists" db_file "/var/lib/mpd/database" log_file "/var/log/mpd/log" pid_file "/var/run/mpd/pid" state_file "/var/lib/mpd/state" sticker_file "/var/lib/mpd/sticker.sql" user "mpd" group "audio" bind_to_address "any" port "6600" log_level "default" restore_paused "yes" auto_update "no" follow_outside_symlinks "yes" follow_inside_symlinks "yes" zeroconf_enabled "no" zeroconf_name "Moode MPD" filesystem_charset "UTF-8" metadata_to_use "+comment" replaygain "off" replaygain_preamp "0" volume_normalization "no" audio_buffer_size "4096" max_output_buffer_size "131072" max_playlist_length "16384" max_connections "128"

decoder { plugin "ffmpeg" enabled "yes" }

input { plugin "curl" }

resampler { plugin "soxr" quality "high" threads "1" }

audio_output { type "alsa" name "ALSA Default" device "_audioout" mixer_type "none" dop "no" stop_dsd_silence "no" thesycon_dsd_workaround "no" }

audio_output { type "alsa" name "ALSA Bluetooth" device "_audioout" mixer_type "software" }

audio_output { type "httpd" name "HTTP Server" port "8000" encoder "lame" bitrate "320" tags "yes" always_on "yes" format "44100:16:2" }

Log

Playing 1 Song from http://198.204.228.202:8160/flac:

root@moode:~# systemctl stop mpd root@moode:~# mpd --stderr --no-daemon --verbose 2>&1 | grep -v '^client' config_file: loading file /etc/mpd.conf path: SetFSCharset: fs charset is soxr: soxr converter 'high' vorbis: Xiph.Org libVorbis 1.3.7 opus: libopus 1.3.1 hybrid_dsd: The Hybrid DSD decoder is disabled because it was not explicitly enabled adplug: adplug 2.3.3 simple_db: reading DB curl: version 7.74.0 curl: with GnuTLS/3.7.1 state_file: Loading state file /var/lib/mpd/state event: RTIOThread could not get realtime scheduling, continuing anyway: sched_setscheduler failed: Operation not permitted playlist: play 4:"http://198.204.228.202:8160/flac" playlist: queue song 5:"http://198.204.228.202:8511/canal1" cache: Prefetch 'http://198.204.228.202:8511/canal1' decoder_thread: probing plugin vorbis decoder_thread: probing plugin oggflac decoder: audio_format=96000:24:2, seekable=false output: OutputThread could not get realtime scheduling, continuing anyway: sched_setscheduler failed: Operation not permitted alsa_output: opened _audioout type=COPY alsa_output: buffer: size=24..192000 time=250..2000000 alsa_output: period: size=12..96000 time=125..1000000 alsa_output: default period_time = buffer_time/4 = 2000000/4 = 500000 alsa_output: format=S32_LE (Signed 32 bit Little Endian) alsa_output: buffer_size=192000 period_size=48000 output: opened "ALSA Default" (alsa) audio_format=96000:32:2 output: converting in=96000:24:2 -> f=96000:24:2 -> out=96000:32:2 state_file: Saving state file /var/lib/mpd/state alsa_output: Decoder is too slow; playing silence to avoid xrun alsa_output: Decoder is too slow; playing silence to avoid xrun alsa_output: Decoder is too slow; playing silence to avoid xrun alsa_output: Decoder is too slow; playing silence to avoid xrun alsa_output: Decoder is too slow; playing silence to avoid xrun alsa_output: Decoder is too slow; playing silence to avoid xrun alsa_output: Decoder is too slow; playing silence to avoid xrun alsa_output: Decoder is too slow; playing silence to avoid xrun alsa_output: Decoder is too slow; playing silence to avoid xrun alsa_output: Decoder is too slow; playing silence to avoid xrun alsa_output: Decoder is too slow; playing silence to avoid xrun alsa_output: Decoder is too slow; playing silence to avoid xrun alsa_output: Decoder is too slow; playing silence to avoid xrun alsa_output: Decoder is too slow; playing silence to avoid xrun

[hombibi]

Same issue here with Moode 8.3.3. and the SO&SO radio stream. Found a workaround on https://community.volumio.org/t/decoder-is-to-slow/10833

where a service is suggested to monitor the mpd logfile and restart mpc everytime a new string "Decoder is too slow; playing silence to avoid xrun" is found. Note the specifics in the thread pertaining to a MoodeAudio installation. The workaround provides the desired behaviour for me. (edited for correct reference)

[jprjr]

@hombibi this isn't really a bug with MPD itself, but with upstream FLAC libraries.

It looks like that FLAC radio stream is relying on Ogg Chaining to update the metadata, which the upstream FLAC project doesn't support - see https://github.com/xiph/flac/issues/254

So what's happening is, when the song changes, the stream closes out the Ogg stream and opens a new one with updated metadata. The FLAC library goes into an infinite loop (see https://github.com/xiph/flac/issues/568), and MPD puts out the "decoder is too slow" message, because the FLAC library isn't returning an error or anything. It's basically just stuck throwing away the data.

One work-around would be to disable the "oggflac" decoder plugin in MPD in your mpd.conf:

decoder {
    plugin "oggflac"
    enabled "no"
}

This will make MPD switch to the ffmpeg plugin for FLAC-in-Ogg.

Now, the issue with that is ffmpeg won't process incoming metadata updates so your "now playing" info will never change. I have an issue open with the ffmpeg project on that here: https://trac.ffmpeg.org/ticket/9778 - and it looks like somebody else may have figured out a patch to ffmpeg to fix it, over in this issue - https://trac.ffmpeg.org/ticket/10364 - I haven't tried the patch personally so I can't vouch for it.

The best fix may be for the radio station itself to make a change. It's using Vorbis comments to send a single TITLE tag, and the TITLE tag contains the artist and song title - just like you'd see in traditional Shoutcast/Icecast in-band metadata (combining the artist and title in a single tag, separated by the string "-"). But since it's stuffed into a Vorbis comment - most players are going to show it as-is and not try to separate the artist out.

If they switch to using the embedded Shoutcast data method (no ogg chaining, inject metadata every so-many bytes), it would actually be a much more compatible stream. A lot of players don't handle chained Ogg FLAC very well - again because the upstream FLAC project doesn't support it, and that's likely the decoder most players use.

In theory, by using chained Ogg they can add a lot more, richer metadata - but they're not, they just sending the artist and title. If you're not taking full advantage of Ogg chaining, it's really a hindrance.

They could switch to sending the artist and title as separate comments so players display them correctly - but even then, if they're only going to send artist and title, they're probably better off going to the old-school Shoutcast method.

[hombibi]

@jprjr, I made the following change to moodeaudio's mpd.conf (instructions) as per your suggestion:

decoder {
   # setting 'plugin "ffmpeg"' is replaced by:
   plugin "oggflac"
   # setting 'enabled "yes"' is replaced by:
   enabled "no"
}

and have been running the same stream for over two hours. That is not decisive, but so far not one interruption. I'll post a further observation on Sunday.

[jprjr]

@hombibi

I don't see anything in your link about changing the MPD config - but based on your snippet's comments about replacing "ffmpeg"and "enabled yes", it sounds like you may have been given the following config to use at some point?

decoder {
   plugin "ffmpeg"
   enabled "yes"
}

Just thought I should mention, it's redundant/unnecessary to configure a plugin with enabled = "yes" - if they're available, they're enabled by default. See the mpd documentation - "By default, all plugins are enabled."

Figured that's worth passing along to whoever wrote up instructions like that.

[hombibi]

@jprjr The link describes how to edit mpd.conf on Moodeaudio.

I am not sure if the changes to oggflac in mpd.conf have any effect with Moodeaudio: behaviour seems much the same. Interruptions still happen, sometimes every 5 or 10 second, up to so quickly that subsequent error messages are suppressed. In addition, the metadata (song title / artist) is still displayed and refreshed. I suppose this means that offvorbis is not disabled.