1683439 - ThreadSanitizer: data race [@ AudioCallbackDriver::MixerCallback] vs. [@ AudioCallbackDriver::Init]

Status: RESOLVED FIXED

(Core :: Web Audio, defect)

Description

[Aria Beingessner [:Gankra]]

Attachment: tsan-backtrace-dec-2020.txt

I noticed that Bug 1638212 "coming back" was actually a different bug altogether. Marked as security because potential dereference of uninit pointer. Filing this new bug to not draw attention to the intermittent.

Racing on writing to mScratchBuffer vs allocating+assigning it.

AudioCallbackDriver::MixerCallback

vs

AudioCallbackDriver::Init

General information about TSan reports

Why fix races?

Data races are undefined behavior and can cause crashes as well as correctness issues. Compiler optimizations can cause racy code to have unpredictable and hard-to-reproduce behavior.

Rating

If you think this race can cause crashes or correctness issues, it would be great to rate the bug appropriately as P1/P2 and/or indicating this in the bug. This makes it a lot easier for us to assess the actual impact that these reports make and if they are helpful to you.

False Positives / Benign Races

Typically, races reported by TSan are not false positives [1], but it is possible that the race is benign. Even in this case it would be nice to come up with a fix if it is easily doable and does not regress performance. Every race that we cannot fix will have to remain on the suppression list and slows down the overall TSan performance. Also note that seemingly benign races can possibly be harmful (also depending on the compiler, optimizations and the architecture) [2][3].

[1] One major exception is the involvement of uninstrumented code from third-party libraries.
[2] http://software.intel.com/en-us/blogs/2013/01/06/benign-data-races-what-could-possibly-go-wrong
[3] How to miscompile programs with "benign" data races: https://www.usenix.org/legacy/events/hotpar11/tech/final_files/Boehm.pdf
Suppressing unfixable races

If the bug cannot be fixed, then a runtime suppression needs to be added in mozglue/build/TsanOptions.cpp. The suppressions match on the full stack, so it should be picked such that it is unique to this particular race. The bug number of this bug should also be included so we have some documentation on why this suppression was added.

Comment 1

[Aria Beingessner [:Gankra]]

Attachment: Bug 1683439 - supress issue found while enabling full tsan shutdown. r?decoder

Depends on D100265

Comment 2

[Karl Tomlinson (:karlt)]

This seems to occur only together with bug 1674039.
I've seen between 1 and 3 occurrences detected in a single run.
It looks like this often happens with toolkit/content/tests/browser/browser_media_wakelock_webaudio.js, but can also happen in other tests such as after browser_delay_autoplay_webAudio.js.

Hypothetically this might happen if AudioCallbackDriver::Init() could be called again somehow while the DataCallback() is running, but I don't see a way that could happen.

FallbackWrapper::OneIteration() is called only with a null mixer.

Comment 3

[Karl Tomlinson (:karlt)]

Alexis, Can we be confident that TSAN analysis across Rust and C++ is now sound?

Part of the synchronization of threads involved here happens out of process. TSAN should be able to see that through write and read system calls to the other process from Rust code. Would the TSAN analysis treat these system calls as synchronization points?

If not, I wonder whether changes for bug 1671691 may have removed suppressions for this situation.

One thing that may be helpful here might be if we could raise SIGABRT to get stack traces from all threads.

Comment 4

[Christian Holler (:decoder)]

(In reply to Karl Tomlinson (:karlt) from comment #3)

Part of the synchronization of threads involved here happens out of process. TSAN should be able to see that through write and read system calls to the other process from Rust code. Would the TSAN analysis treat these system calls as synchronization points?

So you are doing reads and writes and in-between those, there is (out-of-process) synchronization? In this case, TSan considers this synchronized if the read and write happens on the same fd:

io_sync 	(Default: 1) 	Controls level of synchronization implied by IO operations. 0 - no synchronization; 1 - reasonable level of synchronization (write->read on the same fd); 2 - global synchronization of all IO operations.

If you have two syscalls to different file descriptors but there is synchronization between those in another process, then that can currently cause a false positive. We haven't seen this happen yet in Firefox, so far all operations that had external synchronization were on the same fd.

Comment 5

[Karl Tomlinson (:karlt)]

(In reply to Christian Holler (:decoder) from comment #4)

So you are doing reads and writes and in-between those, there is (out-of-process) synchronization?

Thanks, Christian. Yes, my expectation is that, but I'm not familiar with the details.

Matthew, do you know whether audioipc reads and writes on the same fd?
(I would have guessed different pipes for each direction.)

Comment 6

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://hg.mozilla.org/integration/autoland/rev/78ebda5dbac89b8170b75519ab0e77bafe3ad7c7
https://hg.mozilla.org/mozilla-central/rev/78ebda5dbac8

Comment 7

[Matthew Gregan [:kinetik]]

(In reply to Karl Tomlinson (back Feb 2 :karlt) from comment #5)

Matthew, do you know whether audioipc reads and writes on the same fd?
(I would have guessed different pipes for each direction.)

There's one SOCK_STREAM Unix domain socket per cubeb stream which is used to synchronize access to the inter-process shared memory used by AudioIPC's data_callback shim. On waking due to readability of the UDS, the shim will pass the in/out shm to the supplied data_callback for processing. Once data_callback returns, the shim signals the shm access is complete by sending a message via the UDS. Note that the actual read/write syscall and the shm access happen on different threads with some other synchronization via the futures task executor.

There's a second UDS (one per cubeb context) used for cubeb_stream_init processing, but none of that code path accesses the shm regions.

(In reply to Karl Tomlinson (back Feb 2 :karlt) from comment #2)

Hypothetically this might happen if AudioCallbackDriver::Init() could be called again somehow while the DataCallback() is running, but I don't see a way that could happen.

There's may be an ordering issue in AudioIPC where a DataCallback for a previous stream is running after stream destroy, I'll investigate.

Comment 8

[Karl Tomlinson (:karlt)]

(In reply to Matthew Gregan [:kinetik] from comment #7)

There's a second UDS (one per cubeb context) used for cubeb_stream_init processing, but none of that code path accesses the shm regions.

Thanks. That may be something to bear in mind when looking at other TSAN races, but cubeb_stream_init has not yet been called again here.

There's may be an ordering issue in AudioIPC where a DataCallback for a previous stream is running after stream destroy, I'll investigate.

If there is such an ordering issue, then that would lead to this race, yes.

Comment 9

[Matthew Gregan [:kinetik]]

Should be fixed by bug 1690718.

Comment 10

[Aria Beingessner [:Gankra]]

Attachment: Bug 1683439 - Remove suppression for fixed issue. r?kriswright

Comment 11

[Aria Beingessner [:Gankra]]

Not sure how/when to land the supression removal, but it's all ready to go for whenever we're ready

Comment 12

[Matthew Gregan [:kinetik]]

Thanks! Bug 1690718 is on m-c, so I've queued this for landing too.

Comment 13

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Remove suppression for fixed issue. r=KrisWright
https://hg.mozilla.org/integration/autoland/rev/1ae80f5c0d421049b59e3cc32798a1d349056b8c
https://hg.mozilla.org/mozilla-central/rev/1ae80f5c0d42

Can this bug get closed now?

Comment 14

[Matthew Gregan [:kinetik]]

Yes, thank you. Marking resolved.

Comment 15

[Aria Beingessner [:Gankra]]

Is there a plan to uplift this to release? Bug 1638212 is still catching that.

Comment 16

[BugBot [:suhaib / :marco/ :calixte]]

The patch landed in nightly and beta is affected.
:kinetik, is this bug important enough to require an uplift?
If not please set status_beta to wontfix.

For more information, please visit auto_nag documentation.

Comment 17

[Matthew Gregan [:kinetik]]

(In reply to Release mgmt bot [:sylvestre / :calixte / :marco for bugbug] from comment #16)

The patch landed in nightly and beta is affected.
:kinetik, is this bug important enough to require an uplift?

I've requested beta uplift in bug 1690718.

I'm not sure this fix meets the criteria for a release uplift.

Comment 18

[Matthew Gregan [:kinetik]]

beta uplift was denied as it's RC week.