1208289 - [EME] Log outstanding frames in GMPVideoDecoder DrainComplete() and when ResetComplete() is late

Status: RESOLVED FIXED

(Core :: Audio/Video: MediaStreamGraph, defect, P2)

Description

[Chris Pearce [:cpearce (Not reading bugmail)]]

Adobe are having trouble Drain()ing correctly, so logging the number of frames we have outstanding when DrainComplete() is called would help them.

Also they sometimes don't call ResetComplete(), so adding a timer to detect this would help them too.

Comment 1

[Chris Pearce [:cpearce (Not reading bugmail)]]

Attachment: Patch 1: Add SimpleTimer

This is used in the next patch to detect if the GMP forgets to call GMPVideoDecoderCallback::ResetComplete().

Comment 2

[Chris Pearce [:cpearce (Not reading bugmail)]]

Attachment: Patch 2: Log outstanding frames in Drain() and when ResetComplete isn't called

* Log to browser console the number of outstanding frames when DrainComplete is called.
* Log to browser console if GMPVideoDecoderCallback::ResetComplete() isn't called within 5 seconds of GMPVideoDecoder::Reset() being called.

Comment 3

[JW Wang [:jwwang] [:jw_wang]]

Comment on attachment 8665730 [details] [diff] [review]
Patch 1: Add SimpleTimer

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

::: dom/media/VideoUtils.cpp
@@ +345,5 @@
>  
> +void
> +SimpleTimer::Cancel() {
> +  if (mTimer) {
> +    mTimer->Cancel();

It is not safe to cancel a timer on a thread other than the target thread. Add an assertion to ensure this function is not misused.

@@ +360,5 @@
> +    mTask = nullptr;
> +  }
> +  return NS_OK;
> +}
> +                              

space.

@@ +385,5 @@
> +  rv = timer->InitWithCallback(this, aTimeoutMs, nsITimer::TYPE_ONE_SHOT);
> +  if (NS_FAILED(rv)) {
> +    return rv;
> +  }
> +  rv = timer->SetTarget(aTarget);

This should be done before InitWithCallback in case the timer fires before we change the event target.

Comment 4

[JW Wang [:jwwang] [:jw_wang]]

Comment on attachment 8665734 [details] [diff] [review]
Patch 2: Log outstanding frames in Drain() and when ResetComplete isn't called

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

r+ if my concern is addressed.

::: dom/media/gmp/GMPVideoDecoderParent.cpp
@@ +190,5 @@
> +    self->mResetCompleteTimeout = nullptr;
> +    LogToBrowserConsole(NS_LITERAL_STRING("GMPVideoDecoderParent timed out waiting for ResetComplete()"));
> +  });
> +  CancelResetCompleteTimeout();
> +  mResetCompleteTimeout = SimpleTimer::Create(task, 5000);

SimpleTimer defaults to the main thread. It seems we should specify the GMP thread instead of the main thread.

Comment 5

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/bc6762f52775
https://hg.mozilla.org/integration/mozilla-inbound/rev/28ede868e68c

Comment 6

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/a0f4ddc23411

Comment 7

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/40eb9a8ebfec

Comment 8

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/c1093088302a

Comment 9

[Chris Pearce [:cpearce (Not reading bugmail)]]

Backed out, so don't close bug on merge of bad changesets.

Comment 10

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/ce4c3fe31f57

Comment 11

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/967c555a595c
https://hg.mozilla.org/integration/mozilla-inbound/rev/efcfe0c08c24

Comment 12

[Jean-Yves Avenard [:jya]]

Chris, LogToBrowserConsole is defined in EMEUtils.cpp which isn't being compiled on B2G and others.

I suggest to move it to dom/media/VideoUtils.cpp let me know if you want me to do that.

It's still not best

Comment 13

[Nigel Babu [:nigelb]]

Backed out in

https://hg.mozilla.org/integration/mozilla-inbound/rev/8bf3fa9171a0
https://hg.mozilla.org/integration/mozilla-inbound/rev/0a449a9aa674

Comment 14

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/bc6762f52775
https://hg.mozilla.org/mozilla-central/rev/28ede868e68c
https://hg.mozilla.org/mozilla-central/rev/a0f4ddc23411
https://hg.mozilla.org/mozilla-central/rev/40eb9a8ebfec
https://hg.mozilla.org/mozilla-central/rev/c1093088302a
https://hg.mozilla.org/mozilla-central/rev/ce4c3fe31f57

Comment 15

[Chris Pearce [:cpearce (Not reading bugmail)]]

Backed out, as per comment 13. So reopening.

Comment 16

[Chris Pearce [:cpearce (Not reading bugmail)]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=3791ce8e5d7a

Comment 17

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/25677e506eef
https://hg.mozilla.org/integration/mozilla-inbound/rev/37e7c82c0fc3

Comment 18

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/25677e506eef
https://hg.mozilla.org/mozilla-central/rev/37e7c82c0fc3

Comment 19

[Chris Pearce [:cpearce (Not reading bugmail)]]

Comment on attachment 8665730 [details] [diff] [review]
Patch 1: Add SimpleTimer

Approval Request Comment
[Feature/regressing bug #]: EME
[User impact if declined]: This patch adds Browser Console logging to detect when the Adobe EME plugin is misbehaving. It's a prerequisite for Bug 1209385 which terminates misbehaving EME plugins. So without this patch, we can't land Bug 1209385, which will make Netflix more vulnerable to hung EME plugins.
[Describe test coverage new/current, TreeHerder]: Lots of EME mochitests.
[Risks and why]:  Low
[String/UUID change made/needed]: None.

Comment 20

[Chris Pearce [:cpearce (Not reading bugmail)]]

Comment on attachment 8665734 [details] [diff] [review]
Patch 2: Log outstanding frames in Drain() and when ResetComplete isn't called

Approval Request Comment
[Feature/regressing bug #]: EME
[User impact if declined]: This patch adds Browser Console logging to detect when the Adobe EME plugin is misbehaving. It's a prerequisite for Bug 1209385 which terminates misbehaving EME plugins. So without this patch, we can't land Bug 1209385, which will make Netflix more vulnerable to hung EME plugins.
[Describe test coverage new/current, TreeHerder]: Lots of EME mochitests.
[Risks and why]:  Low
[String/UUID change made/needed]: None.

Comment 21

[Chris Pearce [:cpearce (Not reading bugmail)]]

Aurora Try:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=d96adc84f158

Beta Try:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=3e657c22d317

Rebased patches can be found in these pushes.

Comment 22

[Sylvestre Ledru [:Sylvestre]]

Comment on attachment 8665730 [details] [diff] [review]
Patch 1: Add SimpleTimer

Improvement for EME diagnostics, taking it.

Comment 23

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-beta/rev/6b781dafff21
https://hg.mozilla.org/releases/mozilla-beta/rev/a79d0844eb82

Comment 24

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-beta/rev/6b781dafff21
https://hg.mozilla.org/releases/mozilla-beta/rev/a79d0844eb82

Comment 25

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/7c2733198a53
https://hg.mozilla.org/releases/mozilla-aurora/rev/95baa1b51926