Playout goes out of Sync after a while

Get Help
1

Hi together,

i’m running the newest Release of LibreTime on Debian 10 and my Instance seems to ge out of Sync to the Clock after a while.

I had this happen multiple times, a simple restart of the libretime-playout service fixes this issue but this is not a good solution since we run LibreTime on a 24/7 Air-Critical Mission (FM/DAB+ Broadcast).

Is i go to Status in the Menu i see that LibreTime is infoming me that something with Pypo does not work right:

Check that the libretime-playout service is installed correctly in…

systemctl status libretime-playout

Tells me that the service is running and active.

Logs of LiquidSoap looks like they want to tell me something but i’m really unclear what is going on here.

EDIT: The next Show should start right at 23:00 (11pm) but while i listened to the Alsa output i did realise the Show more or less started 2 Minutes late.

ls_script.log is here:

2021/12/25 23:00:00 [server:3] New client: 127.0.0.1.
2021/12/25 23:00:00 [lang:3] vars.show_name
2021/12/25 23:00:00 [server:3] Client 127.0.0.1 disconnected.
2021/12/25 23:01:45 [decoder:3] Method "MAD" accepted "/var/tmp/airtime/pypo/cache/scheduler/111.mp3".
2021/12/25 23:01:46 [cue_cut_7721:3] Cueing out...
2021/12/25 23:01:46 [s4:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/30.mp3".
2021/12/25 23:01:46 [s4:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/111.mp3" (RID 0).
2021/12/25 23:01:46 [lang:3] timeout --signal=KILL 45 libretime-playout-notify --media-id=64 &
2021/12/25 23:01:46 [lang:3] Using stream_format 2
2021/12/25 23:01:46 [lang:3] Using stream_format 2
2021/12/25 23:01:46 [alsa_out(default):2] Underrun!
2021/12/25 23:01:46 [alsa_out(default):2] Trying to recover..
2021/12/25 23:01:46 [lang:3] Using stream_format 2
2021/12/25 23:01:50 [cue_cut_7721:3] Cueing out...
2021/12/25 23:01:50 [s4:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/111.mp3".
2021/12/25 23:01:50 [dummy(dot)3:3] Source failed (no more tracks) stopping output...
2021/12/25 23:01:50 [dummy(dot)4:3] Source failed (no more tracks) stopping output...
2021/12/25 23:01:50 [schedule_noise_switch:3] Switch to map_metadata_7800 with forgetful transition.
2021/12/25 23:01:50 [lang:3] transition called...
2021/12/25 23:01:50 [decoder:3] Method "MAD" accepted "/var/tmp/airtime/pypo/cache/scheduler/146.mp3".
2021/12/25 23:01:50 [s4:3] Prepared "/var/tmp/airtime/pypo/cache/scheduler/146.mp3" (RID 2).
2021/12/25 23:01:50 [schedule_noise_switch:3] Switch to map_metadata_7793 with transition.
2021/12/25 23:01:50 [lang:3] transition called...
2021/12/25 23:01:50 [switch_7791:3] Switch to insert_metadata_7777.
2021/12/25 23:01:50 [lang:3] timeout --signal=KILL 45 libretime-playout-notify --media-id=92 &
2021/12/25 23:01:50 [lang:3] Using stream_format 2
2021/12/25 23:01:50 [lang:3] Using stream_format 2
2021/12/25 23:01:50 [lang:3] Using stream_format 2
2021/12/25 23:03:01 [server:3] New client: 127.0.0.1.
2021/12/25 23:03:01 [server:3] Client 127.0.0.1 disconnected.
2021/12/25 23:03:02 [server:3] New client: 127.0.0.1.
2021/12/25 23:03:02 [lang:3] queues.s8_skip
2021/12/25 23:03:02 [lang:3] queues.s8_skip
2021/12/25 23:03:02 [lang:3] queues.s8_skip
2021/12/25 23:03:02 [lang:3] queues.s8_skip
2021/12/25 23:03:02 [lang:3] queues.s8_skip
2021/12/25 23:03:02 [s4:3] Finished with "/var/tmp/airtime/pypo/cache/scheduler/146.mp3".
2021/12/25 23:03:02 [server:3] Client 127.0.0.1 disconnected.
2021/12/25 23:03:02 [cue_cut_7721:3] End of track before cue-out point.
2021/12/25 23:03:02 [cross_7728:3] No next track ready yet.
2021/12/25 23:03:02 [dummy(dot)3:3] Source failed (no more tracks) stopping output...
2021/12/25 23:03:02 [dummy(dot)4:3] Source failed (no more tracks) stopping output...
2021/12/25 23:03:02 [schedule_noise_switch:3] Switch to map_metadata_7800 with forgetful transition.
2021/12/25 23:03:02 [lang:3] transition called...
2021/12/25 23:03:02 [server:3] New client: 127.0.0.1.
2021/12/25 23:03:02 [lang:3] streams.live_dj_stop
2021/12/25 23:03:02 [lang:3] streams.master_dj_stop
2021/12/25 23:03:02 [lang:3] streams.scheduled_play_start
2021/12/25 23:03:02 [lang:3] vars.stream_metadata_type
2021/12/25 23:03:02 [lang:3] vars.station_name
2021/12/25 23:03:02 [lang:3] vars.default_dj_fade
2021/12/25 23:03:02 [server:3] Client 127.0.0.1 disconnected.
2021/12/25 23:03:02 [server:3] New client: 127.0.0.1.
2021/12/25 23:03:02 [lang:3] queues.s8_skip
2021/12/25 23:03:02 [lang:3] queues.s8_skip
2021/12/25 23:03:02 [lang:3] queues.s8_skip

I really hope someone can help me here, i’m totally lost here and restarting the Service while our Program is running is kind of bad since it leads to a signal loss for a moment and this is really bad for a broadcaster.
Sure we are just a small public radio station with everyone just being hobbyist’s but still this is something that bothers me since i’m the technician and even tho i get no pay i still want to run the best Systems i can.
Lastly i could just move our automation to mAirList but i really like the way LibreTime works for us and i don’t want to stop using it if there is a solution.

Any advice is well appreciated !

Greetings from Germany (and Merry Christmas by the way)
~Chris

2

So this is still an ongoing issue.
My only temporary fix is a Cron Job that restarts libretime-playout but this is not a elegant solution.
Does no one have an idea ?

3

So i found the Problem (kind of).
I have absolutely NO IDEA what causes this issue, BUT:
If i DISABLE the ALSA output and instead use cvlc to play out the Icecast2 Stream it works just fine.

This seems like a serious issue to me since i now have a bit more delay but at least i have a stable Instance now…

I would love to have a nicer solution but as it seems no one has any idea :slight_smile:

4

Here the same.

New install and sometimes the stream stops playing random

Ill hope somebody do have the solution

5

Do you use ALSA playout or just the livestream feature ?
In my case this issue was caused by ALSA as it seems.
After deactivating and playing the Stream via cvlc to my soundkard the issue disappeared.

6

I du use the normal livestream future.

I did solve the problem to stream with an other port then 8000 (standard feature)

Now it looks like stable…

7

Hey @Chris-The-Tuner

Have you tried to upgrade to version of liquidsoap you are using ? I suggest you install liquidsoap 1.4.4 on you debian buster, you can download the deb package directly from the liquidsoap release page.

I don’t know if this will fix your issue, but that will still be a step forward I think.

Cheers,
Jo

8

I tried but sadly it did not help.
But as long as the System runs fine like it is i’m good with it.
Not a nice solution but the Listener on FM or DAB+ does not know that the system is a bit strange :smiley:

9

Here i tried the update but the output stream stops after 5 seconds after every single song

10

Hi,

I noticed a recurring pattern in the playout logs indicating that the playout sometimes goes out of sync. To mitigate this, I wrote a small monitoring setup (script + systemd unit) that watches the logs and automatically restarts the playout service when the issue occurs.

You’ll likely need to adapt this to your setup (e.g., if you’re using Docker instead of Podman, or if LibreTime runs directly on the host), but the idea is simply to watch for a known error pattern in the logs and restart the playout when it happens.

Monitoring script :

#!/bin/bash

# monitor_playout.sh

CONTAINER_NAME="libretime_playout_1"
ERROR_PATTERN="ERROR.*libretime_playout.player.queue.*'NoneType'"
COOLDOWN=120

echo "Starting monitoring of $CONTAINER_NAME for queue NoneType errors"

podman logs -f --tail=0 "$CONTAINER_NAME" 2>&1 | while read line; do
  if echo "$line" | grep -qE "$ERROR_PATTERN"; then
    echo "CRITICAL ERROR DETECTED: Queue NoneType error"
    echo "Restarting container..."

    podman restart "$CONTAINER_NAME"
    
    if [ $? -eq 0 ]; then
        echo "Container restarted successfully"
    else
        echo "Container restart FAILED!"
    fi
    
    echo "Cooldown of ${COOLDOWN}s before resuming monitoring"
    sleep "$COOLDOWN"
    
    exec "$0"
  fi
done

systemd unit :

[Unit]
Description=LibreTime Playout Monitor
After=podman.service

[Service]
Type=simple
ExecStart=%h/.local/bin/monitor_playout.sh
Restart=always
RestartSec=10

[Install]
WantedBy=default.target