Fix random audio dropouts and corruption of audio data (1/2)

[floele]

Description

This is the first part of the original PR #5993. Would appreciate a "Seeking testers" so we can test this change separately from the other one if in doubt about side effects.

Previously, source->next_audio_ts_min was incremented by conv_frames_to_time(sample_rate, in.frames) in each call of source_output_audio_data(), so only by the duration of the audio data which is basically a fixed value (if in.frames doesn't vary).

However, this does not take the incoming audio timestamps into account, which also include execution time. In ProcessCaptureData() for example os_gettime_ns() is used to generate the audio timestamp if device timestamps are off so it's unavoidable that the incoming timestamps are always a little later than the raw duration of the audio data. This also applies if device timestamps are enabled though, at least when recording from desktop audio (Windows 10) which I have used to verify the issue.
This adds up, because in.timestamp is being set to source->next_audio_ts_min before calculating the next timestamp source->next_audio_ts_min = in.timestamp + conv_frames_to_time(sample_rate, in.frames).

If you watch the values over time, you can see the timestamps deviating like this (extract of a few thousand iterations):

next_audio_ts_min: 366688637418000, actual timestamp: 366688637507100, diff: 89100
next_audio_ts_min: 366690227418000, actual timestamp: 366690227453000, diff: 350000
next_audio_ts_min: 366697247418000, actual timestamp: 366697247892200, diff: 474200
next_audio_ts_min: 366702747418000, actual timestamp: 366702748130500, diff: 712500
next_audio_ts_min: 366705197418000, actual timestamp: 366705198281800, diff: 863800
next_audio_ts_min: 366708257418000, actual timestamp: 366708258445200, diff: 1027200

So the incoming audio timestamps gradually deviate further from the expected next_audio_ts_min timestamp, eventually exceeding TS_SMOOTHING_THRESHOLD and then causing a call to source_output_audio_place() which either overwrites existing audio data and causes a glitch or puts data beyond the end of the buffer, resizing it and inserting a gap and thus causing an audio dropout.

Now next_audio_ts_min is incremented based on the current incoming audio timestamp to prevent this issue.

For testing purposes, this issue can be detected by looking for "frames: %lu, size: %lu, placement: %lu, base_ts: %llu, ts: %llu" debug messages (with DEBUG_AUDIO enabled).

Motivation and Context

Fixes #4600 (one of the two kinds of dropouts investigated).

In short, audio recorded or streamed by OBS contains random short dropouts or corruption, independently of settings and environment, though frequency may vary. The frequency of the issue occuring ranges from every couple of minutes to maybe once or twice per hour based on my observations and the reports in the mentioned issue.

How Has This Been Tested?

For my tests I use a test tone generator to record continuous uniform audio data with OBS (default settings, Windows 10). I then check the resulting audio stream for dropouts. For testing, I usually record 1 to 2 h of audio data.

Types of changes

• Bug fix (non-breaking change which fixes an issue)

Checklist:

• My code has been run through clang-format.
• I have read the contributing document.
• My code is not on the master branch.
• The code has been tested.
• All commit messages are properly formatted and commits squashed where appropriate.
• I have included updates to all appropriate documentation.

[cattywampus04]

Hi, still testing, but tried using the 2022-03-12-85e941123-27.2.0-win64 that you posted 6 days ago, but I try record I get "Starting the output failed". Tried with NVENC and x264. Not sure what is wrong? Is this build even intended for testing?

Thanks

[floele]

Hi @Stuwot, looks like you're right, I apparently based it on a broken version of OBS. Updated it now, please try again :)

As for audio/video sync issues, please check the following things:

• Does the delay accumulate over time or is there a fixed delay across the whole recording?
• Is audio ahead or behind?
• Can the same delay be seen in regular OBS versions too? Possibly the sync issue does not happen every time so you might want to try a few recordings with each version.
• Finally, it would be good to know if you experience the issue with builds from both of my PRs or only the second one which includes both changes. I would assume that the changes made with this PR (only one of two issues fixed) have no impact on audio/video sync.

[cattywampus04]

Does the delay accumulate over time or is there a fixed delay across the whole recording?
Is audio ahead or behind?
On 2022-03-05-2de59b407 build, the audio seemed to be synced at the start of the recording, but gradually goes out of sync over time. It took maybe 30 minutes for it to become noticeable, but after 45-60 minutes it was very noticeable. By the 90-105 minute mark, the audio is off by a second or so.

To be clear too: the audio goes out of sync on things like camera to microphone, but also capturing a Chrome window and playing Youtube video, the audio on the video slips out of sync.

Can the same delay be seen in regular OBS versions too? Possibly the sync issue does not happen every time so you might want to try a few recordings with each version.
No the audio delay is not present in the regular version of OBS. I did a test recording to double check. I also did multiple recordings using the 2022-03-05-2de59b407 build, with "use device timestamps" ticked and unticked, and each resulted in the same out-of-sync behaviour.

Finally, it would be good to know if you experience the issue with builds from both of my PRs or only the second one which includes both changes. I would assume that the changes made with this PR (only one of two issues fixed) have no impact on audio/video sync.
I am just grabbing your new build I reported yesterday wouldn't work that you have now fixed. I will test on that, but I need some clarification on he "both of your PRs". When you say "both" do you mean build 2022-03-05-2de59b407 AND OBS-Studio-27.2.0-5cd247710-Win64 which you just uploaded? Or was it an earlier build? Sorry for asking what am sure are dumb questions.

Thanks!

[cattywampus04]

Sorry, just another update. In the OBS-Studio-27.2.0-5cd247710-Win64 build, the browser seems to be broken. Nothing displays, local or remote.

Not sure why.

[WizardCM]

Sorry, just another update. In the OBS-Studio-27.2.0-5cd247710-Win64 build, the browser seems to be broken. Nothing displays, local or remote.

Not sure why.

Any behaviours you see outside of audio is due to unrelated changes in the OBS master branch. We completely overhauled how we build OBS, so we expect things to be broken while we figure it out.

[cattywampus04]

Sorry, just another update. In the OBS-Studio-27.2.0-5cd247710-Win64 build, the browser seems to be broken. Nothing displays, local or remote.

Not sure why.

Ahhh ok. Understood! Thanks!

[PatTheMav]

@Lain-B Is this actually a desirable change? As @norihiro pointed out in the original PR, the audio subsystem runs on its own timer and calculates "expected" timestamps for incoming audio packets accordingly.

A minor deviation of device timestamps to this internal timestamp is baked into the code (we just treat incoming audio packets as having arrived at the calculated timestamp then).

A runaway difference (as explained in the OP) could only happen if the source is not able to consistently produce new audio packets within 70µs of the calculated timestamps (in my tests with CoreAudio, differences sat between 7µs and 21µs) but instead takes considerably longer every time. Wouldn't that be indicative of an issue with the audio device or the subsystem then?