[PROBLEM] Stops playing

[funnyf]

Hi,

I've been using MoOde for a while now, mostly playing radio streams. But it stops playing after a while stop. When I go to the browser I see the screen below.
The only way to get it back running is to reboot it. I've added the startup log. Any ideas what I can do to prevent that it stops playing?

Sometimes I can see there errors in the log, but this last time I did not:
20231106 061541 enhanceMetadata(): error: currentsong file is NULL
or
20231106 105828 readMpdResp(): Error: fgets failure ()

Code:

20231106 110159 worker: --
20231106 110159 worker: -- Start moOde 8 series
20231106 110159 worker: --
20231106 110159 worker: Successfully daemonized
20231106 110159 worker: Waiting for Linux startup...
20231106 110211 worker: Linux startup complete
20231106 110212 worker: Boot config backed up
20231106 110214 worker: File check (OK)
20231106 110215 worker: Session vacuumed
20231106 110215 worker: Session loaded
20231106 110215 worker: Debug logging (ON)
20231106 110215 worker: Reduced system logging (OFF)
20231106 110215 worker: --
20231106 110215 worker: -- Audio debug
20231106 110215 worker: --
20231106 110215 worker: ALSA cards: (0:sndrpihifiberry | 1:empty | 2:empty | 3:empty
20231106 110215 worker: MPD config: (0:HiFiBerry Amp2 | mixer:(Digital) | card:0)
20231106 110215 worker: ALSA mixer actual (Digital)
20231106 110215 worker: ALSA Digital volume set to (0%)
20231106 110215 worker: --
20231106 110215 worker: -- System
20231106 110215 worker: --
20231106 110218 worker: Host      (moode)
20231106 110218 worker: Hardware  (Pi-4B 1.1 2GB)
20231106 110219 worker: moOde     (8.3.6 2023-09-05)
20231106 110219 worker: RaspiOS   (11.3)
20231106 110219 worker: Kernel    (6.1.21-v8+ #1642)
20231106 110219 worker: Procarch  (aarch64, 64-bit)
20231106 110219 worker: MPD ver   (0.23.12)
20231106 110219 worker: CPU gov   (ondemand)
20231106 110219 worker: Userid    (pi)
20231106 110219 worker: Homedir   (/home/pi)
20231106 110219 worker: Timezone  (Europe/Brussels)
20231106 110219 worker: Keyboard  (be)
20231106 110219 worker: USB boot  (enabled)
20231106 110219 worker: File sys  (expanded)
20231106 110219 worker: HDMI port (Off)
20231106 110219 worker: Sys LED0  (On)
20231106 110219 worker: Sys LED1  (On)
20231106 110219 worker: --
20231106 110219 worker: -- Network
20231106 110219 worker: --
20231106 110219 worker: eth0 adapter exists
20231106 110219 worker: eth0 address check (Off)
20231106 110219 worker: IP addr (192.168.0.148)
20231106 110219 worker: Netmask (255.255.255.0)
20231106 110219 worker: Gateway (192.168.0.1)
20231106 110219 worker: Pri DNS (195.130.131.3)
20231106 110219 worker: Domain  ()
20231106 110219 worker: wlan0 adapter does not exist
20231106 110219 worker: --
20231106 110219 worker: -- Software update
20231106 110219 worker: --
20231106 110219 worker: Automatic check (Off)
20231106 110219 worker: --
20231106 110219 worker: -- File sharing
20231106 110219 worker: --
20231106 110219 worker: SMB file sharing (Off)
20231106 110219 worker: NFS file sharing (Off)
20231106 110219 worker: --
20231106 110219 worker: -- Audio config
20231106 110219 worker: --
20231106 110219 worker: MPD conf updated
20231106 110219 worker: ALSA card number (0)
20231106 110219 worker: MPD audio output (HiFiBerry Amp2)
20231106 110219 worker: Audio formats (S16_LE, S24_LE, S32_LE)
20231106 110219 worker: ALSA mixer name (Digital)
20231106 110219 worker: MPD mixer type (hardware)
20231106 110219 worker: Hdwr volume controller exists
20231106 110219 worker: Max ALSA volume (100%)
20231106 110219 worker: ALSA output mode (Default)
20231106 110219 worker: ALSA loopback (Off)
20231106 110219 worker: Renderer active flags (reset)
20231106 110219 worker: CamillaDSP configuration (off)
20231106 110219 worker: --
20231106 110219 worker: -- MPD startup
20231106 110219 worker: --
20231106 110220 worker: MPD started
20231106 110220 worker: MPD accepting connections
20231106 110220 worker: MPD output 1 ALSA Default (On)
20231106 110220 worker: MPD output 2 ALSA Bluetooth (Off)
20231106 110220 worker: MPD output 3 HTTP Server (Off)
20231106 110220 worker: MPD crossfade (off)
20231106 110220 worker: MPD ignore CUE files (yes)
20231106 110220 worker: MPD camilladsp volume sync (Off)
20231106 110220 worker: MPD camilladsp volume range (60 dB)
20231106 110220 worker: --
20231106 110220 worker: -- Music sources
20231106 110220 worker: --
20231106 110220 worker: USB sources
20231106 110220 worker: No drives found
20231106 110220 worker: NAS sources
20231106 110220 worker: None configured
20231106 110220 worker: --
20231106 110220 worker: -- Feature availability
20231106 110220 worker: --
20231106 110220 worker: Input select (available)
20231106 110220 worker: Input (MPD)
20231106 110220 worker: Output (HiFiBerry Amp2)
20231106 110220 worker: Bluetooth (available)
20231106 110220 worker: AirPlay renderer (available)
20231106 110220 startSpotify(): (librespot --name "Moode Spotify Living" --bitrate 160 --format S16 --ap-port 13561  --mixer softvol --initial-volume 18 --volume-ctrl log --volume-range 60 --autoplay --cache /var/local/www/spotify_cache --disable-audio-cache --backend alsa --device "_audioout" --onevent /var/local/www/commandw/spotevent.sh > /dev/null 2>&1 &)
20231106 110220 worker: Spotify renderer (available: started)
20231106 110220 worker: Squeezelite (available)
20231106 110220 worker: RoonBridge renderer (not installed)
20231106 110220 worker: Multiroom sender (available)
20231106 110220 worker: Multiroom receiver (available)
20231106 110220 worker: UPnP renderer (available)
20231106 110220 worker: DLNA server (available)
20231106 110220 worker: GPIO button handler (available)
20231106 110220 worker: Stream recorder (n/a)
20231106 110220 worker: HTTPS-Only mode (n/a)
20231106 110220 worker: --
20231106 110220 worker: -- Other
20231106 110220 worker: --
20231106 110220 worker: USB volume knob (Off)
20231106 110220 worker: Shellinabox SSH started
20231106 110220 worker: USB auto-mounter (udisks-glue)
20231106 110220 worker: Saved MPD vol level (0)
20231106 110220 worker: Preamp volume level (0)
20231106 110220 worker: MPD volume level (14) restored
20231106 110220 worker: ALSA Digital volume (51%)
20231106 110220 worker: Auto-play (On)
20231106 110220 worker: Auto-playing id (1)
20231106 110221 worker: LocalUI (Off)
20231106 110221 worker: Automatic CoverView (Off)
20231106 110221 worker: On-screen keyboard (Off)
20231106 110221 worker: Library scope (all)
20231106 110221 worker: Library active search (None)
20231106 110221 worker: View reset to (Playback)
20231106 110221 sendEngCmd(): File open failed, UI has never been opened in Browser
20231106 110221 worker: Maintenance interval (360 minutes)
20231106 110221 worker: Screen saver activation (Never)
20231106 110221 worker: Session permissions (OK)
20231106 110221 worker: --
20231106 110221 worker: -- Startup complete
20231106 110221 worker: --
20231106 110221 worker: Mount monitor (off)
20231106 110221 worker: Watchdog monitor (started)
20231106 110221 worker: Responsiveness (Boosted)
20231106 110221 worker: Sleep intervals (worker=1.5, waitworker=0.75, watchdog=6, mountmon=30, gpiobuttons=1)
20231106 110221 worker: Ready
20231106 120621 waitWorker(): Start (sys-config, w_active=0)
20231106 120621 waitWorker(): End   (sys-config, w_active=0)
20231106 120640 waitWorker(): Start (sys-config, w_active=0)
20231106 120640 waitWorker(): End   (sys-config, w_active=0)
20231106 120656 waitWorker(): Start (sys-config, w_active=0)
20231106 120656 waitWorker(): End   (sys-config, w_active=0)
20231106 120723 waitWorker(): Start (sys-config, w_active=0)
20231106 120723 waitWorker(): End   (sys-config, w_active=0)
20231106 120751 waitWorker(): Start (sys-config, w_active=0)
20231106 120751 waitWorker(): End   (sys-config, w_active=0)

[Tim Curtis]

What is the URL of the radio station that was playing at the time?
It's odd that the DNS address 195.130.131.3 is not on the same 192.168.0 network segment as the Pi

[funnyf]

The URL of the radio station is http://icecast.vrtcdn.be/stubru-high.mp3
The DNS address comes from the Belgian internet provider, Telenet.

Just now I had the same problem, but the radio station was still visibile and it seemed that was playing (but there was no sound). When I paused it, and press play again, it started again.

[Tim Curtis]

The URL is same as for the built in station "Studio Brussels".
It's been playing just fine on my end for the last 3 hours and thus I'm not able to repro your issue.

It's extremely rare for the WebUI to just go away but some things that could potentially cause that symptom include Web stack (PHP, NGINX) crashing or MPD crashing. It's not obvious to me though why that would happen.

I'd suggest troubleshooting by process of elimination. Do things one at a time for example change from Ethernet to WiFi connection. Try different radio stations, song files, etc.

[funnyf]

Thx Tim. I will try that. Have you ever steen this:

The time runs and the equalizer moves. Just no sound anymore.
When I pauze and press play again. The sound is back.

[the_bertrum]

I see those symptoms occasionally. When it happens, there are entries in the MPD log about "playing silence to avoid xrun". Have a look in /var/log/mpd/log for any messages.

[funnyf]

I can this error in the mpd log:

Nov 07 08:31 : alsa_output: Decoder is too slow; playing silence to avoid xrun

[the_bertrum]

I can this error in the mpd log:

Nov 07 08:31 : alsa_output: Decoder is too slow; playing silence to avoid xrun

OK, that's exactly the condition I get from time to time.  I have been unable to locate a cause myself, and you are the first person on the Forum to have the same issue that I'm aware of.  I suspect in my case that my home network/ISP is to blame, in particular the "smart" router that I got from the ISP that "optimises" connections to ensure speed (or something).  I suspect the optimising interrupts the stream enough to throw ASLA or MPD off kilter and restarting the stream sorts it out again.
Since it doesn't seem to be an issue with moOde (most other users don't see it), nor a problem with the stream (likewise no other users have bother) I have a rather inelegant fix of a script that checks the log and restarts the stream when it sees the error.

Code:

#!/bin/bash
#XRUN_restart.sh - look for and attempt to recover from under-runs and timeouts in MPD.
LASTLOG=$( tail -n 1 /var/log/mpd/log )
STATUS=$(mpc status)
if [[ $STATUS = *"playing"* && $LASTLOG = *"xrun"* ]];
then
    echo "xrun matched"
    mpc stop
    mpc play
else
    LASTLOG=$( tail -n 2 /var/log/mpd/log )
    if [[  $STATUS != *"playing"* && $LASTLOG = *"timed out"* ]];
    then
        echo "timeout matched"
        mpc play
    fi
fi

That's the script, and putting aside the lesson I was taught 30 years ago about avoiding infinite loops in code, I use this to fire it every second:

Code:

#!/bin/bash
while sleep 1; do /home/<your username here>/XRUN_restart.sh; done

I then create a service to start the looper script on boot and the restart script will usually recover within a second or so.  Not perfect, but it saves having to press play all the time

[funnyf]

thank you, I've added the script and service.

Now I cannot wait for the music to stop to check the logs

[the_bertrum]

Now I cannot wait for the music to stop to check the logs

Ha, ha! Yes, it took a lot of waiting around to test the thing when I was writing it. I was certain just having the code there made the problem happen less often