899135 - Blocking the main thread delays mess up ScriptProcessorNode output

Status: RESOLVED FIXED

(Core :: Web Audio, defect)

Description

[(no longer active)]

Attachment: Testcase

testcase provided by Marcus Geelnard

Comment 1

[Paul Adenot (:padenot)]

Yeah, we seem to keep some buffering somewhere that delays the output of the node for ever. I'll poke at it tomorrow.

Comment 2

[(no longer active)]

(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.

Comment 3

[Paul Adenot (:padenot)]

Attachment: Drop buffers instead of buffering them when the main thread is blocked. r=

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.

Comment 4

[(no longer active)]

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?

Comment 5

[Paul Adenot (:padenot)]

Attachment: Drop buffers instead of buffering them when the main thread is blocked. r=

Now with qref.

Comment 6

[(no longer active)]

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?

Comment 7

[Paul Adenot (:padenot)]

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|.

Comment 8

[(no longer active)]

(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!

Comment 9

[Paul Adenot (:padenot)]

Sure, I'll add a comment block explaining the strategy and tradeoff we make here.

Comment 10

[Robert O'Callahan (:roc) (email my personal email if necessary)]

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().

Comment 11

[Paul Adenot (:padenot)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/21e600809600

Comment 12

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/21e600809600

Comment 13

[Paul Adenot (:padenot)]

https://hg.mozilla.org/releases/mozilla-aurora/rev/b9736f48819a

Comment 14

[Manuela Muntean [Away]]

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.

Comment 15

[Cornel Ionce [:noni]]

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?

Comment 16

[Paul Adenot (:padenot)]

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).

Comment 17

[Karl Tomlinson (:karlt)]

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.

Comment 18

[Karl Tomlinson (:karlt)]

Bug 932621 covers something similar to comment 15.

Comment 19

[Catalin Varga [QA][:VarCat]]

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.