Closed Bug 868866 Opened 7 years ago Closed 5 years ago

Intermittent test_delay_load.html | 320x240.ogv:1 is not ready before onload fired (0)

Categories

(Core :: Audio/Video, defect)

ARM
Android
defect
Not set

Tracking

()

RESOLVED FIXED
mozilla38
Tracking Status
firefox36 --- wontfix
firefox37 --- fixed
firefox38 --- fixed
firefox-esr31 --- unaffected
b2g-v2.2 --- fixed
b2g-master --- fixed

People

(Reporter: philor, Assigned: jwwang)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

https://tbpl.mozilla.org/php/getParsedLog.php?id=22615907&tree=Fx-Team
Android Tegra 250 fx-team opt test mochitest-2 on 2013-05-05 14:24:11 PDT for push 34cb9d388cf5
slave: tegra-078

25135 INFO TEST-START | /tests/content/media/test/test_delay_load.html
25136 INFO TEST-PASS | /tests/content/media/test/test_delay_load.html | 320x240.ogv:1 is not ready before onload fired (4)
25137 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_delay_load.html | 320x240.ogv:1 is not ready before onload fired (0)
25138 INFO TEST-PASS | /tests/content/media/test/test_delay_load.html | 320x240.ogv:2 is not ready before onload fired (4)
25139 INFO TEST-PASS | /tests/content/media/test/test_delay_load.html | 320x240.ogv:3 is not ready before onload fired (4)
25140 INFO TEST-PASS | /tests/content/media/test/test_delay_load.html | 320x240.ogv:4 is not ready before onload fired (4)
25141 INFO TEST-END | /tests/content/media/test/test_delay_load.html | finished in 2364ms
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → WORKSFORME
JW, any suggestions for who might be able to look into this recent spike starting a couple days ago? :)
Status: RESOLVED → REOPENED
Flags: needinfo?(jwwang)
Resolution: WORKSFORME → ---
This is a fallout from the patch (https://bug975782.bugzilla.mozilla.org/attachment.cgi?id=8533443) in bug 975782.

Below is the log when problem happened:

01-30 21:19:22.568 I/PRLog   (  590): 2015-01-31 05:19:22.569675 UTC - 2125160[46f3a100]: 55b5e780 ChangeDelayLoadStatus(1) doc=0x0
01-30 21:19:22.568 I/PRLog   (  590): 2015-01-31 05:19:22.570157 UTC - 2125160[46f3a100]: 55b5e780 Network state changed to LOADING
01-30 21:19:22.586 I/PRLog   (  590): 2015-01-31 05:19:22.595340 UTC - 2125160[46f3a100]: 55b5e780 Trying load from src=320x240.ogv?4
4 sec passed exceeding the progress timeout...
01-30 21:19:27.146 I/PRLog   (  590): 2015-01-31 05:19:27.146154 UTC - 2125160[46f3a100]: 55b5e780 ChangeDelayLoadStatus(0) doc=0x540e8800
01-30 21:19:27.577 I/PRLog   (  590): 2015-01-31 05:19:27.579211 UTC - 2125160[46f3a100]: 55b5e780 Created decoder 52cfb480 for type application/ogg
01-30 21:19:27.597 I/PRLog   (  590): 2015-01-31 05:19:27.601321 UTC - 2125160[46f3a100]: 55b5e780 ChangeDelayLoadStatus(1) doc=0x0

It looks like the system was busy enough for the progress timer to time out and stop delaying the load event. Therefore the page load event was fired before loading metadata.

As a quick fix, we stop delaying the load event when downlod stalled on in MSE case. However, I wonder if the progress timer things should ever apply to the MSE case where all media data is fed by the script in a deterministic way. On the other hand, HTTP download is nondeterministic and we need 'progess' and 'stalled' events to notify the page how download is going.
Assignee: nobody → jwwang
Flags: needinfo?(jwwang)
Attachment #8557695 - Flags: review?(cpearce)
Depends on: 975782
Attachment #8557695 - Flags: feedback?(kinetik)
Comment on attachment 8557695 [details] [diff] [review]
868866_fix_delayLoad-v1.patch

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

Karl has touched this code recently, so he may have an opinion on this...
Attachment #8557695 - Flags: feedback?(karlt)
Comment on attachment 8557695 [details] [diff] [review]
868866_fix_delayLoad-v1.patch

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

Doesn't this making this change mean we'll be not implementing the spec correctly?

How about take a different approach; we embed the media in as a data URL in the test file.

That way we can ensure the video is fully downloaded before we start loading it in the media element.

For example, we can run small-shot.ogg, or 320x240.ogv through http://dataurl.net/#dataurlmaker to convert it into a URL that encodes the media to load, and copy/paste that data:video/ogg URL into a variable in the JS in the file, and then set that as the src attribute of the video elements we create in that test.
(In reply to Chris Pearce (:cpearce) from comment #23)
> Doesn't this making this change mean we'll be not implementing the spec
> correctly?
Can you show me what the spec says about it?

> How about take a different approach; we embed the media in as a data URL in
> the test file.
I think that defeat the purpose of test_delay_load.html where we want to test if delaying-the-load-event works as expected. If we set preload to 'metadata', we want to receive page load event after metadata is loaded.
Comment on attachment 8557695 [details] [diff] [review]
868866_fix_delayLoad-v1.patch

(In reply to JW Wang [:jwwang] from comment #12)
> This is a fallout from the patch
> (https://bug975782.bugzilla.mozilla.org/attachment.cgi?id=8533443) in bug
> 975782.

Yes, likely related, but I suspect something else has also changed because
these failures were not reported until one month after bug 975782 landed.

> As a quick fix, we stop delaying the load event when downlod stalled on in
> MSE case.

I don't feel strongly about this, and I don't find the spec clear.

Managing delaying-the-load-event state is a bit difficult if there are
multiple source elements, some MediaSource, and others not.  I think we could
theoretically have a stalled event firing while failing to load a
non-MediaSource source and a subsequent MediaSource source might then continue
to delay the load event indefinitely.  But I don't think we care too much
about that situation.

If it is just to make the test pass, it could instead accept readyState <
HAVE_CURRENT_DATA on elements that have fired the stalled event (and no
subsequent progress events) before the load event.

> However, I wonder if the progress timer things should ever apply
> to the MSE case where all media data is fed by the script in a deterministic
> way.

If the JS driving the MediaSource and the JS handling media element state are
communicating, then progress events are not required.  However, the JS for the
UI may be generic and so would benefit from similar notifications regardless
of whether the source is a MediaSource or not.

Similar behavior in the media element regardless of the kind of source could
also be useful because we can use MediaSource to create deterministic tests of
expected behavior from the media element.

However, there may be a case for different behaviour re stalled and
delaying-the-load-event due to MediaSource not having a timeout like network
requests do.

I'm neither marking f+ nor f- here, just writing down things to consider.
Attachment #8557695 - Flags: feedback?(karlt)
(In reply to JW Wang [:jwwang] from comment #24)
> Can you show me what the spec says about it?

Bug 975782 comment 9 quotes what I could find in the spec.
(In reply to Karl Tomlinson (:karlt) from comment #26)
> Bug 975782 comment 9 quotes what I could find in the spec.

When a user agent decides to completely stall a download, e.g. if it is
waiting until the user starts playback before downloading any further
content, the user agent must queue a task to set the element's
delaying-the-load-event flag to false."

hmm... I think HTTP download doesn't apply to the stalled-by-user-agent case.
(In reply to JW Wang [:jwwang] from comment #24)
> (In reply to Chris Pearce (:cpearce) from comment #23)
> > Doesn't this making this change mean we'll be not implementing the spec
> > correctly?
> Can you show me what the spec says about it?

Mostly I'm thinking of the resource fetch algorithm:
https://html.spec.whatwg.org/multipage/embedded-content.html#concept-media-load-resource

Re-reading it, we should only set the delaying the load event to false "When a user agent decides to completely stall a download", which wouldn't really be the case here; we're not choosing to stall, yet we are stalling.

So I guess resetting the delaying the load event flag in this situation is either poorly defined, or optional.

> > How about take a different approach; we embed the media in as a data URL in
> > the test file.
> I think that defeat the purpose of test_delay_load.html where we want to
> test if delaying-the-load-event works as expected. If we set preload to
> 'metadata', we want to receive page load event after metadata is loaded.

Well, what are we trying to test? We're testing that the delaying-the-load-event flag is reset based on the state of the video element. The state of the video element depends on how much data the network feeds it. I was suggesting we remove the network from the equation, to make the test more reliable.

Also testing how the network feeds data into the video element is a good idea, but we want it to be more reliable.

I'm not really sure what the right solution is here, but if we don't stop delaying the load event here, we should at least make sure we do stop delaying the load event if no more data arrives after a while.

With your patch, if no more data arrives will we ever give up waiting for more data and stop delaying the load event?
(In reply to Chris Pearce (:cpearce) from comment #28)
> With your patch, if no more data arrives will we ever give up waiting for
> more data and stop delaying the load event?

That probably should be handled by HTMLMediaElement::SuspendLoad() where we change network state to IDLE and clear delay-load-event flag. As long as network state is LOADING, the media element should wait for data to come.
(In reply to Chris Pearce (:cpearce) from comment #28)
> Well, what are we trying to test? We're testing that the
> delaying-the-load-event flag is reset based on the state of the video
> element. The state of the video element depends on how much data the network
> feeds it. I was suggesting we remove the network from the equation, to make
> the test more reliable.
> 
> Also testing how the network feeds data into the video element is a good
> idea, but we want it to be more reliable.

I think I would prefer to test the scenario the user is facing mostly where most media data is downloaded from network.
Comment on attachment 8557695 [details] [diff] [review]
868866_fix_delayLoad-v1.patch

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

OK. Provided we otherwise stop delaying the load event, lets run with this.
Attachment #8557695 - Flags: review?(cpearce) → review+
Attachment #8557695 - Flags: feedback?(kinetik)
https://hg.mozilla.org/mozilla-central/rev/22e55c494296
Status: REOPENED → RESOLVED
Closed: 6 years ago5 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla38
Not sure if this is worth taking on beta or not, but for sure request Aurora approval on this if you don't mind :) If you feel it should be on beta too, go for it :)
Flags: needinfo?(jwwang)
Only Aurora is fine.
Flags: needinfo?(jwwang)
(In reply to Ryan VanderMeulen [:RyanVM UTC-5] from comment #40)
> but for sure request Aurora approval on this if you don't mind :)
Flags: needinfo?(jwwang)
Comment on attachment 8557695 [details] [diff] [review]
868866_fix_delayLoad-v1.patch

Approval Request Comment
[Feature/regressing bug #]:bug 975782
[User impact if declined]:page load event might fire before loading metadata which violates the spec.
[Describe test coverage new/current, TreeHerder]:run on Central for about a week.
[Risks and why]: low, the change is simple.
[String/UUID change made/needed]:none
Flags: needinfo?(jwwang)
Attachment #8557695 - Flags: approval-mozilla-aurora?
Comment on attachment 8557695 [details] [diff] [review]
868866_fix_delayLoad-v1.patch

Thanks for fixing an intermittent test failure. Aurora+
Attachment #8557695 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Depends on: 1138557
You need to log in before you can comment on or make changes to this bug.