Open Bug 1228226 Opened 4 years ago Updated Last year

clicks with new playing AudioContext

Categories

(Core :: Web Audio, defect, P3)

41 Branch
x86_64
Linux
defect

Tracking

()

ASSIGNED
mozilla52
Tracking Status
firefox52 --- disabled
firefox-esr52 --- disabled
firefox53 --- disabled
firefox54 --- fixed

People

(Reporter: karlt, Assigned: karlt)

References

Details

(Keywords: regression)

Attachments

(3 files, 1 obsolete file)

Attached file linear-fade test (obsolete) —
This testcase should sound like a very soft tap, but there is often a loud click.

Reload to repeated reproduce, though some occurances are more obvious than others.  Closing and reopening the tab reproduces well.
OS: Unspecified → Linux
Hardware: Unspecified → x86_64
Version: unspecified → 41 Branch
Triggered by https://hg.mozilla.org/mozilla-central/rev/3f40bd7da245
Re-opening a closed tab only reproduces when this is within 10 seconds of closing.

With the previous revision, closing tab, minimizing memory usage in about:memory (to close pa output stream), and reopening closed tab within 10 seconds did not reproduce.
Blocks: 1127188
Flags: needinfo?(kinetik)
Note that the graph shows only about the first 1/50th second of the ramp.
The output should have ramped back to zero after 1/5th second.

Reopening a closed tab also demonstrates (though not as obvious as with a reload), in which case closing the stream is not involved.
Assignee: nobody → dminor
This seems to be tied to the GraphDriver being shutdown. It does not reproduce on first load, if another tab using Web Audio is left open while refreshing the test case tab, or as Karl mentioned, if sufficient time is left after closing the tab before reopening.

When it does reproduce, we're hitting this code [1] which starts a ThreadedDriver. If I comment out that block, we do not get any popping and the audio plays normally. I'll investigate further.

[1] https://dxr.mozilla.org/mozilla-central/rev/62f79d676e0e11b3ad59a5425b3ebb3ec5bbefb5/dom/media/GraphDriver.cpp#359
Status: NEW → ASSIGNED
When this reproduces, in the first output buffer after we switch back to the AudioCallbackDriver the buffer starts out with non-zero values. On initial load, the buffer starts out with zero values and ramps up. Maybe part of this plays on the SystemCallbackDriver and we get a pop when we switch to the AudioCallbackDriver because we end up missing the first portion of the output.
(In reply to Dan Minor [:dminor] from comment #10)
> When this reproduces, in the first output buffer after we switch back to the
> AudioCallbackDriver the buffer starts out with non-zero values. On initial
> load, the buffer starts out with zero values and ramps up. Maybe part of
> this plays on the SystemCallbackDriver and we get a pop when we switch to
> the AudioCallbackDriver because we end up missing the first portion of the
> output.

Have we confirmed this theory ? If yes, we have a race where we need to play audio but we haven't got an AudioCallbackDriver yet. Maybe we're switching to an AudioCallbackDriver too late.
Flags: needinfo?(dminor)
(In reply to Paul Adenot (:padenot) from comment #12)
> (In reply to Dan Minor [:dminor] from comment #10)
> > When this reproduces, in the first output buffer after we switch back to the
> > AudioCallbackDriver the buffer starts out with non-zero values. On initial
> > load, the buffer starts out with zero values and ramps up. Maybe part of
> > this plays on the SystemCallbackDriver and we get a pop when we switch to
> > the AudioCallbackDriver because we end up missing the first portion of the
> > output.
> 
> Have we confirmed this theory ? If yes, we have a race where we need to play
> audio but we haven't got an AudioCallbackDriver yet. Maybe we're switching
> to an AudioCallbackDriver too late.

Yes, I inserted printf logging and with the attached testcase I could see the gain values begin to increase while still on the SystemClockDriver. When we switch to the AudioCallbackDriver, the gain node value is around ~0.203 which is the first value I see in the output buffer being filled by the AudioCallbackDriver.

The switching logic seems to require calling OneIteration on the MediaStreamGraph to work properly. The current patch works around this by not allowing the clock to advance when we're switching to the AudioCallbackDriver. It works fine as far as I've been able to test it, but a cleaner solution would be able to switch to the AudioCallbackDriver before we need to play audio.
Flags: needinfo?(dminor)
Comment on attachment 8794941 [details]
Bug 1228226 - Fix clicks with new playing AudioContext;

https://reviewboard.mozilla.org/r/81148/#review81778

This looks correct, but it's all getting too complicated.
Attachment #8794941 - Flags: review?(padenot) → review+
Pushed by dminor@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/2553c3b5ba89
Fix clicks with new playing AudioContext; r=padenot
https://hg.mozilla.org/mozilla-central/rev/2553c3b5ba89
Status: ASSIGNED → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla52
(In reply to Paul Adenot (:padenot) from comment #14)
> Comment on attachment 8794941 [details]
> Bug 1228226 - Fix clicks with new playing AudioContext;
> 
> https://reviewboard.mozilla.org/r/81148/#review81778
> 
> This looks correct, but it's all getting too complicated.

This was not correct: if we'd happen to switch to an AudioClockDriver on the first iteration of a graph, some control messages would not be executed, resulting in a variety of issues. See bug 1329082 for an example.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
I'm probably not the best person to investigate an alternative fix for this.
Assignee: dminor → nobody
Hi Karl, Padenot is pretty swamped at the moment.  Can you take over this bug?
Flags: needinfo?(karlt)
https://hg.mozilla.org/mozilla-central/rev/3ea2d688da6b
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → FIXED
We need to keep this opened.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
This causes a number of issues, like bug 1329082, where we don't swap the
message queues of the MSG where we should, and blows up an assert in debug.

MozReview-Commit-ID: 2I3IjfK8L8r
Assignee: nobody → padenot
Status: REOPENED → ASSIGNED
Comment on attachment 8839540 [details] [diff] [review]
Backed out changeset 2553c3b5ba89

Approval Request Comment
[Feature/Bug causing the regression]: this is a backout for this very bug
[User impact if declined]: "things" not working when using real-time media. This patch ends up dropping arbitrary control messages to the real-time graph, and those messages could be anything (adding a stream, removing a stream, changing a parameter...).
[Is this code covered by automated tests?]: caught by existing asserts in the code, but related (in part) to the time it takes for an audio device to open, hard to write a test in the current state of things.
[Has the fix been verified in Nightly?]: yes, for a while, also on aurora.
[Needs manual test from QE? If yes, steps to reproduce]: bug 1329082 has STR
[List of other uplifts needed for the feature/fix]: none
[Is the change risky?]: the code has not changed much between the landing and the backout
[Why is the change risky/not risky?]: this has baked for a while on aurora and nightly
[String changes made/needed]: none
Attachment #8839540 - Flags: approval-mozilla-beta?
Comment on attachment 8839540 [details] [diff] [review]
Backed out changeset 2553c3b5ba89

backout a change that caused worse issues, beta52+
Attachment #8839540 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
Setting qe-verify- since this fix has automated coverage per Comment 24. I don't see any useful information available in Bug 1329082 in terms of manual testing.

Paul, if you still think this could benefit from manual QA, please provide additional information.
Flags: qe-verify-
We're good for now, thanks.
Mass change P1->P2 to align with new Mozilla triage process
Priority: P1 → P2
Attached file linear fade testcase 2
The original testcase is no longer reproducing, presumably since MSGs are no longer re-used for different windows.

This testcase closes and opens AudioContexts in the same window so as to reproduce even after that change.
Attachment #8692318 - Attachment is obsolete: true
When a new AudioContext causes a graph to be created I assume processing does
not start until the cubeb stream is ready.

When the graph already exists, I assume it continues running while
initializing a cubeb stream.  As indicated in comment 10, this starts
AudioNode processing before the cubeb stream is ready to receive the output.

One possible solution would be to stop the MSG from advancing in time while
the cubeb stream is being initialized.  This was the approach in
https://hg.mozilla.org/mozilla-central/rev/2553c3b5ba89
A disadvantage however is that any other media streams in the graph will also
be stopped, which I assume could cause video to stutter.

A preferable solution I think would be to only pause processing of media
streams in the new AudioContext.  I'll look into whether this can be done by
starting the whole AudioContext in a suspended state and "resuming" once the
cubeb stream is ready.
Assignee: padenot → karlt
Flags: needinfo?(karlt)
Moving to p3 because no activity for at least 1 year(s).
See https://github.com/mozilla/bug-handling/blob/master/policy/triage-bugzilla.md#how-do-you-triage for more information
Priority: P2 → P3
You need to log in before you can comment on or make changes to this bug.