HEnquist / camilladsp

A flexible cross-platform IIR and FIR engine for crossovers, room correction etc.
https://henquist.github.io/
GNU General Public License v3.0
505 stars 48 forks source link

Restarting playback due to perceived buffer underrun #315

Closed oliver-bendig closed 4 months ago

oliver-bendig commented 5 months ago

Hi,

first of all a great thanks for this fantastic project! I tried to run camilladsp 2.0.1 on my wIndows desktop machine (3.7GHz Core i5 12th gen) . Unfortunately, there is a lot of crackling/distortion in the sound and there are buffer underrun errors. I tried many different combinations of chunksize and target_level, but didn't get it to work. CPU usage is not measurable < 0.1%. I removed all filters and also tried to set realtime thread priority to the camilladsp process, but nothing worked.

The log looks is full of lines like this:

2024-01-22 20:38:23.746499 WARN [src\wasapidevice.rs:360] Missing event! Resetting stream. Interval 0.015354166666666558 s, expected 0.01 s
2024-01-22 20:38:23.756500 WARN [src\wasapidevice.rs:397] Playback interrupted, no data available
2024-01-22 20:38:23.766533 INFO [src\wasapidevice.rs:381] Restarting playback after buffer underrun
2024-01-22 20:38:24.106510 WARN [src\wasapidevice.rs:397] Playback interrupted, no data available
2024-01-22 20:38:24.116531 INFO [src\wasapidevice.rs:381] Restarting playback after buffer underrun
2024-01-22 20:38:32.886967 WARN [src\wasapidevice.rs:360] Missing event! Resetting stream. Interval 0.015020833333332817 s, expected 0.01 s
2024-01-22 20:38:34.817766 WARN [src\wasapidevice.rs:360] Missing event! Resetting stream. Interval 0.015270833333333345 s, expected 0.01 s
2024-01-22 20:38:34.857801 WARN [src\wasapidevice.rs:397] Playback interrupted, no data available
2024-01-22 20:38:34.867896 INFO [src\wasapidevice.rs:381] Restarting playback after buffer underrun
2024-01-22 20:38:36.907840 WARN [src\wasapidevice.rs:397] Playback interrupted, no data available
2024-01-22 20:38:36.918734 INFO [src\wasapidevice.rs:381] Restarting playback after buffer underrun
2024-01-22 20:38:43.067932 WARN [src\wasapidevice.rs:360] Missing event! Resetting stream. Interval 0.015375000000000583 s, expected 0.01 s
2024-01-22 20:38:56.848130 WARN [src\wasapidevice.rs:360] Missing event! Resetting stream. Interval 0.015041666666666842 s, expected 0.01 s
2024-01-22 20:38:57.388084 WARN [src\wasapidevice.rs:397] Playback interrupted, no data available
2024-01-22 20:38:57.398162 INFO [src\wasapidevice.rs:381] Restarting playback after buffer underrun
2024-01-22 20:38:59.168129 WARN [src\wasapidevice.rs:360] Missing event! Resetting stream. Interval 0.015000000000000124 s, expected 0.01 s
2024-01-22 20:38:59.948145 WARN [src\wasapidevice.rs:397] Playback interrupted, no data available
2024-01-22 20:38:59.958263 INFO [src\wasapidevice.rs:381] Restarting playback after buffer underrun
2024-01-22 20:39:01.248610 WARN [src\wasapidevice.rs:360] Missing event! Resetting stream. Interval 0.01564583333333358 s, expected 0.01 s
2024-01-22 20:39:01.578746 WARN [src\wasapidevice.rs:360] Missing event! Resetting stream. Interval 0.01533333333333331 s, expected 0.01 s
2024-01-22 20:39:02.390024 WARN [src\wasapidevice.rs:360] Missing event! Resetting stream. Interval 0.015958333333333297 s, expected 0.01 s
2024-01-22 20:39:02.500836 WARN [src\wasapidevice.rs:397] Playback interrupted, no data available
2024-01-22 20:39:02.520869 INFO [src\wasapidevice.rs:381] Restarting playback after buffer underrun

Actually, I wondered about the long floating numbers and thought that they are pretty close to the mentioned 0.01s - so maybe something with the if condition? I don't know all the technical details, but I simply tried to change the if condition wasapidevice.rs line 358

if buffer_free_frame_count > 0
            && (device_time - device_prevtime) > 1.5 * (buffer_free_frame_count as f64 / samplerate)

to

if buffer_free_frame_count > 0
            && (device_time - device_prevtime) > 1.6 * (buffer_free_frame_count as f64 / samplerate)

to disarm this check and avoid restarting the audio stream. This fixed the buffer underruns and the distortion for me. At least I don't hear any distortion anymore. From time to time, there are still complains about Interval 0.016xxx now in the log, but only very few and no more crackling/buffer underruns anymore.
Maybe my findings are somehow helpful...

Herre a logfile with chunksize=8192, target_level=16383. These were best values I was able to find. camilla_trace.zip

Thanks, Olli

HEnquist commented 5 months ago

Thanks for the report, and for figuring out a way to solve it! The check is there to catch an issue, I mostly have seen with VB Cable, where the capture device sometimes would miss an event. The check simply checks that the time between events isn't too long. If it's over twice the expected time, then there was a missed event. I put the limit at 1.5 because it was an easy number that seemed to work well, but it could well be a larger number closer to 2.0. You could try 1.8 or even 1.9 to see if that gets rid of the last few warnings. There is a risk that it doesn't catch a missed event (larger risk the closer you get to 2.0). If that happens, there will be lots of warnings, and the sound becomes really choppy.

oliver-bendig commented 5 months ago

Hi, thanks for the very quick reply and the technical background! There was no difference for me when running with VB-Cable and my onboard Soundcard (Realtek Audio) as capture device. Both showed the same error messages and the same intervals. I changed to 1.7 now and no more errors in the log anymore. I am enjoying the music now! :-) CamillaDSP is absolutely great! Thanks again!

HEnquist commented 5 months ago

Thanks for testing! I will include this fix in the next version.

HEnquist commented 5 months ago

The fix is included here: https://github.com/HEnquist/camilladsp/pull/319/files

HEnquist commented 4 months ago

fixed in release 2.0.2