Move more code of AudioSink into the audio thread

RESOLVED FIXED in Firefox 42

Status

()

defect
RESOLVED FIXED
4 years ago
4 years ago

People

(Reporter: jwwang, Assigned: jwwang)

Tracking

unspecified
mozilla42
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox42 fixed)

Details

Attachments

(5 attachments)

After bug 1187763 is landed, we are able to move most of the code into the audio thread so it can run without lock held to improve concurrency.
Assignee: nobody → jwwang
Depends on: 1187763
Bug 1187817. Part 1 - Move Set{Volume,PlaybackRate,PreservesPitch} to the audio thread.
Attachment #8639773 - Flags: review?(kinetik)
Bug 1187817. Part 2 - remove unused code.
Attachment #8639774 - Flags: review?(kinetik)
Bug 1187817. Part 3 - move SetPlaying to the audio thread.
Attachment #8639775 - Flags: review?(kinetik)
Bug 1187817. Part 4 - move some code in Shutdown to the audio thread.
Attachment #8639776 - Flags: review?(kinetik)
Bug 1187817. Part 5 - assert some code in the audio thread and don't enter the monitor.
Attachment #8639777 - Flags: review?(kinetik)
Too bad that we still can't remove the monitor because mAudioStream is accessed from 2 threads...
Comment on attachment 8639773 [details]
MozReview Request: Bug 1187817. Part 1 - Move Set{Volume,PlaybackRate,PreservesPitch} to the audio thread.

https://reviewboard.mozilla.org/r/14235/#review12867

Ship It!
Attachment #8639773 - Flags: review?(kinetik) → review+
Comment on attachment 8639774 [details]
MozReview Request: Bug 1187817. Part 2 - remove unused code.

https://reviewboard.mozilla.org/r/14237/#review12869

Ship It!
Attachment #8639774 - Flags: review?(kinetik) → review+
Attachment #8639775 - Flags: review?(kinetik) → review+
Comment on attachment 8639775 [details]
MozReview Request: Bug 1187817. Part 3 - move SetPlaying to the audio thread.

https://reviewboard.mozilla.org/r/14239/#review12871

Ship It!
Comment on attachment 8639776 [details]
MozReview Request: Bug 1187817. Part 4 - move some code in Shutdown to the audio thread.

https://reviewboard.mozilla.org/r/14241/#review12873

Ship It!
Attachment #8639776 - Flags: review?(kinetik) → review+
Comment on attachment 8639777 [details]
MozReview Request: Bug 1187817. Part 5 - assert some code in the audio thread and don't enter the monitor.

https://reviewboard.mozilla.org/r/14243/#review12875

Ship It!
Attachment #8639777 - Flags: review?(kinetik) → review+
Thanks for the review!
Backed out for making test_mediatrack_consuming_mediaresource.html extremely failure-prone on B2G.
https://treeherder.mozilla.org/logviewer.html#?job_id=12202970&repo=mozilla-inbound
This is interesting. I've been tracking this crash for a long time and haven't found a reliable way to reproduce it. Now we have one.

We have similiar issues here:
https://bugzilla.mozilla.org/show_bug.cgi?id=682385#c23
https://bugzilla.mozilla.org/show_bug.cgi?id=996464#c4
https://bugzilla.mozilla.org/show_bug.cgi?id=1020707#c113
https://bugzilla.mozilla.org/show_bug.cgi?id=1092609#c0

I will file another bug to track this issue.
After adding some logs, the logs suggest that bufferqueue_callback were called from 2 threads and we got SL_RESULT_BUFFER_INSUFFICIENT because the queue was full. How is that possible?

code:
LOG("suro bufferqueue_callback, %p, tid=%p\n", user_ptr, (void*)gettid());

logs:
I(  510:0x262) suro bufferqueue_callback, 0x47a7d780, tid=0x262
I(  510:0x262) suro bufferqueue_callback, 0x47a7d780, tid=0x262
I(  510:0x260) suro bufferqueue_callback, 0x47a7d780, tid=0x260
I(  510:0x260) suro bufferqueue_callback, 0x47a7d780, tid=0x260
Flags: needinfo?(kinetik)
Good question... I don't understand the OpenSL backend as well as the others, so just guessing/poking around in the code here.  I think we need more logging to see what's going on...

It looks like OpenSLES/AudioTrack only use a single thread (AudioTrackThread instance) to call the callback that ultimately ends up in bufferqueue_callback, so where does the other thread come from?  Is it where we call bufferqueue_callback directly in opensl_stream_start to prefill or are we ending up in a state where two AudioTracks are calling back with the same user_ptr?  If it's the former, we should only see a single bufferqueue_callback from opensl_stream_start (unless opensl_stream_stop is called).

It looks like the following sequence may be possible:
1. opensl_stream_start -> calls bufferqueue_callback and Enqueues buffers
2. Play long enough that at least one buffer becomes free -> OpenSL calls bufferqueue_callback
3. We call opensl_stream_stop for some reason, which sets SL_PLAYSTATE_PAUSED
   (it appears this could happen while the callback is running on the other (AudioTrackThread) thread)
4. We call opensl_stream_start -> calls bufferqueue_callback to prefill

Where the bufferqueue_callback in step 2 is running while steps 3 and 4 run on the other thread.  Since the code appears to be written assuming bufferqueue_callback runs on a single thread at a time, it's possible both threads get a value from GetState that causes them to refill multiple buffers, thus hitting the Enqueue error SL_RESULT_BUFFER_INSUFFICIENT because the two threads are effectively trying to Enqueue more than NBUFS buffers.
Flags: needinfo?(kinetik)
Thanks for the reply. I will add more logs to investigate the connection between opensl_stream_{start,stop} and the buffer callback.
Hi kinetik,
You are right. The blame goes to bufferqueue_callback() is called in opensl_stream_start(). I wonder if it is really needed though it was already there in the 1st version of cubeb_opensl.c.

https://hg.mozilla.org/mozilla-central/diff/8eee25223a3e/media/libcubeb/src/cubeb_opensl.c#l1.269

I wonder if we can remove it because we will be able to remove most locks in bufferqueue_callback() for those variables will be only accessed in the buffer callback thread.
Flags: needinfo?(kinetik)
(In reply to JW Wang [:jwwang] from comment #22)
> Hi kinetik,
> You are right. The blame goes to bufferqueue_callback() is called in
> opensl_stream_start(). I wonder if it is really needed though it was already
> there in the 1st version of cubeb_opensl.c.

We must enqueue buffers for initial playback.  If there are none enqueued and we start playback, OpenSL will be in a playing-but-waiting-for-buffers state, i.e. the bufferqueue_callback is only called after a previously enqueued buffer becomes free.

We could check if any buffers are already queued, and only prefill from opensl_stream_start if there are none already queued.  We'd need to verify that it's not possible to have a situation where there are 0 buffers queued but the other thread is calling bufferqueue_callback to refill, though, otherwise we'd just be making the bug rarer rather than fixing it.

Curiously, GStreamer's openslringqueue.c pause/play/prefill works in a similar way to libcubeb (except they changed to enqueue only a single buffer when starting/resuming from pause, but for efficient reasons rather than to fix a bug).  c.f. http://cgit.freedesktop.org/gstreamer/gst-plugins-bad/tree/sys/opensles/openslesringbuffer.c

(Unrelated: that also led me to http://cgit.freedesktop.org/gstreamer/gst-plugins-bad/commit/sys/opensles/openslesringbuffer.c?id=c842df1c3dd8bb76d139b9808dc4ed00a53eb62e which we might need a similar hack to solve)

I think we either need to introduce synchronization in bufferqueue_callback or find a way to wait for OpenSL to reach the stable pause state after pausing.  Scanning the OpenSL ES API, I don't see a way to do the latter...

A slightly hackish way to solve this might be to enqueue a single sample of silence when starting/resuming, but that would cause a small glitch when resuming with a partially full buffer queue.
Flags: needinfo?(kinetik)
Forgot to add:

We could also use PLAYSTATE_STOPPED instead of PLAYSTATE_PAUSED.  That would allow us to unregister the callback, which should guarantee that it's not running when we go to start playback again.  But PLAYSTATE_STOPPED resets the playback position within the current buffer, so we'd need to save and restore that when resuming.
Depends on: 1189197
re-land. Bug 1189197 should fix the crash.
You need to log in before you can comment on or make changes to this bug.