serenity-rs / songbird

An async Rust library for the Discord voice API
ISC License
384 stars 110 forks source link

Intermittent Symphonia Probe Failures causing Playback issues on `next` branch #184

Closed maxall41 closed 1 year ago

maxall41 commented 1 year ago

Songbird version: next

Rust version (rustc -V): 1.69

Serenity/Twilight version: next branch serenity

Description: I'm getting intermittent symphonia reached probe limit errors on the next branch with about a 1/50 to a 1/5 chance of happening. It's a bit hard to tell because of the low sample size. It does seem to increase with more load (more concurrent streams). But its not a large load about 5 concurrent streams with 11% CPU Usage and only 30MB Memory usage. And i'm not entirely sure that is the case. Here is the log section when it happens:

[2023-05-19T00:17:08Z INFO songbird::driver::tasks::events ] Global event added.
[2023-05-19T00:17:10Z INFO songbird::driver::tasks::events ] Event state for track 1 added
[2023-05-19T00:17:10Z INFO songbird::events::store ] Firing Preparing for [0]
[2023-05-19T00:17:11Z ERROR symphonia_core::probe ] reached probe limit of 1048576 bytes.
[2023-05-19T00:17:11Z INFO songbird::events::store ] Firing Error for [0]
[2023-05-19T00:17:11Z ERROR hearth::worker::errors ] Track 23810d79-74a4-4a0e-bf8a-ed795d2db073 encountered an error: Errored(Parse(Unsupported("core (probe): no suitable format reader found")))

This happens when using the HttpRequest source. Though it may happen with others as I haven't tested any others.

Steps to reproduce:

  1. Copy basic example
  2. Create concurrent streams
  3. Try stopping and playing streams until error occurs.

Environment Arch: x86 OS: Ubuntu Linux System: 4 Core 8GB

FelixMcFelix commented 1 year ago

Whenever I saw something like this in testing, it tended to be because I'd been served a page body or other HTTP response instead of valid audio data. What website are you making requests to? What codecs do you have enabled?

maxall41 commented 1 year ago

The funny thing is I'm using the exact same file served from the exact same URL between play requests. And it seems to happen intermittently. And I'm not changing anything between requests. The file I'm using is: https://www.ee.columbia.edu/~dpwe/sounds/music/africa-toto.wav. And the codecs I have enabled are:

symphonia = { version = "0.5.2", features = ['pcm','mp3','wav','isomp4','aac','alac'] }

I also made sure I'm not getting rate limited or anything

maxall41 commented 1 year ago

Update: This also seems to happen when seeking at a lower frequency. I think this may be due to the servers serving africa-toto.wav (the test file I'm using) seem to be straight out of the 90s and are limited to about 900kbs so maybe there is some sort of issue here when the server isn't keeping up on occasion or something. Because it only very rarely happens with other tracks.

maxall41 commented 1 year ago

I have been able to confirm that this issue is due to the server not being able to keep up. This also explains why the frequency goes up with more concurrent tracks of the same song served from the same server.

FelixMcFelix commented 1 year ago

I just spun up 100 concurrent downloads of the file using request (77.9 Mbps) and then opened the URL in a web browser: image You are, in fact, being served an HTML document every once in a while, which can't be parsed as audio so the probing step fails. Status code is 520, which apparently means an unknown web server error in Cloudflare parlance. We should probably be checking Response::status on our side, which is a simple enough change if you feel like adding it to src/input/sources/http.rs.

maxall41 commented 1 year ago

Sure Il make a PR

Skarlett commented 1 year ago

Any chance we can get the status logged out via tracing if the process exits with a status code other than 0?

FelixMcFelix commented 1 year ago

@Skarlett That's a problem on current, where development is practically frozen. next does not call out to external processes.