Intermittent TEST-UNEXPECTED-TIMEOUT | /encrypted-media/clearkey-mp4-setmediakeys-again-after-resetting-src.html | org.w3.clearkey, setmediakeys again after resetting src - Test timed out

RESOLVED FIXED in Firefox 59

Status

()

Core
Audio/Video: Playback
P5
normal
RESOLVED FIXED
a year ago
2 months ago

People

(Reporter: Treeherder Bug Filer, Assigned: kikuo)

Tracking

({intermittent-failure})

unspecified
mozilla59
intermittent-failure
Points:
---

Firefox Tracking Flags

(firefox58 wontfix, firefox59 fixed)

Details

MozReview Requests

()

Submitter Diff Changes Open Issues Last Updated
Loading...
Error loading review requests:

Attachments

(3 attachments, 4 obsolete attachments)

Updated

a year ago
Component: Audio/Video → Audio/Video: Playback
Priority: -- → P5
Status: NEW → RESOLVED
Last Resolved: 7 months ago
Keywords: bulk-close-intermittents
Resolution: --- → INCOMPLETE

Comment 1

6 months ago
1 failures in 822 pushes (0.001 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* try: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1313449&startday=2017-07-17&endday=2017-07-23&tree=all

Comment 2

5 months ago
1 failures in 949 pushes (0.001 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-central: 1

Platform breakdown:
* linux64-ccov: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1313449&startday=2017-08-14&endday=2017-08-20&tree=all

Comment 3

5 months ago
2 failures in 908 pushes (0.002 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-inbound: 1
* mozilla-beta: 1

Platform breakdown:
* windows10-64: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1313449&startday=2017-08-21&endday=2017-08-27&tree=all

Comment 4

4 months ago
1 failures in 1032 pushes (0.001 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* try: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1313449&startday=2017-09-11&endday=2017-09-17&tree=all

Comment 5

4 months ago
2 failures in 943 pushes (0.002 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 2

Platform breakdown:
* linux64-stylo-disabled: 1
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1313449&startday=2017-09-18&endday=2017-09-24&tree=all

Comment 6

4 months ago
1 failures in 824 pushes (0.001 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-beta: 1

Platform breakdown:
* linux64-stylo-disabled: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1313449&startday=2017-10-02&endday=2017-10-08&tree=all
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

Comment 7

3 months ago
2 failures in 947 pushes (0.002 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 2

Platform breakdown:
* linux64: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1313449&startday=2017-10-09&endday=2017-10-15&tree=all
(Assignee)

Comment 8

3 months ago
Created attachment 8918779 [details]
[Log] MFR::Update early returns when checking MFR::UpdateReceivedNewData after key is usable.

Retried 259 times, gotcha !

Check the log,
sometimes, when MFR has rejected video promise due to waiting for key, it still cannot decode video frames even after the CDM response has been updated.

HTMLMediaElement's ReadyState is forced to HAVE_METADATA due to no video frame.
(Assignee)

Comment 9

3 months ago
In short,

When the key for decrypting/decoding samples is not usable, VideoDataPromise for MDSM may be rejected, and MDSM will then invoke MFR::WaitForData().

Until then when the key is usable, MFR should be no longer waiting for key, but decoderdata.mWaitingPromise won't be resolved because it will always early return in MFR::Update() [1] due to [2]

[1] http://searchfox.org/mozilla-central/rev/a984558fa2bbde6492d3fb918496fc0b0835b2ce/dom/media/MediaFormatReader.cpp#2253
[2] http://searchfox.org/mozilla-central/rev/a984558fa2bbde6492d3fb918496fc0b0835b2ce/dom/media/MediaFormatReader.cpp#1976
(Assignee)

Comment 10

3 months ago
Created attachment 8920054 [details] [diff] [review]
[WIP] CancelWaitingForKey when all keys which are needed by samples are usable.

There seems to be another case (very very hard to reproduce) which may causing timeout.

1) don't know which state MDSM is in.
2) AudioData is decoded.
3) VideoData request is rejected due to waiting-for-key

Somehow MDSM::MaybeReleaseResources() is invoked and both mVideoDataRequest, mAudioDataRequest don't exist and that results to MFR::ReleaseResource() being called. Then a timeout happens.

I'll have a longer test to find out if that really is a case.
(Assignee)

Comment 11

3 months ago
Created attachment 8921795 [details]
MFR calls ReleaseResource due to MDSM's entering DormatState.

It did happen somehow, when the key is usable, MFR stops asking for input.
(Assignee)

Comment 12

3 months ago
Created attachment 8922602 [details]
[WIP] Notify MFR not to wait for key when the waitforkey promise for specific sample is resolved.

This is a better fix to avoid the issue when NonTailDispatching/TailDispatching thread are mix-usded (Bug 1411501).

Now the last issue is somehow,
1) After key is usable and MDSM receives video sample then enters DecodingState from DecodingFirstFrameState, MediaDecoder change its state from LOADING to PAUSED. 
2) Then MDSM will start a timer to enter DormantState.
3) The test fails.
Attachment #8920054 - Attachment is obsolete: true
Attachment #8921795 - Attachment is obsolete: true
(Assignee)

Comment 13

3 months ago
Created attachment 8922604 [details]
[Log] MDSM enters DecodingState from DecodingFirstFrameState, but start a timer for DormantState.

Because MediaDecoder changes its state from LOADING to PAUSED.
(Assignee)

Updated

3 months ago
Attachment #8922604 - Attachment description: MDSM enters DecodingState from DecodingFirstFrameState, but start a timer for DormantState. → [Log] MDSM enters DecodingState from DecodingFirstFrameState, but start a timer for DormantState.
(Assignee)

Updated

3 months ago
Attachment #8918779 - Attachment description: reproduced.log → [Log] MFR::Update early returns when checking MFR::UpdateReceivedNewData after key is usable.
(Assignee)

Comment 14

3 months ago
Created attachment 8923232 [details]
[Log] Document is hidden while minimizing the WPT test browser and that results to a pending play followed by a timeout.

When the WPT browser is minimized, the document is hidden, so even the visibility of MediaElement is VISIBLE, the Play() will be pended by |mAudioChannelWrapper->IsPlaybackBlocked()| [1].

That shall not happen on try. So I'll stop digging here.

[1] http://searchfox.org/mozilla-central/rev/1ebd2eff44617df3b82eea7d2f3ca1b60cc591a0/dom/html/HTMLMediaElement.cpp#4133
Attachment #8922604 - Attachment is obsolete: true
Comment hidden (mozreview-request)
(Assignee)

Updated

3 months ago
Attachment #8922602 - Attachment is obsolete: true
(In reply to Kilik Kuo [:kikuo] from comment #14)
> That shall not happen on try. So I'll stop digging here.
So do you mean there is something wrong to the test runner on Try which shouldn't minimize the browser?
Comment hidden (mozreview-request)
(Assignee)

Comment 18

3 months ago
mozreview-review
Comment on attachment 8923256 [details]
Bug 1313449 - Refactor the condition for resolving the waiting promise.

https://reviewboard.mozilla.org/r/194446/#review199392

By providing information from SamplesWaitingForKey to indicate MFR to wait for key or not, we can simplified the logic in MFR.  Also the early return case mentioned in Comment 9 is avoided .

Though putting NotifyNotToWait() in the resolving function results to an extra event flood, providing additional variable in SamplesWwaitingForKey to indicate is_waiting should help, but seems a bit tricky.
(Assignee)

Updated

3 months ago
Attachment #8923256 - Flags: review?(cpearce)
(Assignee)

Comment 19

3 months ago
(In reply to JW Wang [:jwwang] [:jw_wang] from comment #16)
> (In reply to Kilik Kuo [:kikuo] from comment #14)
> > That shall not happen on try. So I'll stop digging here.
> So do you mean there is something wrong to the test runner on Try which
> shouldn't minimize the browser?

I'm not sure whether the browser window may be minimized or not on Try.
But the WPT window always pop on the top each round when I run it on local and that's annoying. So I need to alt+tab switch to other application or sometimes I minimize it accidentally, and that's how I found this case until I logged out the visibility information.

Comment 20

3 months ago
mozreview-review
Comment on attachment 8923256 [details]
Bug 1313449 - Refactor the condition for resolving the waiting promise.

https://reviewboard.mozilla.org/r/194446/#review199400

::: dom/media/platforms/agnostic/eme/SamplesWaitingForKey.h:36
(Diff revision 2)
>      WaitForKeyPromise;
>  
>    SamplesWaitingForKey(
>      CDMProxy* aProxy,
>      TrackInfo::TrackType aType,
> -    MediaEventProducer<TrackInfo::TrackType>* aOnWaitingForKey);
> +    MediaEventProducer<TrackInfo::TrackType, bool>* aOnWaitingForKey);

just passed by,
If cpearce accepts this change, would you please leave some comment to explain what is this boolean flag being used? How does it work. Thanks.

Comment 21

3 months ago
mozreview-review
Comment on attachment 8923256 [details]
Bug 1313449 - Refactor the condition for resolving the waiting promise.

https://reviewboard.mozilla.org/r/194446/#review199734

I don't understand how the failure happens.

It looks like you're canceling a wait-for-key when a sample is decrypted. Why can't the MediaFormatReader just cancel waiting for key if a sample is output?

::: dom/media/MediaFormatReader.h:783
(Diff revision 2)
>  
>    // Notify if this media is not seekable.
>    MediaEventProducer<void> mOnMediaNotSeekable;
>  
>    // Notify if we are waiting for a decryption key.
> -  MediaEventProducer<TrackInfo::TrackType> mOnTrackWaitingForKey;
> +  MediaEventProducer<TrackInfo::TrackType, bool> mOnTrackWaitingForKey;

I would prefer you used an enum to denote the states that this bool represents, i.e.

enum {
  CancelWaitingForKey,
  WaitForKey
};

::: dom/media/MediaFormatReader.cpp:2564
(Diff revision 2)
>  
>  RefPtr<MediaFormatReader::WaitForDataPromise>
>  MediaFormatReader::WaitForData(MediaData::Type aType)
>  {
>    MOZ_ASSERT(OnTaskQueue());
> +  LOGV("");

Why are you adding empty logging?
(Assignee)

Comment 22

3 months ago
(In reply to Chris Pearce (:cpearce) from comment #21)
> Comment on attachment 8923256 [details]
> Bug 1313449 - Notify MFR not to wait for key when the WaitForKeyPromise is
> resolved.
> 
> https://reviewboard.mozilla.org/r/194446/#review199734
> 
> I don't understand how the failure happens.

In this case, DecoderData::mWaitingForKey should be set to false while calling |DecoderData::CancelWaitingForKey()| here [1] (near the end of |MFR::Update()|), but in fact |MFR::Update()| will early return at here [2]/[3] because

'''
DecoderData::HasWaitingPromise() is true 
(because MFR already rejects the data request and MDSM calls |MFR::WaitForData()|)
DecoderData::IsWaiting() is true 
(DecoderData::mWaitingForKey is true)
'''

[1] http://searchfox.org/mozilla-central/rev/1c4901d060e3953e41088c038b62a0c026c1e1fb/dom/media/MediaFormatReader.cpp#2481
[2] http://searchfox.org/mozilla-central/rev/1c4901d060e3953e41088c038b62a0c026c1e1fb/dom/media/MediaFormatReader.cpp#2255
[3] http://searchfox.org/mozilla-central/rev/1c4901d060e3953e41088c038b62a0c026c1e1fb/dom/media/MediaFormatReader.cpp#1980

> 
> It looks like you're canceling a wait-for-key when a sample is decrypted.
> Why can't the MediaFormatReader just cancel waiting for key if a sample is
> output?
> 

That's an option too, but I don't think it's a good idea for MFR to decide when should cancel waiting for key especially when I found this issue.  There are many conditions to be checked inside an single MFR::Update and the result may be effected by the order.


> ::: dom/media/MediaFormatReader.h:783
> (Diff revision 2)
> >  
> >    // Notify if this media is not seekable.
> >    MediaEventProducer<void> mOnMediaNotSeekable;
> >  
> >    // Notify if we are waiting for a decryption key.
> > -  MediaEventProducer<TrackInfo::TrackType> mOnTrackWaitingForKey;
> > +  MediaEventProducer<TrackInfo::TrackType, bool> mOnTrackWaitingForKey;
> 
> I would prefer you used an enum to denote the states that this bool
> represents, i.e.
> 
> enum {
>   CancelWaitingForKey,
>   WaitForKey
> };
> 

SGTM.

> ::: dom/media/MediaFormatReader.cpp:2564
> (Diff revision 2)
> >  
> >  RefPtr<MediaFormatReader::WaitForDataPromise>
> >  MediaFormatReader::WaitForData(MediaData::Type aType)
> >  {
> >    MOZ_ASSERT(OnTaskQueue());
> > +  LOGV("");
> 
> Why are you adding empty logging?

Without this trace, I cannot notice where this problem is.
And it's not a frequently called function, I think having a log here should be good.
(In reply to Kilik Kuo [:kikuo] from comment #22)
> (In reply to Chris Pearce (:cpearce) from comment #21)
> > Comment on attachment 8923256 [details]
> > Bug 1313449 - Notify MFR not to wait for key when the WaitForKeyPromise is
> > resolved.
> > 
> > https://reviewboard.mozilla.org/r/194446/#review199734
> > 
> > I don't understand how the failure happens.
> 
> In this case, DecoderData::mWaitingForKey should be set to false while
> calling |DecoderData::CancelWaitingForKey()| here [1] (near the end of
> |MFR::Update()|), but in fact |MFR::Update()| will early return at here
> [2]/[3] because
> 
> '''
> DecoderData::HasWaitingPromise() is true 
> (because MFR already rejects the data request and MDSM calls
> |MFR::WaitForData()|)
> DecoderData::IsWaiting() is true 
> (DecoderData::mWaitingForKey is true)
> '''
> 
> [1]
> http://searchfox.org/mozilla-central/rev/
> 1c4901d060e3953e41088c038b62a0c026c1e1fb/dom/media/MediaFormatReader.cpp#2481
> [2]
> http://searchfox.org/mozilla-central/rev/
> 1c4901d060e3953e41088c038b62a0c026c1e1fb/dom/media/MediaFormatReader.cpp#2255
> [3]
> http://searchfox.org/mozilla-central/rev/
> 1c4901d060e3953e41088c038b62a0c026c1e1fb/dom/media/MediaFormatReader.cpp#1980

Thank you for explaining.

I think our this is a limitation of the design of MediaFormatReader::Update(), as it depends on the order in which it updates its state, i.e. bailing out early affects unrelated states.


> That's an option too, but I don't think it's a good idea for MFR to decide
> when should cancel waiting for key especially when I found this issue. 

Indeed, the thing doing the decrypting has more information and responsibility for decryption.

> > ::: dom/media/MediaFormatReader.cpp:2564
> > (Diff revision 2)
> > >  
> > >  RefPtr<MediaFormatReader::WaitForDataPromise>
> > >  MediaFormatReader::WaitForData(MediaData::Type aType)
> > >  {
> > >    MOZ_ASSERT(OnTaskQueue());
> > > +  LOGV("");
> > 
> > Why are you adding empty logging?
> 
> Without this trace, I cannot notice where this problem is.
> And it's not a frequently called function, I think having a log here should
> be good.

Normally I'd use my text editor's search function, or grep, to find logs I'm interested in. Please don't add empty logging, as it's not an approach that will scale; if everyone did this, the logs would be mostly empty lines, and would be harder to read.

Comment 24

3 months ago
mozreview-review
Comment on attachment 8923256 [details]
Bug 1313449 - Refactor the condition for resolving the waiting promise.

https://reviewboard.mozilla.org/r/194446/#review201700

Please address the two review comments, and re-request review. You also need to request review from jya, since this touches MediaFormatReader.
Attachment #8923256 - Flags: review?(cpearce) → review-

Comment 25

3 months ago
2 failures in 857 pushes (0.002 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 2

Platform breakdown:
* linux32-stylo-disabled: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1313449&startday=2017-10-30&endday=2017-11-05&tree=all
Comment hidden (mozreview-request)

Comment 27

3 months ago
mozreview-review
Comment on attachment 8923256 [details]
Bug 1313449 - Refactor the condition for resolving the waiting promise.

https://reviewboard.mozilla.org/r/194446/#review202336

I don't see the point for this change. There's no need to explicitly tell the MFR that it's not longer waiting for key.

So just use the architecture at hand to do what you need:

The MFR will call the MediaDataDecoder when it needs to decode a sample. The MediaDataDecoder will have been created with a reference to the MediaEventProducer via CreateDecoderParams.

It assumes that if a MediaDataDecoder can't decode a sample because it's waiting for a key, then the MediaEventProducer will be notified but the decode promise will *not* be resolved.

If the key is now available, the MediaDataDecoder will now resolve its promise and the MFR will automatically resume decoding.

If you want to cancel this "waitingforkey" then you call MFR::Flush(), and I believe that it shouldn't be up to the MediaDataDecoder to do so. The MDD resolve the DecodePromise or it doesn't. There's no need for yet another mechanism to do the same thing.

If not, please provide the rationale behind this change.

I don't see how this change simplify the logic.

If there's a problem with MFR::Update exiting early because there's another condition (like waiting for data being processed first) as you mentioned, then change that, and just that.
But normally, you shouldn't be able to be in waiting for data mode and waiting for key mode. they are mutually exclusive as the MFR won't attempt to demux a new sample until the MediaDataDecoder has resolved its promise (which it won't because it's waiting for a key)
Attachment #8923256 - Flags: review?(jyavenard) → review-
Comment on attachment 8923256 [details]
Bug 1313449 - Refactor the condition for resolving the waiting promise.

I'm clearing the review request until jya's comments are addressed.
Attachment #8923256 - Flags: review?(cpearce)
(Assignee)

Comment 29

2 months ago
mozreview-review-reply
Comment on attachment 8923256 [details]
Bug 1313449 - Refactor the condition for resolving the waiting promise.

https://reviewboard.mozilla.org/r/194446/#review202336

For me, to simplify the logic means that whoever sends the notification for waiting the key should be the one to send the notification to unblock the state.

MFR is not able to be in waiting for key mode and waiting for data mode at the same time.
What I mean is that MFR is in waitingforkey mode and has a waiting promise.

Anyway, MFR will try to cancel "waitingforkey" if "waitingforkey" is true and there's *no* decode request existing.
The crux here is assuming it's in waitingforkey mode and MDSM has already called MFR::WaitForData which means a waiting promise is existing, then if a call to |NotifyTrackDemuxer| comes right after |NotifyNewOutput|.
The next round, MFR::UpdateReceivedNewData will set decoder.mReceivedNewData to false but the waiting promise still won't be resolved because decoder.IsWaiting() returns ture.

This patch solves this case which is the waiting promise should be resolved by a more comprehensive condition.
And there's no need to modify the MediaEventProducer.
Comment hidden (mozreview-request)

Comment 31

2 months ago
mozreview-review
Comment on attachment 8923256 [details]
Bug 1313449 - Refactor the condition for resolving the waiting promise.

https://reviewboard.mozilla.org/r/194446/#review204044

LGTM, though im not clear on why those chsnges would be necessay

::: commit-message-23d2b:1
(Diff revision 4)
> +Bug 1313449 - Refactor the condition for resolving the waiting promise.

please provide more details:

that should include:
- what was the problem
- what was fixed
- why it fixes it

::: dom/media/MediaFormatReader.h:428
(Diff revision 4)
>      }
> -    bool IsWaiting() const
> +
> +    bool IsWaitingForData() const
> +    {
> +      MOZ_ASSERT(mOwner->OnTaskQueue());
> +      return mWaitingForData &&

why this extra check?

wouldnt that risk, during internal seeking to assume that we are not waiting for data, while we really are?

::: dom/media/MediaFormatReader.h:435
(Diff revision 4)
> +    }
> +
> +    bool IsWaitingForKey() const
>      {
>        MOZ_ASSERT(mOwner->OnTaskQueue());
> -      return mWaitingForData || mWaitingForKey;
> +      return mWaitingForKey && mDecodeRequest.Exists();

seems to me that this entire changeset could have just be equivalent to a single line change:
bool IsWaiting() const
{
  return mWaitingForData || (mWaitingForKey && mDecodeRequest.Ezists());
}
Attachment #8923256 - Flags: review?(jyavenard) → review+
(In reply to Kilik Kuo [:kikuo] from comment #29)
> Comment on attachment 8923256 [details]
> Bug 1313449 - Refactor the condition for resolving the waiting promise.
> 
> https://reviewboard.mozilla.org/r/194446/#review202336
> 
> For me, to simplify the logic means that whoever sends the notification for
> waiting the key should be the one to send the notification to unblock the
> state.
> 
> MFR is not able to be in waiting for key mode and waiting for data mode at
> the same time.


Thats because no demuxing request is initiated while there's a pending decoding request. 

> What I mean is that MFR is in waitingforkey mode and has a waiting promise.
> 
> Anyway, MFR will try to cancel "waitingforkey" if "waitingforkey" is true
> and there's *no* decode request existing.
> The crux here is assuming it's in waitingforkey mode and MDSM has already
> called MFR::WaitForData which means a waiting promise is existing, then if a
> call to |NotifyTrackDemuxer| comes right after |NotifyNewOutput|.what 

What you describe cannot occur. A demux request can not exist while a decoding promise is pending.

> The next round, MFR::UpdateReceivedNewData will set decoder.mReceivedNewData
> to false but the waiting promise still won't be resolved because
> decoder.IsWaiting() returns ture.
Is Waiting() after clearing mWaitingForKey can only return true if the demuxer has rejected the promise with WAITING_FOR_DATA. However this will never happen because the MFR will not initiate a new demuxing request until the decode promise has been rejected. And as mentioned earlier, if you're waiting for key, then the decoding request can't have been resolved. 



> 
> This patch solves this case which is the waiting promise should be resolved
> by a more comprehensive condition.
> And there's no need to modify the MediaEventProducer.

So in all, I r+ your patch because it does make the code a bit more readable, however I don't think you're fixing the issue you think you're fixing. As the cases you now handle can't occur to start with.
(Assignee)

Comment 33

2 months ago
(In reply to Jean-Yves Avenard [:jya] from comment #32)
> (In reply to Kilik Kuo [:kikuo] from comment #29)
> > Comment on attachment 8923256 [details]
> > Bug 1313449 - Refactor the condition for resolving the waiting promise.
> > 
> > https://reviewboard.mozilla.org/r/194446/#review202336
> > 
> > For me, to simplify the logic means that whoever sends the notification for
> > waiting the key should be the one to send the notification to unblock the
> > state.
> > 
> > MFR is not able to be in waiting for key mode and waiting for data mode at
> > the same time.
> 
> 
> Thats because no demuxing request is initiated while there's a pending
> decoding request. 
> 
> > What I mean is that MFR is in waitingforkey mode and has a waiting promise.
> > 
> > Anyway, MFR will try to cancel "waitingforkey" if "waitingforkey" is true
> > and there's *no* decode request existing.
> > The crux here is assuming it's in waitingforkey mode and MDSM has already
> > called MFR::WaitForData which means a waiting promise is existing, then if a
> > call to |NotifyTrackDemuxer| comes right after |NotifyNewOutput|.what 
> 
> What you describe cannot occur. A demux request can not exist while a
> decoding promise is pending.
> 

There's no existing demux request in the case I described. |NotifyTrackDemuxer| is triggered when new data is appended into sourcebuffer, it doesn't matter if there's a demux request or not.

Check the log.
...
"[MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::NotifyTrackDemuxers:"
// new data arrived

"[MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::ScheduleUpdate: SchedulingUpdate(Video)"
"[Main Thread]: D/EME ChromiumCDMProxy::ResolvePromise(pid=6)"
"[MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::ScheduleUpdate: SchedulingUpdate(Audio)"
"[MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::Update: Processing update for Video"
"[MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::Update: Nothing more to do"
"[MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::Update: Processing update for Audio"
"[MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::Update: Update(Audio) ni=0 no=0 in:1 out:1 qs=0 decoding:0 flushing:0 desc:ffmpeg audio decoder
"[MediaPlayback #1]: V/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::Update: No need for additional input (pending:0)"
"[Main Thread]: D/EME MediaKeys[0x7fc346c6e340]::ResolvePromise(6)"
"[MediaPlayback #3]: D/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::NotifyNewOutput: Done processing new Video samples"
// decode request is resolved

"[MediaPlayback #3]: V/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::ScheduleUpdate: SchedulingUpdate(Video)"
"[MediaPlayback #3]: V/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::NotifyTrackDemuxers:"
// new data arrived again, and a scheduled update for video is not executed yet.

"[MediaPlayback #3]: V/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::ScheduleUpdate: SchedulingUpdate(Audio)"
"[MediaPlayback #3]: V/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::Update: Processing update for Video"
"[MediaPlayback #3]: V/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::Update: Nothing more to do"
// IsWaiting() is still true even video decode request has been resolved, that is what I try to fix in this patch.

"[MediaPlayback #3]: V/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::Update: Processing update for Audio"
"[MediaPlayback #3]: V/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::Update: Update(Audio) ni=0 no=0 in:1 out:1 qs=0 decoding:0 flushing:0 desc:ffmpeg audio decoder
"[MediaPlayback #3]: V/MediaFormatReader MediaFormatReader(0x7fc31c4f7000)::Update: No need for additional input (pending:0)"
...timeout


> > The next round, MFR::UpdateReceivedNewData will set decoder.mReceivedNewData
> > to false but the waiting promise still won't be resolved because
> > decoder.IsWaiting() returns ture.
> Is Waiting() after clearing mWaitingForKey can only return true if the
> demuxer has rejected the promise with WAITING_FOR_DATA. However this will
> never happen because the MFR will not initiate a new demuxing request until
> the decode promise has been rejected. And as mentioned earlier, if you're
> waiting for key, then the decoding request can't have been resolved. 
> 
> 
> 
> > 
> > This patch solves this case which is the waiting promise should be resolved
> > by a more comprehensive condition.
> > And there's no need to modify the MediaEventProducer.
> 
> So in all, I r+ your patch because it does make the code a bit more
> readable, however I don't think you're fixing the issue you think you're
> fixing. As the cases you now handle can't occur to start with.
(Assignee)

Comment 34

2 months ago
mozreview-review-reply
Comment on attachment 8923256 [details]
Bug 1313449 - Refactor the condition for resolving the waiting promise.

https://reviewboard.mozilla.org/r/194446/#review204044

> why this extra check?
> 
> wouldnt that risk, during internal seeking to assume that we are not waiting for data, while we really are?

hmm, i realized that the extra check may lead to missing cases.
I'll remove that.

> seems to me that this entire changeset could have just be equivalent to a single line change:
> bool IsWaiting() const
> {
>   return mWaitingForData || (mWaitingForKey && mDecodeRequest.Ezists());
> }

Yes, that's true
And I found that when there's waiting promise in MFR, it is caused by either waitforday or waitforkey.
I think it's more readable to have 2 functions to identify the waiting stauts.
Comment hidden (mozreview-request)
(Assignee)

Updated

2 months ago
Assignee: nobody → kikuo
(In reply to Kilik Kuo [:kikuo] from comment #34)
> And I found that when there's waiting promise in MFR, it is caused by either
> waitforday or waitforkey.
yes

> I think it's more readable to have 2 functions to identify the waiting
> stauts.

I agree.
(In reply to Kilik Kuo [:kikuo] from comment #33)

> 
> There's no existing demux request in the case I described.
> |NotifyTrackDemuxer| is triggered when new data is appended into
> sourcebuffer, it doesn't matter if there's a demux request or not.
> 

but why would it matter that NotifyTrackDemuxer is called or not?
This can't have an effect on the waiting for key behaviour

Especially for MSE, it's a no-op operation once the init promise has been resolved (e.g. the metadata have been read)
https://searchfox.org/mozilla-central/source/dom/media/mediasource/MediaSourceDemuxer.cpp#75

> "[MediaPlayback #3]: V/MediaFormatReader
> MediaFormatReader(0x7fc31c4f7000)::ScheduleUpdate: SchedulingUpdate(Audio)"
> "[MediaPlayback #3]: V/MediaFormatReader
> MediaFormatReader(0x7fc31c4f7000)::Update: Processing update for Video"
> "[MediaPlayback #3]: V/MediaFormatReader
> MediaFormatReader(0x7fc31c4f7000)::Update: Nothing more to do"
> // IsWaiting() is still true even video decode request has been resolved,
> that is what I try to fix in this patch.

oh I see... good find...

so it's just https://searchfox.org/mozilla-central/rev/bab833ebeef6b2202e71f81d225b968283521fd6/dom/media/MediaFormatReader.cpp#2057 we're worrying about.

I would feel more confident if we only touched that part though...
The waiting_for_something logic is rather complicated and it can easily introduce intermittent timeouts that are hard to troubleshoot (particularly with YouTube).

Comment 39

2 months ago
Pushed by kikuo@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/271a6b2de3ad
Refactor the condition for resolving the waiting promise. r=jya
https://hg.mozilla.org/mozilla-central/rev/271a6b2de3ad
Status: REOPENED → RESOLVED
Last Resolved: 7 months ago2 months ago
status-firefox59: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla59
Please request Beta approval on this when you're comfortable doing so.
status-firefox58: --- → affected
Flags: needinfo?(kikuo)
Keywords: bulk-close-intermittents
(Assignee)

Comment 42

2 months ago
Thanks for asking. The reprodce rate is quite low and I also doubt that the use case is common in real world.
I think we could just fix this on 59.
Flags: needinfo?(kikuo)
status-firefox58: affected → wontfix
You need to log in before you can comment on or make changes to this bug.