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

[kurt1970]

Hi @Tim Curtis

Since 9.1.2 (9.1.3 was a typo in my previeus post), I've several times a day radio stations stop playing. 
When looking into moodeutl -l, it seems it has to do with an ad-hoc crashing MPD.
Any thoughts?
Tx,
k

Code:

20241011 133412 watchdog: MPD crashed and was restarted (check journal for messages)
20241011 133415 mpdmon: Buffer underrun 3 detected: Pure Lounge Radio
20241011 133415 mpdmon: MPD restarted, play resumed
20241011 133415 mpdmon: Buffer underrun 1 detected: Pure Lounge Radio
20241011 133415 mpdmon: Buffer underrun 2 detected: Pure Lounge Radio
20241011 133415 mpdmon: Buffer underrun 3 detected: Pure Lounge Radio
20241011 133415 mpdmon: MPD restarted, play resumed
20241011 133415 mpdmon: Buffer underrun 1 detected: Pure Lounge Radio
20241011 133415 mpdmon: Buffer underrun 2 detected: Pure Lounge Radio
20241011 133415 mpdmon: Buffer underrun 3 detected: Pure Lounge Radio
20241011 133415 mpdmon: MPD restarted, play resumed
20241011 133415 mpdmon: Buffer underrun 1 detected: Pure Lounge Radio
20241011 133415 mpdmon: Buffer underrun 2 detected: Pure Lounge Radio
20241011 133415 mpdmon: Buffer underrun 3 detected: Pure Lounge Radio
20241011 133415 mpdmon: MPD restarted, play resumed
20241011 133415 mpdmon: Buffer underrun 1 detected: Pure Lounge Radio
20241011 133415 mpdmon: Buffer underrun 2 detected: Pure Lounge Radio
20241011 133415 mpdmon: Buffer underrun 3 detected: Pure Lounge Radio
20241011 133415 mpdmon: MPD restarted, play resumed
20241011 133415 mpdmon: Buffer underrun 1 detected: Pure Lounge Radio
20241011 133415 mpdmon: Buffer underrun 2 detected: Pure Lounge Radio
20241011 133415 mpdmon: Buffer underrun 3 detected: Pure Lounge Radio
20241011 133415 mpdmon: MPD restarted, play resumed
20241011 133415 mpdmon: Buffer underrun 1 detected: Pure Lounge Radio
20241011 133419 watchdog: MPD crashed and was restarted (check journal for messages)
20241011 133425 watchdog: MPD crashed and was restarted (check journal for messages)

[TheOldPresbyope]

What is Pure Lounge Radio? I don't recall it being in the curated stations included with moOde.

In any case, buffer underrun messages suggest an issue with Internet throughput. Have you checked the journal for messages as suggested?

Regards,
Kent

[kurt1970]

Pure Lounge Radio is a custom radio station (https://pureloungeradio.com) I added. Station URL: http://mscp4.live-streams.nl:8142/lounge.ogg

The issue I'm referring to is not the buffer underrun, but the MPD crash lines in the code fragment.

Here's the journal content
 

Code:

Oct 11 13:34:12 moode systemd[1]: Stopped mpd.service - Music Player Daemon.
Oct 11 13:34:12 moode systemd[1]: mpd.service: Start request repeated too quickly.
Oct 11 13:34:12 moode systemd[1]: mpd.service: Failed with result 'start-limit-hit'.
Oct 11 13:34:12 moode systemd[1]: Failed to start mpd.service - Music Player Daemon.
Oct 11 13:34:12 moode systemd[1]: mpd.service: Start request repeated too quickly.
Oct 11 13:34:12 moode systemd[1]: mpd.service: Failed with result 'start-limit-hit'.
Oct 11 13:34:12 moode systemd[1]: Failed to start mpd.service - Music Player Daemon.
Oct 11 13:34:15 moode systemd[1]: mpd.service: Start request repeated too quickly.
Oct 11 13:34:15 moode systemd[1]: mpd.service: Failed with result 'start-limit-hit'.
Oct 11 13:34:15 moode systemd[1]: Failed to start mpd.service - Music Player Daemon.
Oct 11 13:34:15 moode systemd[1]: mpd.service: Start request repeated too quickly.
Oct 11 13:34:15 moode systemd[1]: mpd.service: Failed with result 'start-limit-hit'.
Oct 11 13:34:15 moode systemd[1]: Failed to start mpd.service - Music Player Daemon.
Oct 11 13:34:15 moode systemd[1]: mpd.service: Start request repeated too quickly.
Oct 11 13:34:15 moode systemd[1]: mpd.service: Failed with result 'start-limit-hit'.
Oct 11 13:34:15 moode systemd[1]: Failed to start mpd.service - Music Player Daemon.
Oct 11 13:34:15 moode systemd[1]: mpd.service: Start request repeated too quickly.
Oct 11 13:34:15 moode systemd[1]: mpd.service: Failed with result 'start-limit-hit'.
Oct 11 13:34:15 moode systemd[1]: Failed to start mpd.service - Music Player Daemon.
Oct 11 13:34:15 moode systemd[1]: mpd.service: Start request repeated too quickly.
Oct 11 13:34:15 moode systemd[1]: mpd.service: Failed with result 'start-limit-hit'.
Oct 11 13:34:15 moode systemd[1]: Failed to start mpd.service - Music Player Daemon.
Oct 11 13:34:15 moode systemd[1]: mpd.service: Start request repeated too quickly.
Oct 11 13:34:15 moode systemd[1]: mpd.service: Failed with result 'start-limit-hit'.
Oct 11 13:34:15 moode systemd[1]: Failed to start mpd.service - Music Player Daemon.
Oct 11 13:34:19 moode systemd[1]: mpd.service: Start request repeated too quickly.
Oct 11 13:34:19 moode systemd[1]: mpd.service: Failed with result 'start-limit-hit'.
Oct 11 13:34:19 moode systemd[1]: Failed to start mpd.service - Music Player Daemon.
Oct 11 13:34:25 moode systemd[1]: Starting mpd.service - Music Player Daemon...
Oct 11 13:34:25 moode mpd[40419]: Ignoring the 'pid_file' setting in systemd mode

[Tim Curtis]

You must have the stream monitor enabled for that station.

It looks like watchdog and mpdmon are conflicting with one another. Basically mpdmon which runs every 6 seconds by default sees a threshold number of buffer underruns and restarts MPD. Watchdog which runs every 6 seconds happens to wake up and see that MPD is not running as would be the case during the first part of being restarted.

I'll add to the TODO list to investigate how to keep this from happening.

[TheOldPresbyope]

So Tim has identified a clash between watchdog and mpdmon that he'll look into.

The fact remains that the trigger of this is the buffer underrun which MPD is experiencing.

As a point of reference, I have had a moOde 9.1.2 player streaming Pure Lounge Radio since the moment you posted the URL, with mpdmon enabled, trying to replicate your MPD crash. It's been playing for the last 5 hours without a hitch.
 
I still think you may have an Internet / LAN throughput issue.

Regards,
Kent

[kurt1970]

Hi@Tim Curtis

Yes, for all of my radio stations, I've the stream monitor enabled. Reason for this is that I'm only listening FLAC/CD quality radio stations (with some few exceptions). This means that almost all of them are custom added stations. I've 45 in total.
Because of the higher bandwidth demand, those are more subject to buffer underruns etc. I can perfectly live with that. So, the wonderful moOde monitor option is just great, as in most cases, it restarts the stream. But...it seems there's an issue amongst the requested restart frequency and what MPD likes. At least, this is my interpretation.

[kurt1970]

So Tim has identified a clash between watchdog and mpdmon that he'll look into.

The fact remains that the trigger of this is the buffer underrun which MPD is experiencing.

As a point of reference, I have had a moOde 9.1.2 player streaming Pure Lounge Radio since the moment you posted the URL, with mpdmon enabled, trying to replicate your MPD crash. It's been playing for the last 5 hours without a hitch.
 
I still think you may have an Internet / LAN throughput issue.

Regards,
Kent

That's not the point. Here (Belgium, 150km away from the Netherlands) it plays as well. Point is that when it goes wrong, it really goes wrong. And this is basically related to the fact (I believe) moOde tries to fire/restart MPD too many times, in a given timeframe.

Bandwidth is not an issue (wired). This is what I measured via speedtest on the PI running moOde. And, by coincidence, speedtest selected a server in the Netherlands, which is a good reprensation for the expected latency/bandwidth fot Lounge Radio in the Netherlands.

Code:

moode@moode:~ $ speedtest
Retrieving speedtest.net configuration...
Testing from Telenet (78.23.101.145)...
Retrieving speedtest.net server list...
Selecting best server based on ping...
Hosted by ColoCenter bv (Zoetermeer) [107.96 km]: 25.254 ms
Testing download speed................................................................................
Download: 177.66 Mbit/s

[Tim Curtis]

Hi@Tim Curtis

Yes, for all of my radio stations, I've the stream monitor enabled. Reason for this is that I'm only listening FLAC/CD quality radio stations (with some few exceptions). This means that almost all of them are custom added stations. I've 45 in total.
Because of the higher bandwidth demand, those are more subject to buffer underruns etc. I can perfectly live with that. So, the wonderful moOde monitor option is just great, as in most cases, it restarts the stream. But...it seems there's an issue amongst the requested restart frequency and what MPD likes. At least, this is my interpretation.

I think it's a timing conflict between the Stream Monitor and Watchdog Monitor both of which attempt to detect MPD crash and try to restart it. When they both do this more or less simultaneously there will be multiple unnecessary restarts. 

The fix I'm testing is to have watchdog monitor do the detection check up to 3 times with a 1 second delay between tries. This should avoid the simultaneous detect/restart between mpdmon and watchdog.

Btw, glad to hear the Stream Monitor is working out for your usage scenario :-)

[Tim Curtis]

So Tim has identified a clash between watchdog and mpdmon that he'll look into.

The fact remains that the trigger of this is the buffer underrun which MPD is experiencing.

As a point of reference, I have had a moOde 9.1.2 player streaming Pure Lounge Radio since the moment you posted the URL, with mpdmon enabled, trying to replicate your MPD crash. It's been playing for the last 5 hours without a hitch.
 
I still think you may have an Internet / LAN throughput issue.

Regards,
Kent

I got the same result with that station. It played for hours without any issues.

US Internet though, especially in the backbone regions is really good.

[kurt1970]

As posted some posts above, indeed, it plays for hours ok, but when it goes wrong, it really goes wrong. And this because of an issue about too many times restarting MPD in a given timeframe. At least, this is what the logs say.
Btw, this behavior is not related to that particular station. Same behavior for other stations.
Next to that, 177mbit/s should be enough to play CD quality I guess?