obsproject / obs-studio

OBS Studio - Free and open source software for live streaming and screen recording
https://obsproject.com
GNU General Public License v2.0
58.54k stars 7.81k forks source link

Random short audio dropouts when recording or streaming #4600

Open floele opened 3 years ago

floele commented 3 years ago

Operating System Info

Windows 10

Other OS

No response

OBS Studio Version

27.0.0-rc2

OBS Studio Version (Other)

No response

OBS Studio Log URL

https://pastebin.com/WfdNU2QN

OBS Studio Crash Log URL

No response

Expected Behavior

Audio recording without dropouts.

Current Behavior

When recording or streaming, audio data contains multiple random short audio dropouts.

Looks like this: grafik

Distribution of the dropouts seems to be random but happen at a certain rate depending on which computer it is being run on. On my computer it’s approx. every 5 minutes, I have seen it on another computer where it happens roughly twice per hour. For a 40 min. test recording on my computer, dropouts have occurred at these time stamps: 00:03:19 00:09:40 00:15:38 00:19:51 00:23:41 00:29:55 00:36:07 The length of the dropouts are not necessarily all the same length.

Steps to Reproduce

  1. Launch OBS.
  2. Start test tone (I use https://www.szynalski.com/tone-generator/).
  3. Record desktop audio using OBS (all default settings) and wait.
  4. After stopping the recording, audio dropouts can be found in the resulting file.

As indicated above, the frequency of this issue seems to depend on hardware and may either not occur at all or very rarely on some systems, I'm not sure what it depends on.

The issue can also be reproduced without using a test tone of course, but a continuous tone makes it easier to check the resulting file for dropouts.

Anything else we should know?

Conditions

I have been testing on Windows 10 20H2 with OBS 26.1.2-276 and 27.0.rc2, 64 bit, without any video source configured (issue also happens with video configured though).

The issue seems to be independent of OBS settings (like audio sample rate or output format). I have not yet found any setting in the OS (like energy settings) that fix or reduce the issue.

The frequency of the issue seems to depend on the hardware. There are systems where I was not able to reproduce the issue, though I did not make excessively long recordings (> 4 h) to eliminate the possibility of the issue occurring on these systems.

The issue is not limited to recording from desktop audio but also applies when recording from external USB audio interfaces.
The issue is not limited to recording but also applies to streaming.

When an audio dropout occurs, the message “can't discard, data still pending” is seen in the debug output (if compiled with DEBUG_AUDIO).

The attached log file includes a debug message (Capture size: 480) I added, it outputs the captureSize variable in ProcessCaptureData() to check for any changes in amount of data being returned there.

Debug attempt

I’m not familiar with the OBS code base and the audio processing happening, but to me it seems like the problem is the fact that in audio_callback(), it always takes a fixed amount of data from the audio buffer (audio_size = AUDIO_OUTPUT_FRAMES * sizeof(float)) even if the buffer is not sufficiently filled due to potential delays in the capture thread.

What I have tried to solve this issue is basically waiting for the buffer to be filled, like this in audio_callback.

        if (!source->audio_pending && source->audio_ts > 0) {
            int iterations = 0;
            while (source->audio_input_buf[0].size < 4096) {
                blog(LOG_DEBUG,
                     "waiting 2 ms for audio buffer to fill (%s)",
                     obs_source_get_name(source));
                os_sleep_ms(2);
                iterations++;
            }

            if (iterations > 0) {
                blog(LOG_DEBUG,
                     "waited %i iterations for the audio buffer to fill",
                     iterations);
            }
        }

This significantly reduces the number of dropouts (on my system to like 1 in half an hour), but it’s not a good solution because additional to not entirely fixing the issue it doesn’t recover from the situation and adds continuous wait cycles after the first dropout that far exceed the number of dropouts that would have actually occurred. Also it seems kind of wrong to me doing that in the first place.

I would appreciate some guidance or a fix for this issue.

WizardCM commented 3 years ago

To confirm, this issue is not new in 27, as you've verified it in OBS 26.1.1?

floele commented 3 years ago

Yep, I have been investigating this in 26 already and only confirmed that it's still there before reporting.

DJ-3ncoder commented 3 years ago

I found a simillar or maybe the same issue in my latest stream recordings.

My software and hardware: OBS 27.0.1 Windows 10 64bit Focusrite Clarett 4Pre USB

My signal chain: Pioneer DJ Mixer puts out 48kHz signal via S/PDIF into the Focusrite Clarett. The soundcard gets the S/PDIF clock from the mixer and is locked to it. Every soft- and hardware is set to 48kHz.

OBS_Audio-drop-out

On the top there is the recording done with Audacity and on the bottom there is the audio-track from the recorded video. Recording is set to "stream encoder" (nvenc), mkv and remux to mp4 afterwards. The drop-out occurs in the mkv and mp4. Both audio-tracks are recorded using the same interface on the same computer. Audacity looks fine but OBS is struggling.

After scrolling through the waveforms I found this: OBS_Audio-time-shift To get the first picture I aligned the waveforms after the drop-out. The second picture is before the audio-drop out. You can see that the waveforms are not aligned. The bottom waveform (=OBS) is earlier in time. After seeing that I was thinking that the drop-out is more like a "break" in the signal because when you delete it and move the bottom waveform to the right, both are aligned all the time.

These drop-outs or "breaks" happen randomly. I do not click anything because in the video everyone can see that I am not in front of my PC.

Due to the fact that the Audacity recording is fine on the same PC I think this issue is caused by OBS. I do not know if it occurs in the stream too, nobody is listening that carefully.

Log-file: https://cloud.3ncoder.com/s/nsS7n98QYED9Tnr

konsolenritter commented 3 years ago

Unfortunately i must confirm. Still using obs 26.1.1 under win10. All sound devices disabled but a steinberg ur-22. External playback of 1khz tone. i7 10th generation nearby idling. With recording or streaming the same experience: By chance (random) happen such short dropouts. Sometimes once within in a couple of minutes, sometimes two dropouts within 20 seconds or even less. Randomly distributed. The try/workaround as of user floele i find very interesting.

Due to the nature of live events in the case of streaming people tend to be forgiving alot, especially in the case of ultra-short outages (its almost anticipated these days). But even then a short cut on audio is more distracting then a few lost frames. So ever stable audio wins (and is more important) over stable video for normal broadcast.

Would be unbelievable happy if that nasty thing could be fixed.

floele commented 3 years ago

Unfortunately I did not have time too look into the issue futher, just wanted to share the last thing I found out. It looks like (at least on my PC) I'm dealing with two different kind of dropouts. A frequent one (occurs roughly every 5 minutes) and an infrequent one (maybe each 30 min.).

I was able to fix the frequent one by changing the sleep method to a more precise alternative (example commit https://github.com/floele/obs-studio/commit/a34fda122b4307abff3c7670f8c4abba291e6173), but the issue I actually want to fix is the infrequent one because it reproduces on the machine I'm concerned about (and many other machines as far as I know). This one does not seem to trigger a “can't discard, data still pending” debug message so at this point I'm not sure when it is triggered or what is causing it.

konsolenritter commented 3 years ago

Is anybody else working on that issue here? My C or C++ is fifteen years ago..., so there is a little rust around. ;) I could imagine to invest a couple of hours into the obs-audio world over the next few weeks. My problem is, that i don't have a working environment to test and compile for windows here by myself. I'm totally fan of free software, but when it comes to ms studio or something alike... shiver

DJ-3ncoder commented 2 years ago

I found out that the problem that I am facing occurs at around 1h 7min of stream/recording time. It occurs only once but everytime at the same time!

grafik

Audacity recordings are fine. Changing the buffer size in the Focusrite panel makes no difference.

Maybe I can find out how to change log level to debug or so to find out what happens at 1h 7min.

bnacar commented 2 years ago

It's not just on Windows. This has been happening to me during livestreams and recordings on both MacOS and Linux, on average once every ten minutes. Just now I was able to replicate this after compiling from the latest source on Linux (Debian Stable). With OBS and Audacity recording simultaneously for fifteen minutes, I got two dropouts in the OBS recording and none from Audacity.

@floele were you ever able to pinpoint the cause of the less-frequent dropouts?

floele commented 2 years ago

Unfortunately I have not yet looked into it any further...it's still bothering me though.

DJ-3ncoder commented 2 years ago

Since the beginning of 2022 I tried the ASIO plugin for OBS. I set my input accordingly and the drop outs are still there. grafik

I also tried on a different computer (but the same soundcard). Same result, 1 drop out at timestamp 01:xx:xx of recording.

I am still shure that this bug is caused by OBS itself and not by my soundcard. It annoys me very much. Is there a way to change log level in OBS? I want to find out what is happening at that time. Normal loglevel does not log that drop out.

floele commented 2 years ago

If you combile OBS yourself you can enable the DEBUG_AUDIO flag for more logs.

After fixing one of the issues (the frequent dropouts) there weren't any relevant logs left corresponding to the occurrences of the issue on my PC though. So it's likely that these logs won't help you at all.

I also tried ASIO without success.

konsolenritter commented 2 years ago

Hi floele,

what is the toolchain needed to compile obs myself for/under win10? How much effort? Is there a clear documentation for this?

My IMHO feeling is that the problem is bound by the amount of samples obs reads each cycle in the audio thread from the samplequeue, and how this thread is triggered. Is it a fixed timing, a kernel timer based, or something else? Do you know something about?

Greez,

timo

Am 10.02.2022 um 23:07 schrieb floele:

If you combile OBS yourself you can enable the DEBUG_AUDIO flag for more logs.

After fixing one of the issues (the frequent dropouts) there weren't any relevant logs left corresponding to the occurrences of the issue on my PC though. So it's likely that these logs won't help you at all.

I also tried ASIO without success.

— Reply to this email directly, view it on GitHub https://github.com/obsproject/obs-studio/issues/4600#issuecomment-1035579157, or unsubscribe https://github.com/notifications/unsubscribe-auth/ANLNV47JOTGCLW2Y2UFQXKTU2QZINANCNFSM43TMLWEQ. Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

You are receiving this because you commented.Message ID: @.***>

floele commented 2 years ago

Yes, there are build instructions available. I would link to it, but apparently there is currently some reorganisation happening and the page asks not to link to it for the moment. So just look for it on Google ("Build Instructions (Windows) - OBS Studio"). You basically only need VS 2019 with C++ and install some additional tools (like QT). It's doable.

As for the issue, I've been focusing on https://github.com/obsproject/obs-studio/blob/master/libobs/media-io/audio-io.c and https://github.com/obsproject/obs-studio/blob/master/libobs/obs-audio.c but I'm starting to believe that maybe the issue might be at a later point in execution, maybe the muxing process.

The reading is basically sleep() controlled as far as I can see. As per my previous comment, this seems to be unreliable on my hardware so I replaced it with a different method, but that doesn't solve the problem everyone is having.

Fenrirthviti commented 2 years ago

apparently there is currently some reorganisation happening and the page asks not to link to it for the moment.

Where exactly are you seeing this comment? Our official build directions are on our Wiki pages here: https://github.com/obsproject/obs-studio/wiki/install-instructions

There is a pending cmake rewrite that will change how some things work at a high level, but the overall process should be largely unchanged.

bnacar commented 2 years ago

I tried adapting @floele's solution - of making the sleep time in the audio thread more precise - for Linux, and for whatever reason, it didn't affect the frequency of the dropouts (on my system anyway). I did several other experiments and this what I observed on my system:

The vast majority of audio dropouts that I've encountered are indeed correlated with the "data still pending" message, and these dropouts have a duration equivalent to whatever I set AUDIO_OUTPUT_FRAMES to. Using Audacity to visually inspect the recorded audio, the waveforms at the beginning and end of these dropouts line up, i.e. audio data is getting delayed, not deleted, and delayed by just about one sleep cycle.

In addition to making the sleep time in audio_thread more accurate, I tried setting AUDIO_OUTPUT_FRAMES to 768, which corresponds to a nice round number of 16 milliseconds when recording at 48kHz. Unfortunately this didn't make any difference either.

I'm not familiar with what sequence of events will deterministically result in a call to add_audio_buffering, but I tried modifying this function to add an absurd amount of buffering when it does get called:

- ticks = (int)((frames + AUDIO_OUTPUT_FRAMES - 1) / AUDIO_OUTPUT_FRAMES);
+ ticks = (int)((frames + 3 * AUDIO_OUTPUT_FRAMES - 1) / AUDIO_OUTPUT_FRAMES);

On the occasions that add_audio_buffering does get called, the additional extra buffer results in an initial long stretch of recording (on the order of 20 to 30 minutes) completely free of dropouts, but over that time the buffer gradually shrinks until there isn't enough data available, and then the dropouts resume.

In short, audio data is being output slightly faster than it gets added to the buffer. If this discrepancy is unavoidable, the permanent solution might be closer to the original proposed fix of adjusting the sleep time on the fly with extra wait cycles (I haven't tried this myself yet).

floele commented 2 years ago

@Fenrirthviti Ah, thanks. That is the page I was looking for. I got to this page instead: https://obsproject.com/kb/build-instructions-windows

konsolenritter commented 2 years ago

@floele Thanks! Thats alot of stuff. And i hoped to get around VS... sigh

@bnacar Thanks for your significant investigations regarding the buffer! Regarding your observation of "delayed" audio in audacity: I think its a case of post- and pre-echo due to the typical side effects of windowing functions in lossy encoding like aac.

[UPDATE: The written below is still true. But i've re-read bnacar's post and realized that a different observation was meant: Yes. The audio data lines up around the gap, not being discarded.] grafik In the image above the upper screenshot is from a short dropout (simulated by myself by cutting a -12dB sine) in uncompressed, and below after re-reading in an exported aac version (160kbps) of the above. Lossy compression like in movie audio always shows up such ghosts at sharp signal changes, especially dropouts.

So i'm sure our disaster is not bound to the mux'ing stage, because all encoding happens before. The muxer doesn't break or decode the single streams again (AFAIK). [UPDATE: end of objection]

In short, audio data is being output slightly faster than it gets added to the buffer. If this discrepancy is unavoidable...

Personally i think this is exactly our problem here: rarely buffer-underruns. And the bad news is: such discrepancy can't be avoided. Sleep- or timer-interrupt based threading is bound to the crystals of the board and cpu, while incoming audio (despite observed timing delays at usb stage or so...) is always bound to the crystal of the sound device or even external clocking. A clear sign of this would be that everyone of us experiences such dropouts after differnt runtime with different probability and interspacing of such dropouts. Because everyone of us has different combination of pc/mac and sound-card/-device.

I want definitely to get more into this issue (because i hate it that much) but i've had no time yet to get the whole process of setting up the compilation workflow these days (too much job-based trouble)... sniff

konsolenritter commented 2 years ago

@DJ-3ncoder

I found out that the problem that I am facing occurs at around 1h 7min of stream/recording time. It occurs only once but everytime at the same time!

According to my theory it should happen again around 2h 14min...? ;)

bnacar commented 2 years ago

@konsolenritter sorry for the confusion, I should have included a screenshot: testb10_dropout2

Those ghost artifacts that you were talking about do show up at either end of the dropout, so the glitch in the signal does occur before any compression. The alignment of the waveform before and after the dropout is thus approximate, but consistent.

floele commented 2 years ago

@konsolenritter Thanks for the hint, I have done some further debugging and can confirm that the issue occurs before encoding and muxing.

I have further noticed that the issue seems to occur whenever audio data is written to the puffer using circlebuf_place() instead of the regular push_back(). I'll try to investigate further when and why this happens, but this call seems to be reponsible for putting a NULL-gap into the buffer, which is then subsequently read and causing the issue.

konsolenritter commented 2 years ago

Where have you seen such ...place() calls?

bnacar commented 2 years ago

Also just to clarify wrt the circlebuf_place() calls, are you referring to the "data still pending" dropouts or the more-elusive less-frequent ones?

konsolenritter commented 2 years ago

"Both" of them (for me. Or did you mentioned floele?). I'm still not into the code yet. I proofed (like for a blackbox) what's happening if i tweak the technical (external) sampling rate a bit. Lowering the external 48k (in case of 48k) by 0.1% or 0.4% already brought up the dropouts on a regularly basis, every couple of seconds. It even doesn't need streaming or recording. I can hear it in the monitoring device, already. That points to the generic parts of audio sources ticking and mixing in the general audio thread, too (IMHO). I'm about to upload a vid showing this (possibly today already) to YT.

Sometimes (not in every case) a "data still pending" shows up in between. So i can't distinguish between the two cases yet. Sorry for that. I'm still in the phase of "what needed to produce such dropouts", or, "what-adjusting-screw-belongs-to-the-occurrence/frequentness-of-dropouts"... (leaving the pc/sound-device combo unchanged).

floele commented 2 years ago

In source_output_audio_data() there is a call to source_output_audio_place() which is called under certain circumstances. I'm still not entirely sure what those are. Possibly some timing issue with being more data on the buffer for a moment than expected, so it tries to put the next audio data further to - or rather beyond - the end of the input buffer. Maybe there is someone else who can explain the logic in source_output_audio_data() properly. It compares some timestamps and then possibly doesn't set the variable push_back to true.

So what I have observed is that data is added to the buffer so that there is some empty space in the middle. Like [11111111111111111100000000000000002222222222222] with 1 being the current data on the buffer, 0 the empty space in between and 2 the new data being added to the buffer.

So we have this state in source_output_audio_data() (notice the huge diff being > TS_SMOOTHING_THRESHOLD and thus not making a push_back happening): grafik

And this buffer in source_output_audio_place(), buf_placement being 21692 in this case, so quite a bit beyond the buffer end (while resizing the buffer, the empty space is filled with zeros). grafik

My proposed fix (though without understanding the intentions it might only be a workaround) for that would be to not put any data in the buffer beyond its end, I don't see why the gap would have to be created. Maybe the code in source_output_audio_data() was only created with the intention of overwriting existing data in the buffer and not accidentially create a gap? Or maybe it is to keep in sync to the video? Which wouldn't make sense for me because I don't even record any video for my tests.

The occurrence of the issue is not accompanied by a "data still pending" debug message. However, if you add a #define DEBUG_AUDIO 1 to libobs\obs-source.c you'll get a frames: %lu, size: %lu, placement: %lu, base_ts: %llu, ts: %llu" debug message each time the source_output_audio_place() method is being called, which should correlate to the issue.

I made a commit here: Would be great if someone could verify if that helps. https://github.com/floele/obs-studio/commit/6cde82c088de4b0b5856e597c849b76c1d39a4bc

bnacar commented 2 years ago

@floele I ran a handful of tests ranging between 30 and 70 minutes long.

The good news is that all the dropouts I saw that did not correlate to the "data still pending" message did correlate to the "frames ... size ... placement ..." message, and this second type of dropout reliably occurred for me between 40 and 45 minutes into recording, which is similar to what you were observing, so you definitely have a lead on the two distinct dropout sources.

The bad news is that the effect of the altered source_output_audio_place() was inconclusive. Keep in mind of course multiple confounding factors, different hardware, Windows vs Linux etc...

Out of four occurrences of the "frames ... size ... placement ..." message, two of them were associated with no dropout. I looked very carefully - the waveform in these two cases appeared continuous. Of the remaining two cases, one of them was associated with a dropout, interestingly right after a "data still pending" dropout: waitwhat2 (The second dropout pictured here had a duration _less_than AUDIO_OUTPUT_FRAMES, unlike the "data still pending" ones.)

And the other appearance of the "frames ... size ... placement ..." message was associated with this oddity: waitwhat

Then, just for comparison, I recompiled with the original version of source_output_audio_place() and started recording, and after 45 minutes I hit a "frames ... size ... placement ..." message associated with a waveform similar to the second screenshot.

So yeah... can anyone else give this a try? I hate being the party pooper.

bnacar commented 2 years ago

@konsolenritter re: your observation about timing discrepancies between audio or video sources and the processor itself. If this is in fact the source of some or all of these dropouts, then practically speaking there is no perfect workaround - how do you decide what "true" 48kHz is? Or "true" 30fps for that matter? Is OBS feeding data to YouTube at exactly the rate YouTube is expecting it, or does YouTube just have such a massive buffer that it doesn't matter?

If all we care about is audio continuity, a simple workaround for such timing differences might be to manually specify extra buffer (like as much as a second) at startup, enough to cover the time drift over the course of the entire session.

It gets more complicated when you have multiple audio and video sources that might drift out of sync. For those users to whom strict continuity matters, in addition to a manually specified buffer they would need to be able to define a particular audio or video source as ground truth and lock all other sources to that one, accepting some disruptions in those other sources. For example, gamers are probably going to care more about video continuity and musicians are going to care more about audio continuity.

Ouch.

floele commented 2 years ago

@bnacar Thanks for the tests so far!

Since we might be dealing with different types of/reasons for dropouts, we probably need to carefully distinguish between them for verifying whether a change fixes at least one type of them or not.

The dropout I'm looking for and have been debugging a little more today at seems to depend on the TS_SMOOTHING_THRESHOLD constant, which decides on whether or not a "push back" is being done. Whenever the timestamp difference between source->next_audio_ts_min and in.timestamp is greater than that constant, it was only a very close miss on my system, I got these values with in.timestamp being greater:

70004300 70005600 70004700 70015100 70006700

I'm not sure why it's set to 70000000, seems a bit arbitrary and increasing the value by a bit could also be a solution. You could try that for comparison. It would be interesting to know if the timestamp differences are in the same range on your hardware.

However, the difference being calculated here is an absolute one, so there might also be situations where in.timestamp is smaller and not greater, which could potentially lead to the result of your second screenshot. This would not be fixed by my solution, but if you increase TS_SMOOTHING_THRESHOLD instead, it could also fix that situation (assuming that source_output_audio_place() is being used here to overwrite existing audio data).

In any case, it would be interesting to know how your timestamps are set in source_output_audio_data(), particularly if in.timestamp is way too large or too small.

The "data still pending" related dropout might be fixed by my other fix (not sure if you applied that as well?).

floele commented 2 years ago

I just realized my solution might be a fit flawed here...since I'm only switching to push_back when the buffer is still small, the fix might only work for the first dropout and revert back to the "place" behavior after that. Will verify that in another debug session. So it might actually be smarter increasing the TS_SMOOTHING_THRESHOLD, even if the value is a bit arbitrary.

floele commented 2 years ago

Got more insights today. Actually, even increasing TS_SMOOTHING_THRESHOLD will not help.

The actual root problem is something else. Still in source_output_audio_data(), if everything is "normal", there's a line that sets in.timestamp = source->next_audio_ts_min. In each previous call to that method, next_audio_ts_min is set like this source->next_audio_ts_min = in.timestamp + conv_frames_to_time(sample_rate, in.frames);

So this means that source->next_audio_ts_min will always be the "ideal" expected timestamp, since it's increased by a fixed value in each iteration. However, the incoming audio time stamps will always be a little bit later (higher) than the ideal theoretical values (it doesn't matter whether or not you have enabled "device timestamps" for the audio sources) since it also includes the execution time of the application and doesn't provide continuous values.

This means that the timestamp associated with the incoming audio data will deviate further and further away from the expected timestamp, eventually exceeding TS_SMOOTHING_THRESHOLD, causing an audio issue and then invoking a reset of the timer. This explains the behavior we have seen very well.

To give some actual data, it would look like this (only an extract of a few thousand iterations):

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

New proposed solution: Increase next_audio_ts_min like this: source->next_audio_ts_min = data->timestamp + conv_frames_to_time(sample_rate, in.frames); So we'd be using the unmodified timestamp to calculate the next expected timestamp, avoiding the buildup of "delay".

I'll be testing that a little now...

bnacar commented 2 years ago

OMG I just tested this - changed in.timestamp + conv_frames_to_time(sample_rate, in.frames); to data->timestamp + conv_frames_to_time(sample_rate, in.frames); and ran two separate hour-long tests.

Result: the "frames ... size ... placement ..." message did not occur, and the only dropouts I got were the "data still pending" dropouts!

(Regarding the latter, I had previously tried your other fix with no luck, see my comment upthread)

I'm not sure I completely understood what you did to get those timestamp comparisons - this is what I added right before setting source->last_audio_ts and source->next_audio_ts_min:

#ifdef DEBUG_AUDIO
    blog(LOG_DEBUG, "Perfect timestamp: %" PRIu64 ", "
                    "actual timestamp: %" PRIu64 ", "
                    " diff: %" PRIu64 "",
                    in.timestamp,
                    data->timestamp,
                    data->timestamp - in.timestamp);
#endif

Before altering the source->next_audio_ts_min line, this is what I would see:

debug: Perfect timestamp: 199851195957235, actual timestamp: 199851205733117,  diff: 9775882
debug: Perfect timestamp: 199851196207235, actual timestamp: 199851196961653,  diff: 754418
debug: Perfect timestamp: 199851205269735, actual timestamp: 199851204709421,  diff: 18446744073708991302
debug: ts 199851207628747-199851218295414
debug: audio discarded, new ts: 199851218295414
debug: Perfect timestamp: 199851206644735, actual timestamp: 199851212878274,  diff: 6233539
debug: Perfect timestamp: 199851208957235, actual timestamp: 199851209284523,  diff: 327288
debug: ts 199851218295414-199851228962081
deug: audio discarded, new ts: 199851228962081
debug: Perfect timestamp: 199851214957235, actual timestamp: 199851223846996,  diff: 8889761
debug: Perfect timestamp: 199851215248901, actual timestamp: 199851215568386,  diff: 319485
debug: ts 199851228962081-199851239628747
debug: audio discarded, new ts: 199851239628747
debug: Perfect timestamp: 199851223915567, actual timestamp: 199851233620234,  diff: 9704667
debug: Perfect timestamp: 199851224332233, actual timestamp: 199851225060634,  diff: 728401
debug: Perfect timestamp: 199851233394733, actual timestamp: 199851232872051,  diff: 18446744073709028934
debug: ts 199851239628747-199851250295414
debug: audio discarded, new ts: 199851250295414
debug: Perfect timestamp: 199851234686399, actual timestamp: 199851240897241,  diff: 6210842
debug: Perfect timestamp: 199851237769732, actual timestamp: 199851238503086,  diff: 733354
debug: Perfect timestamp: 199851243373898, actual timestamp: 199851242843501,  diff: 18446744073709021219
debug: ts 199851250295414-199851260962081
debug: audio discarded, new ts: 199851260962081
debug: Perfect timestamp: 199851244665564, actual timestamp: 199851251744927,  diff: 7079363
debug: Perfect timestamp: 199851246748897, actual timestamp: 199851247313393,  diff: 564496
debug: Perfect timestamp: 199851253353063, actual timestamp: 199851252757044,  diff: 18446744073708955597
debug: ts 199851260962081-199851271628747
debug: audio discarded, new ts: 199851271628747
debug: Perfect timestamp: 199851254540563, actual timestamp: 199851262549689,  diff: 8009126
debug: Perfect timestamp: 199851255623896, actual timestamp: 199851256099999,  diff: 476103
debug: Perfect timestamp: 199851263332229, actual timestamp: 199851263814794,  diff: 482565

So sometimes in.timestamp was actually greater than data->timestamp (hence the overflows when I would print the difference) but I didn't see anything that clearly indicated that the difference was monotonically increasing... had you put the debug statement somewhere else?

But the actual results were promising.

floele commented 2 years ago

@bnacar Thanks for testing so far!

Looks like my change works as intended, but I still got “can't discard, data still pending” messages (which causes pretty much the same issues) just like you.

For comparing the two values, I used source->next_audio_ts_min vs. data.timestamp IIRC. If you see some huge values like 18446744073708955597 you probably got an overflow, you might have to use uint64_diff() for calculating the diff.

For fixing both of these issues I made these two changes: https://github.com/floele/obs-studio/commit/a8791e0fda3c5f5914e5fc6e202eb4a20354a4ef https://github.com/floele/obs-studio/commit/dc5faf21787ef9bab9c9a019b6f65d220e747cb9

(You can forget about the modified sleep() method, that doesn't really work after all and it doesn't surprise me.)

I'm not entirely sure about the latter one. It seems to work, but it doesn't feel like an ideal solution so I'll think about it a little more.

If you apply both of these changes to a clean OBS codebase, the audio dropouts should be solved though. Would appreciate some test results :) I've been able to record a flawless 1:20 h recording with these changes so I'm optimistic.

Also as for an explanation of the issue solved by the second commit: It's obviously the case that the buffer is running empty, but that isn't really an "issue" in the sense that something isn't working right. It's just that filling and consuming the buffer is a little irregular. On the one hand, there are different amounts being put into the buffer (in my case 480 frames per iteration = 1920 bytes) and taken out of the buffer (4096 bytes compile time constant). Add to this that the timing is very irregular, meaning the intervals between filling and consuming the buffer changes a lot, it can occasionally happen that the consuming thread is running a little ahead of the filling thread, sometimes only a few bytes. I created a log for this as well: https://file.io/CQLvOHo8s22m At the very end (the first dropout) you can see that by pure chance, consumption is a little faster and by just waiting for another iteration the situation usually normalizes again. So the general approach of not consuming the buffer for a moment should be OK, it doesn't look like there is an underlying problem to solve.

bnacar commented 2 years ago

Latest test recording using those two commits: two straight hours - and no dropouts!!

What I'm wondering is if OBS is actually waiting an occasional extra tick to output what's in the buffer, is that going to cause issues downstream (pun not intended) if I'm streaming rather than recording? I'll test stream a pure sine wave to youtube later tonight.

floele commented 2 years ago

@bnacar Did you do your tests based on v27 of OBS? I upgraded my environment today in preparation of making final versions of the fixes and wasn't able to produce a "data still pending" dropout today, but this might be pure chance since I don't see any changes to the audio processing code.

For this issue, I revised my fix a little and now do this: https://github.com/floele/obs-studio/commit/95e38bff9f1398f21da9bc53f84b8b2912e70d4d

This causes less changes to the overall behaviour of the code and makes more sense in general. This way it's simply making use of the check below which is already present in process_audio_source_tick() but didn't prevent the call to do_audio_output() in input_and_output() before.

if (source->audio_input_buf[0].size < size) {
        source->audio_pending = true;
        pthread_mutex_unlock(&source->audio_buf_mutex);
        return;
}
jp9000 commented 2 years ago

Make a PR once you feel a bit more comfortable with it, I'd like to review it at some point.

floele commented 2 years ago

@DJ-3ncoder @konsolenritter Would either of you be interested in running some tests with a compiled version of OBS that includes these two fixes?

bnacar commented 2 years ago

@floele I was testing based on v27.??, although I was behind by two or three couple weeks. I'll retest this morning.

also THANK YOU for doing this. Even if your pull request doesn't get accepted immediately I'm using this for my next "real" livestream.

bnacar commented 2 years ago

forgot to mention - my youtube test from last Friday had zero dropouts.

floele commented 2 years ago

@bnacar Good to know, thanks! Prepared the PR today, submission will happen soon.

konsolenritter commented 2 years ago

@DJ-3ncoder @konsolenritter Would either of you be interested in running some tests with a compiled version of OBS that includes these two fixes?

Naturally, konjetschno, aber natürlich...! :) Due to the stormy conditions these days i've some trouble with a couple of wind turbines, but i want to test your changes for sure. Cause i'm absolutely interested how your changes make a difference if using external audio interfaces...

DJ-3ncoder commented 2 years ago

Sorry for being inactive but the new semester started and I was very busy organizing things. I also had no time to check if the dropouts occur periodically.

I am using v27.0.0 because I found out that looped videos caused troubles after some time in the last version of OBS but I had no time to investigate. That's why i have to stick with an old version but I would like to test anyway!

I am very interested in the changes and I would be happy if the problem is solved :D

floele commented 2 years ago

@konsolenritter @DJ-3ncoder I have a compiled version based on the latest version of OBS 27.2 (64 bit) here (see https://github.com/floele/obs-studio/tree/fix-audio-v27): (link removed, will provide builds through PR)

You can either use the whole thing or just copy the obs.dll which contains both changes.

RytoEX commented 2 years ago

@floele Could you please submit a PR instead of linking binary downloads? We can enable build artifacts for the PR and users can download from there. We aren't very comfortable with linking binary downloads like this. Thank you for your understanding.

konsolenritter commented 2 years ago

These binaries were just mentioned/provided for DJ-3ncoder and me for testing purposes, not regularly.

PR is in preparation AFAIK. :)

-- K-9 Mail provided by konsolenritter.net

Am 21. Februar 2022 04:00:52 MEZ schrieb Ryan Foster @.>: @. Could you please submit a PR instead of linking binary downloads? We can enable build artifacts for the PR and users can download from there. We aren't very comfortable with linking binary downloads like this. Thank you for your understanding.

-- Reply to this email directly or view it on GitHub: https://github.com/obsproject/obs-studio/issues/4600#issuecomment-1046423426 You are receiving this because you were mentioned.

Message ID: @.***>

dodgepong commented 2 years ago

Generally speaking, we don't recommend sharing random builds of OBS using file sharing sites on official OBS sites/forums, just for the sake of security. Instead, you can submit a PR and have somebody apply the "Seeking Testers" tag, which will create a build from your PR using our CI system, which will help ensure the safety, transparency, and GPL-compliance of whatever binary gets built.

floele commented 2 years ago

Thanks for the suggestion @RytoEX , I feel more comfortable with that option as well. Created a draft PR now: created a draf

bnacar commented 2 years ago

@floele I spoke too soon :/

I just did a "real" stream test, that is, with the camera and mics that I usually use, instead of no video and a pure sine wave from desktop audio. In 49 minutes, there were no dropouts - but the audio and video drifted out of sync and by the end the audio was noticeably ahead of the video, by a quarter of a second or more.

I haven't tried this with an untouched recompile, but this hadn't happened to me previously with the downloadable compiled versions of OBS.

Can anyone else replicate this?

DJ-3ncoder commented 2 years ago

I did a 04:55:34 stream I did not yet check for dropouts but i can confirm that audio drifts out of sync. At the end of my stream the audio was ahead like @bnacar said. My mouth-movement doesn't fit the audio and on the screen of my CDJs at the beginning of the stream the audio was nearly perfectly aligned with the wave on the DJ player and at the end of the stream audio was ahead.

floele commented 2 years ago

Thanks, good to know. I guess I need to find a suitable video source for testing sync.

It would be helpful though if you could determine if only one of these two changes is responsible for going out of sync so I can focus on the change that matters.

floele commented 2 years ago

I was able to do some tests on my own today, as far as I can see, only the second fix (for “can't discard, data still pending”) is causing the video to go out of sync. If I remove the fix, the video is still fine after exceeding TS_SMOOTHING_THRESHOLD 4 times in ~2 h.

bnacar commented 2 years ago

I'm sorry to say that either fix causes the video to go out of sync - for me, anyway. I did a couple 1.5-hour streams, one with each fix separately, and I clapped my hands in front of the camera a few times at the very beginning and the very end. It was a little difficult to tell on playback, but after downloading the streamed videos from youtube and examining them frame by frame, I found they both had a 4-5 frame drift (at 30 fps). I also did one 1-hour stream without either fix (clean recompile) and there was no drift.

I'm kind of scratching my head because as far as I can tell from both the docs and the code, the audio and video threads in OBS are completely independent and don't talk to one another, and the output plugins are only concerned with making sure the two sequences of packets are interleaved monotonically - so how on earth the audio and video stay in sync without your audio fixes eludes me.