Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

LS falling back to backup when it shouldn't #3912

Open
voipster opened this issue May 10, 2024 · 12 comments
Open

LS falling back to backup when it shouldn't #3912

voipster opened this issue May 10, 2024 · 12 comments

Comments

@voipster
Copy link

Debian running LS in a docker container

radio = mksafe(fallback( track_sensitive=false, [live, playlist] ))

Where live is a harbor input and playlist is a local file backup

Every half hour or so when live is going out (streaming from Stereo Tool), LS drops out to the backup for about ten seconds.

I initially thought it was the silence detection I had set on the Harbor endpoint. So I dropped the threshold right down, and when that didn't fix it, took it off completely so it's just:

live = input.harbor( id="live", port=8000, password=HARBOR_PASS, buffer=6.,max=30.,"live.mp3" )

But the drop out is still happening. The Internet is a rock steady 1Gb/s, and the server is ok too... what am I looking for, in terms of logging etc?

@toots
Copy link
Member

toots commented May 10, 2024

Hi.

Do you have logs around the time when the switch happens?

@voipster
Copy link
Author

Yes, what am I looking for? I can't post them in a public forum as there's loads of identifying info so I'd need sign off for GDPR etc...

@voipster
Copy link
Author

voipster commented May 10, 2024

Actually looking at it, the most pertinent parts are postable.... does this help?

2024/05/10 09:56:19 [cross:3] Analysis: -25.075215dB / -26.556913dB (4.98s / 5.02s)
[mp3 @ 0x7fc23e60b000] Estimating duration from bitrate, this may be inaccurate
2024/05/10 09:56:20 [crossfade:3] No transition: using default.
2024/05/10 09:56:20 [cross_before.2743:3] Content type is {audio=pcm(stereo)}.
2024/05/10 09:56:20 [buffer.5485:3] Content type is {audio=pcm(stereo)}.
2024/05/10 09:56:20 [cross_after.2743:3] Content type is {audio=pcm(stereo)}.
2024/05/10 09:56:20 [buffer.5486:3] Content type is {audio=pcm(stereo)}.
2024/05/10 09:56:20 [clock.main:2] We must catchup 1.02 seconds!
2024/05/10 10:00:00 [live:3] Decoding...
2024/05/10 10:00:04 [live:2] Feeding stopped: Avutil.Error(Invalid data found when processing input).
2024/05/10 10:00:04 [live:3] Decoding...
2024/05/10 10:00:16 [switch.5:3] Switch to live with transition.
2024/05/10 10:20:02 [switch.5:3] Switch to cross with forgetful transition.
2024/05/10 10:20:02 [replay_metadata.7617:3] Content type is {audio=pcm(stereo)}.
2024/05/10 10:20:08 [switch.5:3] Switch to live with transition.
2024/05/10 10:20:08 [replay_metadata.7618:3] Content type is {audio=pcm(stereo)}.
2024/05/10 10:39:47 [switch.5:3] Switch to cross with transition.
2024/05/10 10:39:47 [replay_metadata.7619:3] Content type is {audio=pcm(stereo)}.
2024/05/10 10:39:53 [switch.5:3] Switch to live with transition.
2024/05/10 10:39:53 [replay_metadata.7620:3] Content type is {audio=pcm(stereo)}.
2024/05/10 10:59:31 [switch.5:3] Switch to cross with forgetful transition.
2024/05/10 10:59:31 [replay_metadata.7621:3] Content type is {audio=pcm(stereo)}.
2024/05/10 10:59:37 [switch.5:3] Switch to live with transition.
2024/05/10 10:59:37 [replay_metadata.7622:3] Content type is {audio=pcm(stereo)}.
2024/05/10 11:00:02 [current:3] Reloading playlist with URI /data/xxxxx.
2024/05/10 11:00:02 [decoder.ffmpeg:3] Requested content-type for "/data/xxxxx/xxxxx.mp3": {audio=pcm(stereo)}
2024/05/10 11:00:02 [decoder.ffmpeg:3] FFmpeg recognizes "/data/xxxxx/xxxxx.mp3" as audio: {codec: mp3, 44100Hz, 2 channel(s)}
2024/05/10 11:00:02 [decoder.ffmpeg:3] Decoded content-type for "/data/data/xxxxx/xxxxx.mp3": {audio=pcm(stereo)}
2024/05/10 11:19:25 [switch.5:3] Switch to cross with transition.
2024/05/10 11:19:25 [replay_metadata.7623:3] Content type is {audio=pcm(stereo)}.
2024/05/10 11:19:31 [switch.5:3] Switch to live with transition.
2024/05/10 11:19:31 [replay_metadata.7624:3] Content type is {audio=pcm(stereo)}.
2024/05/10 11:39:10 [switch.5:3] Switch to cross with transition.
2024/05/10 11:39:10 [replay_metadata.7625:3] Content type is {audio=pcm(stereo)}.
2024/05/10 11:39:16 [switch.5:3] Switch to live with transition.
2024/05/10 11:39:16 [replay_metadata.7626:3] Content type is {audio=pcm(stereo)}.
2024/05/10 11:59:06 [switch.5:3] Switch to cross with forgetful transition.
2024/05/10 11:59:06 [replay_metadata.7627:3] Content type is {audio=pcm(stereo)}.
2024/05/10 11:59:12 [switch.5:3] Switch to live with transition.

@voipster
Copy link
Author

Updated with more. It seems to be doing it every 20 minutes, to the clock.

@voipster
Copy link
Author

Hey, any thoughts of this?

@vitoyucepi
Copy link
Collaborator

Hi @voipster,
I'm interested to see if this is caused by the buffer running out.
Maybe you could log the buffer length of live like this

live = input.harbor(...) 
thread.run({log.important("Buffer length: #{live.buffer_length()}", label="live")}, every=0.5)

You can choose to log this message to a file if you'd like to do so.

@toots
Copy link
Member

toots commented May 14, 2024

@vitoyucepi suggestion is on point. If the sender's clock has a drift, this is what you would observe.

@voipster
Copy link
Author

@vitoyucepi suggestion is on point. If the sender's clock has a drift, this is what you would observe.

Can you define "has a drift"? I've checked - host, docker container and sender are all in sync with NTP. The only difference between all three is that the container (running ls) is set to UTC. Would that have a bearing?

@voipster
Copy link
Author

thread.run({log.important("Buffer length: #{live.buffer_length()}", label="live")}, every=0.5)

So I can see straight away that it's (very slowly) counting down that 6s buffer over the course of the 20 minutes before it will drop it and start again.

How do I fix it?

@vitoyucepi
Copy link
Collaborator

I don't know what's causing your problem yet, but in an ideal world the streaming client should produce 1 second of content per 1 second. I like to call it a rate, and the ideal rate is 100%.
If the rate is less than 100%, then eventually the initial buffer will run out and the server will have to refill the buffer.
If the rate is greater than 100%, then the buffer will overflow and the server will drop the part of the content.

As a quick fix, you can use buffer.adaptive, which can slow down or speed up the content, but it can cause distortion.

streaming from Stereo Tool

Can you verify that the Stereo Tool is (not) the cause of the problem by disabling it?

@voipster
Copy link
Author

Can you verify that the Stereo Tool is (not) the cause of the problem by disabling it?

Interesting, switched to using BUTT and the problem has gone. So it's some setting in ST I guess?

@vitoyucepi
Copy link
Collaborator

So it's some setting in ST I guess?

I think so. If you're a paid customer of Stereo Tool, it's probably a good idea to contact their support.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants