Playback (Audio) Stops in the middle of tracks

hi,

almost each second track stops audio somewhere in the middle.
no audio output, but playback and stream keeps going
until next track,
on next track audio starts again.

any ideas ?
maybe it has something todo with the silan issue

btw this happens not always, but when issue starts, the whole machine needs to be rebooted to fix.

after some time of watching, the issue starts after 30min after reboot, so its something like a buffer issue
not sure how to debug.

also i dont think its icecast issue, couse LT is streaming 2 streams, one to icecast and second to shoutcast
same on both, so maybe liquidsoap

Ok, so this is consistently happening to you ? Is it always the same tracks ? Is it possible that the tracks were cut off and are shorter then the system thinks they are ? Download the track and open it directly with a MP3 player. WE have seen something like this happen rather sporadically vs. consistently so it has been hard to diagnose. Check your pypo.log and liquidsoap log and see if you see any errors.

i have checked the files many times they are ok. its not same tracks
files cue in and out also correct

its not consistently, it happens randomly.
but when it starts it repeats same behavior until reboot

just tailing pypo.log will check it.

cant find any liquidsoap.log
also /var/log/liquidsoap is empty
just find this when locating “liquidsoap.log”
~/libretime/python_apps/pypo/liquidsoap/airtime-liquidsoap.logrotate

Blockquote
2019-03-08 10:17:54,455 [pypofetch] [INFO ] File ‘/var/tmp/airtime/pypo/cache/scheduler/324.mp3’ removed
2019-03-08 10:17:54,571 [pypofetch] [INFO ] File ‘/var/tmp/airtime/pypo/cache/scheduler/409.mp3’ removed
2019-03-08 10:17:54,575 [pypofetch] [INFO ] Loop #260
19-03-08 10:25:56,637 [pypofetch] [INFO ] Handling command: update_schedule
2019-03-08 10:25:56,662 [pypoliquidsoap] [INFO ] Need to remove items from Liquidsoap: set([3147])
2019-03-08 10:25:56,663 [pypofetch] [INFO ] New timeout: 480
2019-03-08 10:25:56,666 [pypofetch] [INFO ] Loop #262
2019-03-08 10:25:56,674 [pypoliquidsoap] [INFO ] Need to add items to Liquidsoap now: set([3146])
19-03-08 10:33:57,051 [pypoliqqueue] [INFO ] waiting 44.948878s until next scheduled item
2019-03-08 10:33:57,098 [pypofetch] [INFO ] File ‘/var/tmp/airtime/pypo/cache/scheduler/32.mp3’ removed
2019-03-08 10:33:57,193 [pypofetch] [INFO ] File ‘/var/tmp/airtime/pypo/cache/scheduler/302.mp3’ removed
2019-03-08 10:33:57,194 [pypofetch] [INFO ] Loop #263

there is always The “Loop” Entries in pypo.log when audio fails or better explained, its like putting silence in the rest of the current playing track until next track

i just see there was some permission problems, but i think its not permission issue.
same track plays fine next time

19-03-08 10:41:57,196 [pypofetch] [INFO ] Queue timeout. Fetching schedule manually

there is also this entry before the Loop entry

btw just find out that same happens while moving any track in scheduled list
same entries in pypo.log and silence

i have long scheduled shows, just 2 shows for 24h
the longer one has 16h playtime
maybe it has todo something with it
i see in pypo.log it loads whole list each time there is something changed

2019/03/09 19:01:35 [schedule_noise_switch:3] Switch to map_metadata_5852 with transition.
2019/03/09 19:01:35 [lang:3] transition called…
2019/03/09 19:01:35 [lang:3] vars.show_name
2019/03/09 19:01:35 [server:3] Client localhost.localdomain disconnected.
2019/03/09 19:01:35 [switch_5850:3] Switch to insert_metadata_5836.
2019/03/09 19:01:35 [amplify_5721:3] Overriding amplification: 0.891251.
2019/03/09 19:01:35 [lang:3] timeout --signal=KILL 45 pyponotify --media-id=4289 &
2019/03/09 19:01:35 [lang:3] Using stream_format 0

these entrys in
/var/log/airtime/pypo-liquidsoap/ls_script.log

some more logs

2019/03/09 19:06:46 [server:3] Client localhost.localdomain disconnected.
2019/03/09 19:06:46 [amplify_5781:3] Overriding amplification: 0.456037.
2019/03/09 19:06:46 [lang:3] timeout --signal=KILL 45 pyponotify --media-id=4290 &
2019/03/09 19:06:46 [lang:3] Using stream_format 0
2019/03/09 19:06:46 [lang:3] Using stream_format 0
2019/03/09 19:06:46 [lang:3] Using stream_format 0
2019/03/09 19:06:48 [cue_cut_5717:3] Cueing out…
2019/03/09 19:06:48 [s0:3] Finished with “/var/tmp/airtime/pypo/cache/scheduler/722.mp3”.
2019/03/09 19:06:48 [amplify_5721:3] End of the current overriding.
2019/03/09 19:06:48 [cross_5724:3] No next track ready yet.
2019/03/09 19:09:11 [server:3] New client: localhost.localdomain.
2019/03/09 19:09:11 [lang:3] dynamic_source.get_id
2019/03/09 19:09:11 [server:3] Client localhost.localdomain disconnected.
2019/03/09 19:09:11 [s4:3] Finished with “/var/tmp/airtime/pypo/cache/scheduler/5.mp3”.
2019/03/09 19:09:11 [cue_cut_5777:3] End of track before cue-out point.
2019/03/09 19:09:11 [amplify_5781:3] End of the current overriding.
2019/03/09 19:09:11 [schedule_noise_switch:3] Switch to map_metadata_5859 with forgetful transition.
2019/03/09 19:09:11 [lang:3] transition called…
2019/03/09 19:09:11 [dummy(dot)4:3] Source failed (no more tracks) stopping output…
2019/03/09 19:09:11 [dummy(dot)3:3] Source failed (no more tracks) stopping output…

Quick question, are you generally adding tracks to an ongoing show when this happens or is your show schedule setup completely ahead of time. From what I see it seems like you are modifying an ongoing show.

LibreTime wasn’t really programmed well to handle changes to a ongoing show. There are definitely some bugs in the airtime-playout python script. While I would love to get to the bottom of this the easiest workaround is to avoid modifying shows while they are playing and instead partition your shows into blocks where you can do most of your edits before the show starts airing.

I think that Airtime didn’t even allow you to modify a show at all once it was playing and LibreTime (or the saas-dev branch that became airtime.pro that we based LibreTime off of) added this capability but it hasn’t been fully vetted and I think we should discourage people from doing this until we can pinpoint what is causing the bug you are experiencing.

See this githug bug for my first attempt to document this error. You can feel free to contribute info there.

So if you dont have a lot of desire to troubleshoot the python airtime-playout and airtime-liquidsoap configuration I’d suggest trying to break your shows up into smaller segments and see if you can fix it that way.

Otherwise if you can document a set of steps that consistently causes this error and post it in that github issue along with logs will make it a LOT easier for someone with more python knowledge to fix the problem. If you know enough python to figure it out feel free to go at it.

hi thank you for this information

i see that issue on github, im trying to figure out since days

also i found an old issue, its also related to that i think

currently i have no more ideas on that :slight_smile:
but it is really annoying when you get dead air, for 1 minute or more

btw, the shows are been auto generated by smart blocks, so im not adding or moving tracks
but i can say it has something todo with that, couse when you move, add or delete tracks on ongoing shows, this happens constantly

So does the dead air usually go away by itself without you rebooting after a minute or so ?

silence starts always in the middle of current playing track until next track
next track starts normal with audiosignal

Check this issue on github Tracks longer than 55 minutes change status to "offline" · Issue #1275 · LibreTime/libretime · GitHub