Playout goes out of Sync after a while

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

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 ?

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: