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

[kurt1970]

Now, music stops playing. Nothing in the moodeutl or journal log
Got this 3x by now.

[Tim Curtis]

It's been playing/recovering for over an hour on my end. The xruns occur between each track change. Very odd from this broadcaster.

moode log

Code:

20241018 094306 mpdmon: Buffer underrun 1 detected: _New station2
20241018 094312 mpdmon: Buffer underrun 2 detected: _New station2
20241018 094318 mpdmon: Buffer underrun 3 detected: _New station2
20241018 094318 mpdmon: MPD port 6600: accepting connections
20241018 094318 mpdmon: MPD restarted, play resumed
20241018 094624 mpdmon: Buffer underrun 1 detected: _New station2
20241018 094630 mpdmon: Buffer underrun 2 detected: _New station2
20241018 094930 mpdmon: Buffer underrun 1 detected: _New station2
20241018 094936 mpdmon: Buffer underrun 2 detected: _New station2
20241018 094936 mpdmon: Buffer underrun 3 detected: _New station2
20241018 094936 mpdmon: MPD port 6600: accepting connections
20241018 094936 mpdmon: MPD restarted, play resumed
20241018 095737 mpdmon: Buffer underrun 1 detected: _New station2
20241018 095743 mpdmon: Buffer underrun 2 detected: _New station2
20241018 095749 mpdmon: Buffer underrun 3 detected: _New station2
20241018 095749 mpdmon: MPD port 6600: accepting connections
20241018 095749 mpdmon: MPD restarted, play resumed

mpd log

Code:

Oct 18 10:03 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 10:03 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 10:03 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 10:03 : player: played "http://icecast.centaury.cl:7570/SuperStereoHiRes7"
Oct 18 10:06 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 10:06 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 10:07 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 10:07 : player: played "http://icecast.centaury.cl:7570/SuperStereoHiRes7"
.
.
.

[kurt1970]

Well, the stange thing is that I don't have any logging at all anymore after the last patches, but the drops are still there.
Now, we're almost evening in Belgium and network traffic increases. I can reproduce it almost every minute. But no logs at all.
Also, it looks like moOde has no notion the stream stopped, as the pause icon is stiil there.
How can I see the mpd log?

[Tim Curtis]

Well, the stange thing is that I don't have any logging at all anymore after the last patches, but the drops are still there.
Now, we're almost evening in Belgium and network traffic increases. I can reproduce it almost every minute. But no logs at all.
Also, it looks like moOde has no notion the stream stopped, as the pause icon is stiil there.
How can I see the mpd log?

Very odd. 

Check to see whether there are crashes or strange log entries

pgrep mpdmon
pgrep mpd

cat (or tail -f) /var/log/mpd/log

[kurt1970]

I was just able to reprodurce it.

Same story, but this is in the mpd log (goes forever).
And ideed, it plays "silence". Maybe also the reason why moOde still shows the "pause" button, and does not report any error?

Code:

moode@moode:~ $  tail -f /var/log/mpd/log
Oct 18 17:32 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:32 : player: played "http://icecast.centaury.cl:7570/SuperStereoHiRes7"
Oct 18 17:37 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:37 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:38 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:38 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:38 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:38 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:38 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:38 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:38 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:38 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:38 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:38 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:38 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:38 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:39 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:39 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:39 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:39 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:39 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:39 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:39 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:39 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:39 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:39 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:39 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:39 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:40 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:40 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:40 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:40 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 17:40 : alsa_output: Decoder is too slow; playing silence to avoid xrun

[kurt1970]

The same radio station has also a 44.1/16 stream (http://icecast.centaury.cl:7560/SuperStereoNoData7).
This keeps on going longer, but when it drops, it keeps dropping without recovery.

mpd log

Code:

Oct 18 19:06 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:06 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:07 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:07 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:07 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:07 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:07 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:07 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:07 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:07 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:07 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:07 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:07 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:07 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:08 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:08 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:08 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:08 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:08 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:08 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:08 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:08 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:08 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:08 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:08 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:09 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:09 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:09 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:09 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:09 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:09 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:09 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:09 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:09 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:09 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:09 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:09 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:10 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:10 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:10 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:10 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:10 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:10 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:10 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:10 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:10 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:10 : alsa_output: Decoder is too slow; playing silence to avoid xrun
Oct 18 19:10 : alsa_output: Decoder is too slow; playing silence to avoid xrun

[kurt1970]

duplicate message: removed

[TheOldPresbyope]

Just so you know:

The subject of "Decoder is too slow; playing silence to avoid xrun" has come up in the MPD issues log from time to time. The most recent time I recall is 2 years ago https://github.com/MusicPlayerDaemon/MPD/issues/1630. The first one I came across was posted in 2018.

Coiincidently, one of the first issues I recall also mentioned a SuperStereo URL.

You won't get any sympathy from the MPD maintainer. His position is that if the TCP connection is still open then this is the proper response from MPD.

[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?

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"

[the_bertrum]

@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.