[PROBLEM] [PROBLEM] 9.x: MPD crashing ad-hoc / stops playing

[the_bertrum]

I recall that before the monitor existed, I had a script that recovered for me which didn't restart MPD but issued a stop command then a play command which cleared the xrun condition nicely.  Maybe the monitor could do that rather than restart MPD, or @kurt1970 could turn the monitor off for this station and try the script instead?

[Tim Curtis]

@Tim Curtis isn't it an option to monitor never ending "alsa_output: Decoder is too slow; playing silence to avoid xrun" messages to restart MPD?

Btw, since the patch, I've the same behavior for ALL stations having an underrun. No moOde log entries anymore, nothing in the journal, only something in the MPD log.

Code:

moode@moode:~ $ tail -f /var/log/mpd/log
Oct 19 11:16 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 19 11:17 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 19 11:17 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 19 11:17 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 19 11:17 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 19 11:17 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 19 11:17 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 19 11:17 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 19 11:17 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 19 11:17 : player: played "http://icecast.vrtcdn.be/ra2wvl.aac"

Has mpdmon crashed?

pgrep mpdmon

[kurt1970]

@Tim Curtis isn't it an option to monitor never ending "alsa_output: Decoder is too slow; playing silence to avoid xrun" messages to restart MPD?

That is exactly what the monitor does.  If it get (default) 3 messages it restarts MPD.  The issue here, it seems to me, is the frequency that the xrun happens.

I got a patch from Tim and since then, the monitor does not retry anymore, as no log info anymore.

[kurt1970]

@Tim Curtis, for the time being, I had to reinstall the original file, as soon as - with whatever radio station - it hits a drop, I keeps playing radio silence for ever.

[Tim Curtis]

@Tim Curtis, for the time being, I had to reinstall the original file, as soon as - with whatever radio station - it hits a drop, I keeps playing radio silence for ever.

The updated mpdmon "works" on my end with the SuperStereoHiRes7 (24/96K) station but I had to set the Message threshold to 5 in Radio manager in order to avoid eventual MPD crash. 

Code:

http://icecast.centaury.cl:7570/SuperStereoHiRes7

And by "works" I mean that buffer under-runs were detected, MPD was restarted and play was resumed during a ~6 hour test however these buffer under-runs always occurred at track change which caused the beginning of the new track to be cut off because of the MPD restart. This makes the playback experience unlistenable.

Below is the MPD verbose log for two of their streams that are playing the exact same set of tracks. One decodes to 24/96K with metadata and the other decodes to 16/44.1K without any metadata.

It's only the 24/96K decoded stream that constantly buffer under-runs. The 16/44.1K stream has no issues whatsoever.

Code:

# This decodes to 24/96K PCM and has metadata

Oct 20 08:13 : playlist: play 30:"http://icecast.centaury.cl:7570/SuperStereoHiRes7"
Oct 20 08:13 : decoder_thread: probing plugin vorbis
Oct 20 08:13 : decoder_thread: probing plugin oggflac
Oct 20 08:13 : decoder: audio_format=96000:24:2, seekable=false
Oct 20 08:13 : alsa_output: opened _audioout type=COPY
Oct 20 08:13 : alsa_output: buffer: size=8..65536 time=83..682667
Oct 20 08:13 : alsa_output: period: size=4..32768 time=41..341334
Oct 20 08:13 : alsa_output: default period_time = buffer_time/4 = 500000/4 = 125000
Oct 20 08:13 : alsa_output: format=S24_LE (Signed 24 bit Little Endian)
Oct 20 08:13 : alsa_output: buffer_size=48000 period_size=12000
Oct 20 08:13 : output: opened "ALSA Default" (alsa) audio_format=96000:24:2

# This decodes to 16/44.1K PCM and has no metadata

Oct 20 08:13 : playlist: play 31:"http://icecast.centaury.cl:7560/SuperStereoNoData7"
Oct 20 08:13 : decoder_thread: probing plugin vorbis
Oct 20 08:13 : decoder_thread: probing plugin oggflac
Oct 20 08:13 : decoder: audio_format=44100:16:2, seekable=false
Oct 20 08:13 : alsa_output: opened _audioout type=COPY
Oct 20 08:13 : alsa_output: buffer: size=16..131072 time=362..2972155
Oct 20 08:13 : alsa_output: period: size=8..65536 time=181..1486078
Oct 20 08:13 : alsa_output: default period_time = buffer_time/4 = 500000/4 = 125000
Oct 20 08:13 : alsa_output: format=S16_LE (Signed 16 bit Little Endian)
Oct 20 08:13 : alsa_output: buffer_size=22050 period_size=4410
Oct 20 08:13 : output: opened "ALSA Default" (alsa) audio_format=44100:16:2

Some options:

1. Post an issue to the MPD repo about the buffer under-runs for only the 24/96K stream
2. Contact the broadcaster and ask them to add metadata to the 16/44.1K stream
3. Try other broadcasters. There doesn't seem to be anything unique about the track list in these streams

[kurt1970]

Hi @Tim Curtis, point is that my current install doenn't log any retries anymore in the moodeutl log, nor in the journal, and this for ALL radio stations causing a hick-up. But at the end, when a hick-up occurs, it keeps on playing silence, for whatever radio station. In order to get it playing again, I've to re-select the radio station in the radio view. So, not at all related to 1 particular station.

[the_bertrum]

Hi @Tim Curtis, point is that my current install doenn't log any retries anymore in the moodeutl log, nor in the journal, and this for ALL radio stations causing a hick-up. But at the end, when a hick-up occurs, it keeps on playing silence, for whatever radio station. In order to get it playing again, I've to re-select the radio station in the radio view. So, not at all related to 1 particular station.

I suspect you are at the point where starting from a fresh installation is required.  It sounds very much as if the back and forth with patches and so on has broken something in your installation.

[kurt1970]

I reinstalled the original mpdmon.php, and now, MPD is restarting again, but also crashing again.

@Tim Curtis any other tests I can do?

[kurt1970]

Hi @Tim Curtis , any progress on this? Anything else to test?

[Tim Curtis]

Hi @Tim Curtis , any progress on this? Anything else to test?

I can't reproduce it on my end so there is nothing more for me to investigate.