Closed Bug 899135 Opened 6 years ago Closed 6 years ago

Blocking the main thread delays mess up ScriptProcessorNode output

Categories

(Core :: Web Audio, defect)

x86
macOS
defect
Not set

Tracking

()

RESOLVED FIXED
mozilla26
Tracking Status
firefox25 --- verified
firefox26 --- verified

People

(Reporter: ehsan, Assigned: padenot)

Details

(Keywords: verifyme)

Attachments

(2 files, 1 obsolete file)

Attached file Testcase
testcase provided by Marcus Geelnard
Yeah, we seem to keep some buffering somewhere that delays the output of the node for ever. I'll poke at it tomorrow.
(In reply to comment #1)
> Yeah, we seem to keep some buffering somewhere that delays the output of the
> node for ever. I'll poke at it tomorrow.

I'm reasonably sure that this is happening because of the blocking time computations happening in the stable state, as the test case is just causing that code to not run for a second.
As discussed last time, this patch checks if too much latency built-up, and
start dropping packets until the latency goes back to a normal value (that is,
around 0.0).

It seems to work fine for the attached test case. Maybe we can discuss about the
value of the MAX_LATENCY_S member. Maybe we could make it a multiple of the
buffer size or something.
Attachment #789683 - Flags: review?(roc)
Comment on attachment 789683 [details] [diff] [review]
Drop buffers instead of buffering them when the main thread is blocked. r=

Review of attachment 789683 [details] [diff] [review]:
-----------------------------------------------------------------

::: content/media/webaudio/ScriptProcessorNode.cpp
@@ +37,5 @@
>  NS_IMPL_ADDREF_INHERITED(ScriptProcessorNode, AudioNode)
>  NS_IMPL_RELEASE_INHERITED(ScriptProcessorNode, AudioNode)
>  
> +// The maximum latency, in seconds, we allow before we start dropping packets.
> +const uint32_t MAX_BUFFERING_LATENCY_S = 0.1;

uint32_t???

@@ +92,5 @@
>      BufferList mBufferList;
>    };
>  
>  public:
> +  SharedBuffers(float aSampleRate)

Nit: explicit.

@@ +114,5 @@
> +      mLatency += latency - aBufferSize / mSampleRate;
> +      mLastEventTime = now;
> +      if (mLatency > MAX_BUFFERING_LATENCY_S) {
> +        return;
> +      }

Shouldn't you reset mLatency when you start dropping frames?
Attachment #789683 - Attachment is obsolete: true
Attachment #789683 - Flags: review?(roc)
Comment on attachment 789693 [details] [diff] [review]
Drop buffers instead of buffering them when the main thread is blocked. r=

Review of attachment 789693 [details] [diff] [review]:
-----------------------------------------------------------------

In this patch, mLatency still seems to only increase.  Am I missing something?
Right after the main thread unblocks and all the events are processed, |(now - mLastEventTime).ToSeconds()| will be very small, and the buffer size is the same, so |(latency - bufferDuration)| is negative, and we go back to a small |mLatency|.
(In reply to comment #7)
> Right after the main thread unblocks and all the events are processed, |(now -
> mLastEventTime).ToSeconds()| will be very small, and the buffer size is the
> same, so |(latency - bufferDuration)| is negative, and we go back to a small
> |mLatency|.

Oh I see.  This is kind of non-obvious though, can you please describe it in a comment before checking this in?  Thanks!
Sure, I'll add a comment block explaining the strategy and tradeoff we make here.
Comment on attachment 789693 [details] [diff] [review]
Drop buffers instead of buffering them when the main thread is blocked. r=

Review of attachment 789693 [details] [diff] [review]:
-----------------------------------------------------------------

Looks great.

::: content/media/webaudio/ScriptProcessorNode.cpp
@@ +21,5 @@
>  namespace dom {
>  
> +// The maximum latency, in seconds, that we can live with before dropping
> +// buffers.
> +const float MAX_LATENCY_S = 0.5;

static const float

@@ +110,5 @@
>  
> +    if (mLastEventTime.IsNull()) {
> +      mLastEventTime = TimeStamp::Now();
> +    } else {
> +      TimeStamp now = TimeStamp::Now();

Move this out of the "else" so we only have one call to Now().
Attachment #789693 - Flags: review?(roc) → review+
https://hg.mozilla.org/mozilla-central/rev/21e600809600
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla26
Whiteboard: [checkin-needed-aurora]
Verified as fixed with latest Aurora (build ID: 20130911004006) on Mac OSX 10.8.4 in 32bit mode.

The testcase behaves the same way, both with Firefox and Chrome.
QA Contact: manuela.muntean
Tested on latest Aurora and latest Nightly (Mac OS X 10.7.5) but after a while hitting on "Click me to make a tone" does not work anymore. Its not that easy to reproduce, it happens randomly so I can`t provide reliable STR. I noticed that if I open a new tab or change focus to another tab/program may trigger this behavior. Sometimes I wait ~5min and hit the block the thread button and then try to make a tone and bum, nothing happens. On Chrome the TC does not work if a new tab is opened after the TC is loaded. Any thoughts/suggestions?
Flags: needinfo?(paul)
Cornel, thanks for the STR, I'm trying to repro on my macbook (I was unsuccessful on my windows 7, although this does not mean it cannot be reproduced on windows).
If (on Linux) I click "block the main thread" and then, while the button is still down, click "make a tone", I see non-zero sineSamples in the web console log, but hear no sound.

Clicking "make a tone" again usually works fine.

But in one case, "make a tone" got stuck permanently failing to produce audible output, but still writing non-zero sineSamples to the console on each click.  Opening the same testcase in a new tab made an audible tone, but still nothing could be heard when returning to the first testcase.
Bug 932621 covers something similar to comment 15.
I verified this bug sing FF beta 26.06 build id 20131118212339 on Mac Os X 10.8.5.
The initial issue does not reproduce anymore, but I manage to reproduce the issue from comment 17. To reproduce this issue I clicked several consecutive times on block the thread button and switched between tabs.
Flags: needinfo?(paul)
You need to log in before you can comment on or make changes to this bug.