Closed Bug 608634 Opened 14 years ago Closed 8 years ago

Intermittent test_error_in_video_document.html | Network state - got 2, expected 0 | Error object - didn't expect null, but got it

Categories

(Core :: Audio/Video: Playback, defect, P5)

Product:
Core
Component:
Audio/Video: Playback
Platform:
ARM
Android
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla51
Tracking Flags:
Tracking Status
firefox32 --- disabled
firefox33 --- disabled
firefox51 --- fixed

People

(Reporter: Callek, Assigned: ctai)

References

(Blocks 1 open bug,
URL
)

Details

(Keywords: intermittent-failure)

Attachments

(6 files)

(Dv1) Improve code and checks, somewhat [Checked in: Comment 20]
2.25 KB, patch
cpearce
: review+
Details | Diff | Splinter Review
Disable test [Checked in: Comment 539]
1.37 KB, patch
philor
: review+
emorley
: checkin+
Details | Diff | Splinter Review
608634_fix_test_error_in_video_document_html.patch
3.61 KB, patch
Details | Diff | Splinter Review
Bug 608634 - Fix redundant comments. .
58 bytes, text/x-review-board-request
jwwang
: review+
Details
Bug 608634 - Enable test_error_in_video_document.html in all platform. .
58 bytes, text/x-review-board-request
jwwang
: review+
Details
Bug 608634 - Add the bug number for the todo part.
58 bytes, text/x-review-board-request
jwwang
: review+
Details 
      No description provided.
Depends on: 604067
landed: http://hg.mozilla.org/mozilla-central/rev/fd8cba3a7fd6 to [try] and help diagnose this.
Blocks: 604067, 438871
URL: http://mxr.mozilla.org/mozilla-centra...
Depends on: 565307
No longer depends on: 604067
OS: Windows XP → Linux
Summary: [SeaMonkey] [mochi-1] test_error_in_video_document.html failing → [SeaMonkey] [mochi-1] Intermittent "test_error_in_video_document.html | Must have error set to MEDIA_ERR_DECODE"
Version: unspecified → Trunk
This is unrelated to bug 604067. In this test, we'll attempt to load an invalid Ogg file, so the WebM decoder is not involved.
No longer blocks: 604067
From the debug output I stuck here:

55218 INFO TEST-PASS | /tests/content/media/test/test_error_in_video_document.html | iframe src=http://mochi.test:8888/tests/content/media/test/bogus.ogv
55219 INFO TEST-PASS | /tests/content/media/test/test_error_in_video_document.html | video src=
55220 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_error_in_video_document.html | Must have error set to MEDIA_ERR_DECODE
55221 INFO TEST-END | /tests/content/media/test/test_error_in_video_document.html | finished in 1647ms

cpearce, any ideas what is going on... and where does the "generation" of the <video> element happen in code?  Any clue if SeaMonkey needs to port stuff to support whatever is going on there.
and actually, a passing Firefox run shows:

55361 INFO TEST-PASS | /tests/content/media/test/test_error_in_video_document.html | iframe src=http://mochi.test:8888/tests/content/media/test/bogus.ogv
55362 INFO TEST-PASS | /tests/content/media/test/test_error_in_video_document.html | video src=
55363 INFO TEST-PASS | /tests/content/media/test/test_error_in_video_document.html | Must have error set to MEDIA_ERR_DECODE
55364 INFO TEST-END | /tests/content/media/test/test_error_in_video_document.html | finished in 1804ms


so video.src is empty in BOTH passing and failing, hrm.
(In reply to comment #5)
> From the debug output I stuck here:
> 
> 55218 INFO TEST-PASS |
> /tests/content/media/test/test_error_in_video_document.html | iframe
> src=http://mochi.test:8888/tests/content/media/test/bogus.ogv
> 55219 INFO TEST-PASS |
> /tests/content/media/test/test_error_in_video_document.html | video src=
> 55220 ERROR TEST-UNEXPECTED-FAIL |
> /tests/content/media/test/test_error_in_video_document.html | Must have error
> set to MEDIA_ERR_DECODE
> 55221 INFO TEST-END |
> /tests/content/media/test/test_error_in_video_document.html | finished in
> 1647ms
> 
> cpearce, any ideas what is going on... and where does the "generation" of the
> <video> element happen in code?

We create an nsVideoDocument when we detect that the iframe is loading vidoe content. We create the video element and add it as a child of the document in nsVideoDocument::CreateSyntheticVideoDocument(). Set a break point in nsHTMLMediaElement::InitializeDecoderForChannel() to see the callstack.

> Any clue if SeaMonkey needs to port stuff to
> support whatever is going on there.

I don't know much about the inner workings of content/docshell in either Firefox or SeaMonkey.

I would be interesting to know if v.error is non-null, and what the v.error.code is if v.error is non-null, plus the values of v.readyState and v.networkState.
55222 INFO TEST-PASS | /tests/content/media/test/test_error_in_video_document.html | iframe src=http://mochi.test:8888/tests/content/media/test/bogus.ogv
55223 INFO TEST-PASS | /tests/content/media/test/test_error_in_video_document.html | v.readyState=0
55224 INFO TEST-PASS | /tests/content/media/test/test_error_in_video_document.html | v.networkState=2
55225 INFO TEST-PASS | /tests/content/media/test/test_error_in_video_document.html | v.error is null
55226 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_error_in_video_document.html | Must have error set to MEDIA_ERR_DECODE
55227 INFO TEST-END | /tests/content/media/test/test_error_in_video_document.html | finished in 1661ms
consequently in Firefox, v.networkState=0 and v.error is non-null with v.error.code=3
Is this SeaMonkey only? I got what looks like this failure on m-c try.
(In reply to comment #9)
> consequently in Firefox, v.networkState=0 and v.error is non-null with
> v.error.code=3

This what we expect.

(In reply to comment #10)
> tnikkel%gmail.com
> http://tinderbox.mozilla.org/showlog.cgi?log=MozillaTry/1288839089.1288839894.29462.gz
> Rev3 WINNT 6.1 tryserver opt test mochitests-1/5 on 2010/11/03 19:51:29

(In reply to comment #11)
> Is this SeaMonkey only? I got what looks like this failure on m-c try.

That failure on try/m-c looks like the load didn't get time to decode enough (i.e. anything) to determine that there's an error before the test finished. It's as if we stopped delaying the load event to soon.
(In reply to comment #14)
> Rev3 WINNT 6.1 mozilla-central opt test mochitests-1/5 on 2010/12/10 17:04:58

{
56639 INFO TEST-START | /tests/content/media/test/test_error_in_video_document.html
56640 INFO TEST-PASS | /tests/content/media/test/test_error_in_video_document.html | iframe src=http://mochi.test:8888/tests/content/media/test/bogus.ogv
56641 INFO TEST-PASS | /tests/content/media/test/test_error_in_video_document.html | v.readyState=0
56642 INFO TEST-PASS | /tests/content/media/test/test_error_in_video_document.html | v.networkState=2
56643 INFO TEST-PASS | /tests/content/media/test/test_error_in_video_document.html | v.error is null
56644 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_error_in_video_document.html | Must have error set to MEDIA_ERR_DECODE
56645 INFO TEST-END | /tests/content/media/test/test_error_in_video_document.html | finished in 192ms
}

Same with
http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1292082389.1292084659.17865.gz
Linux comm-central-trunk debug test mochitests-1/5 on 2010/12/11 07:46:29
Severity: normal → major
Component: Testing Infrastructure → Video/Audio
OS: Linux → All
Product: SeaMonkey → Core
QA Contact: testing-infrastructure → video.audio
Summary: [SeaMonkey] [mochi-1] Intermittent "test_error_in_video_document.html | Must have error set to MEDIA_ERR_DECODE" → [mochi-1] Intermittent "test_error_in_video_document.html | Must have error set to MEDIA_ERR_DECODE"
Whiteboard: [orange] → [near perma-orange on Linux SeaMonkey] [orange]
2010-11-01 23:28 -0400
http://hg.mozilla.org/mozilla-central/rev/0c4fb639c49e
Additional debugging info for Bug 608634
Unless the s/setTimeout/SimpleTest.executeSoon/ would fix the near-perma-orange,
I'll do an additional workaround patch for Linux SeaMonkey ftb.
Attachment #497100 - Flags: review?(chris)
Attachment #497100 - Attachment description: chris@pearce.org.nz → (Dv1) Improve code and checks, somewhat
Comment on attachment 497100 [details] [diff] [review]
(Dv1) Improve code and checks, somewhat
[Checked in: Comment 20]

Looks fine. I'd be concerned if changing the setTimeout on check() to use SimpleTest.executeSoon() instead changed the test behaviour.
Attachment #497100 - Flags: review?(chris) → review+
Comment on attachment 497100 [details] [diff] [review]
(Dv1) Improve code and checks, somewhat
[Checked in: Comment 20]

http://hg.mozilla.org/mozilla-central/rev/b9dcbc836bb3
Attachment #497100 - Attachment description: (Dv1) Improve code and checks, somewhat → (Dv1) Improve code and checks, somewhat [Checked in: Comment 20]
(In reply to comment #20)
> http://hg.mozilla.org/mozilla-central/rev/b9dcbc836bb3

As we already knew:
http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1292557672.1292560985.28674.gz
Linux comm-central-trunk debug test mochitests-1/5 on 2010/12/16 19:47:52
{
55807 INFO TEST-START | /tests/content/media/test/test_error_in_video_document.html
55808 INFO TEST-PASS | /tests/content/media/test/test_error_in_video_document.html | iframe src=http://mochi.test:8888/tests/content/media/test/bogus.ogv
55809 INFO TEST-PASS | /tests/content/media/test/test_error_in_video_document.html | Ready state - 0 should equal 0
55810 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_error_in_video_document.html | Network state - got 2, expected 0
55811 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_error_in_video_document.html | Error object - didn't expect null, but got it
55812 INFO TEST-END | /tests/content/media/test/test_error_in_video_document.html | finished in 2424ms
}

***

(In reply to comment #12)
> That failure on try/m-c looks like the load didn't get time to decode enough
> (i.e. anything) to determine that there's an error before the test finished.
> It's as if we stopped delaying the load event to soon.

Should we try to use
http://mxr.mozilla.org/mozilla-central/ident?i=xpcWaitForFinishedFrames
{
    * docshell/test/navigation/NavigationUtils.js
          o line 185 -- function xpcWaitForFinishedFrames(callback, numFrames) { 
}
or anything else?
Summary: [mochi-1] Intermittent "test_error_in_video_document.html | Must have error set to MEDIA_ERR_DECODE" → [mochi-1] Intermittent "test_error_in_video_document.html | Must have error set to MEDIA_ERR_DECODE", now "Network state - got 2, expected 0"
I suspect the landing of http://hg.mozilla.org/mozilla-central/rev/615cffa67cfa in bug 566779 may fix this random orange...
status2.0: ? → ---
Depends on: 566779
(In reply to comment #45)

http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1304986018.1304989157.12680.gz
Linux comm-central-trunk debug test mochitests-1/5 on 2011/05/09 17:06:58  

Ftr, it didn't fix Linux SeaMonkey perma-orange.
Kind of interesting that I hit the crap (well, a small but noticeable amount of crap) out of this on try when I disable test_fullscreen-api.html on WinXP. Guess that could be explained by the way we rarely make it through M1 on WinXP when we try to run test_fullscreen-api.html, though.
Summary: [mochi-1] Intermittent "test_error_in_video_document.html | Must have error set to MEDIA_ERR_DECODE", now "Network state - got 2, expected 0" → [mochi-1] Intermittent "test_error_in_video_document.html | Network state - got 2, expected 0"
(In reply to Chris Pearce (:cpearce) (Mozilla Corporation) from comment #45)
> I suspect the landing of
> http://hg.mozilla.org/mozilla-central/rev/615cffa67cfa in bug 566779 may fix
> this random orange...

It didn't fix Firefox orange either :-(
No longer depends on: 566779
Summary: [mochi-1] Intermittent "test_error_in_video_document.html | Network state - got 2, expected 0" → [mochi-1] Intermittent test_error_in_video_document.html | Network state - got 2, expected 0 | Error object - didn't expect null, but got it
http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1341380160.1341382046.27379.gz
WINNT 5.2 comm-central-trunk debug test mochitests-1/5 on 2012/07/03 22:36:00
s: sea-vm-win32-1
Summary: [mochi-1] Intermittent test_error_in_video_document.html | Network state - got 2, expected 0 | Error object - didn't expect null, but got it → Intermittent test_error_in_video_document.html | Network state - got 2, expected 0 | Error object - didn't expect null, but got it
500 failures later we've apparently learnt nothing other than nobody cares about this test. Enough is enough (particularly when we'll be stuck with this for another year thanks to ESR17).
Attachment #653102 - Flags: review?(philringnalda)
Comment on attachment 653102 [details] [diff] [review]
Disable test
[Checked in: Comment 539]

buh-bye!
Attachment #653102 - Flags: review?(philringnalda) → review+
(In reply to Ed Morley [:edmorley] from comment #535)
> Created attachment 653102 [details] [diff] [review]
> Disable test

https://hg.mozilla.org/integration/mozilla-inbound/rev/7fdb5fa19cf3
Whiteboard: [near perma-orange on Linux SeaMonkey] [orange] → [orange][test disabled][leave open]
Whiteboard: [orange][test disabled][leave open] → [What about comment 21?] [leave open] [test disabled] [orange]
Attachment #653102 - Attachment description: Disable test → Disable test [Checked in: Comment 539]
Whiteboard: [What about comment 21?] [leave open] [test disabled] [orange] → [What about comment 21?] [leave open] [test disabled]
Attachment #653102 - Flags: checkin+
Runs without issue now. Re-enabled.
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Resolution: FIXED → WORKSFORME
I just hit what looks like this bug, on a Try run (based off of up-to-date mozilla-inbound from today):
{
Android 4.0 Panda try opt test mochitest-3 on 2014-06-07 15:08:10 PDT for push d2861378de69
slave: panda-0160
15:23:46     INFO -  995 INFO TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_error_in_video_document.html | Network state - got 2, expected 0
15:23:46     INFO -  996 INFO TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_error_in_video_document.html | Error object - didn't expect null, but got it
}
https://tbpl.mozilla.org/php/getParsedLog.php?id=41297455&tree=Try

Should we reopen?

(Odd that we had no reports for ~1.5 years, and then on the day that this is closed, I hit it [or something very like it]...)
(In reply to Daniel Holbert [:dholbert] from comment #552)
> (Odd that we had no reports for ~1.5 years, and then on the day that this is
> closed, I hit it [or something very like it]...)

Oh, because the test was disabled (and was re-enabled today). Right.

So I guess that means this is still an issue after all, then. Ryan, should we re-disable the test? Or collect more data to see if it's as spammy as it used to be?
Status: RESOLVED → REOPENED
Flags: needinfo?(ryanvm)
Resolution: WORKSFORME → ---
Whiteboard: [What about comment 21?] [leave open] [test disabled] → [What about comment 21?] [leave open]
I'm willing to wait and see. I expect that a few of the tests I re-enabled on Android will hit failures again, but in general, the media tests fail often enough on Android that I'm not convinced it'll have any significant on the overall orange rate (i.e. trading one failure for a different one) :)
Flags: needinfo?(ryanvm)
(In reply to Ryan VanderMeulen [:RyanVM UTC-4][PTO June 19-22] from comment #554)
> I'm willing to wait and see. I expect that a few of the tests I re-enabled
> on Android will hit failures again, but in general, the media tests fail
> often enough on Android that I'm not convinced it'll have any significant on
> the overall orange rate (i.e. trading one failure for a different one) :)

Please re-disable this one Ryan :-)
Flags: needinfo?(ryanvm)
Whiteboard: [What about comment 21?] [leave open]
(In reply to Ryan VanderMeulen [:RyanVM UTC-4][PTO June 19-22] from comment #551)
> Runs without issue now.

This is good news! :-)
Ftr, do we have any idea about what fixed this intermittent failure?


(In reply to Ed Morley [:edmorley UTC+0] from comment #577)
> Please re-disable this one Ryan :-)

Yes, disable this test on "Android 4.0 Panda" only, per (frequent) failures since comment 552.
Or resolve this bug and file a followup Android bug.
Oh well, was worth a shot. Queued up for Aurora too the next time I push there.
https://hg.mozilla.org/integration/mozilla-inbound/rev/c70a41a3fc2b
status-firefox32: --- → affected
status-firefox33: --- → disabled
Flags: needinfo?(ryanvm)
OS: All → Android
Hardware: x86 → ARM
Whiteboard: [test disabled on Android][leave open]
(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #582)
> https://hg.mozilla.org/releases/mozilla-aurora/rev/b1ee18fd4e50

Fwiw, it looks like a second '+' was mistakenly added, isn't it?
{{
 [test_error_in_video_document.html]
++skip-if = toolkit == 'android' # bug 608634
 [test_error_on_404.html]
}}
Status: REOPENED → NEW
Flags: needinfo?(ryanvm)
*sigh* manual rebase fail. Thanks for noticing.
https://hg.mozilla.org/releases/mozilla-aurora/rev/2a6029bf443f
Flags: needinfo?(ryanvm)
Comments 586 to 591 are all on 'Rev4 MacOSX Snow Leopard 10.6 [...] opt test mochitest-1'.
Want to re-disable this test on that platform?
(In reply to Serge Gautherie (:sgautherie) from comment #592)
> Comments 586 to 591 are all on 'Rev4 MacOSX Snow Leopard 10.6 [...] opt test
> mochitest-1'.
> Want to re-disable this test on that platform?

Yes. Disabled on OSX and Windows opt.

https://hg.mozilla.org/integration/mozilla-inbound/rev/4a0693451d28
Whiteboard: [test disabled on Android][leave open] → [test disabled on Android and OSX/Windows opt][leave open]
685953a0 ChangeDelayLoadStatus(1) doc=0x6c742800
685953a0 Created decoder 71cfdaa0 for type video/ogg
685953a0 Network state changed to LOADING
Decoder=71cfdaa0 MediaDecoderStateMachine ctor=68534c00 realtime=0
Decoder=71cfdaa0 ChangeState PAUSED => LOADING
Decoder=71cfdaa0 Change machine state from NONE to DECODING_METADATA
Decoder=71cfdaa0 Decoding Media Headers
Decoder=71cfdaa0 Change machine state from DECODING_METADATA to SHUTDOWN
Decoder=71cfdaa0 NotifyDownloadEnded, status=0
685953a0 Network state changed to IDLE

test failed!!!

Decoder=71cfdaa0 Changed state to SHUTDOWN
Decoder=71cfdaa0 ChangeState LOADING => SHUTDOWN
685953a0 Network state changed to EMPTY
685953a0 ChangeDelayLoadStatus(0) doc=0x6c742800
Decoder=71cfdaa0 SHUTDOWN OK

From the logs it looks like the 'load' is fired on the iframe before ChangeDelayLoadStatus(0) is called on the media element.

Hi roc,
Do you know where is the code about firing 'load' event on an iframe? I would like to check why the media element fails to delay the 'load' event.
Flags: needinfo?(roc)
I'm not super-familiar with the load event code. The 'load' event for the document fires when the set of non-background loads in its loadgroup is empty. Try running the test in the debugger and see where the "load" event fires from.
Flags: needinfo?(roc)
Load gets fired from nsDocumentViewer::LoadComplete, that's a starting point.
Thanks. I will take a look.
The call stack when the media element calls ChangeDelayLoadStatus() for the first time:
#0  nsDocument::BlockOnload
#1  mozilla::dom::HTMLMediaElement::ChangeDelayLoadStatus
#2  mozilla::dom::HTMLMediaElement::LoadWithChannel
#3  mozilla::dom::VideoDocument::CreateSyntheticVideoDocument
#4  mozilla::dom::VideoDocument::StartDocumentLoad

When nsDocument::BlockOnload() is called, mScriptGlobalObject is null and therefore loadGroup->AddRequest() is not called at all.

Hi roc,
Do you think we should only delay the onload event when the media element is bound to the DOM tree? It doesn't make much sense to me to do so when a media element is outside the tree and not visible to the user.

Hi Timothy,
It appears to me that nsDocument::BlockOnload should handle the case where BlockOnload is called before mScriptGlobalObject is ready, and change the blocking count when mScriptGlobalObject is ready later on.
Flags: needinfo?(roc)
Flags: needinfo?(tnikkel)
(In reply to JW Wang [:jwwang] from comment #632)
> When nsDocument::BlockOnload() is called, mScriptGlobalObject is null and
> therefore loadGroup->AddRequest() is not called at all.
> 
> Hi Timothy,
> It appears to me that nsDocument::BlockOnload should handle the case where
> BlockOnload is called before mScriptGlobalObject is ready, and change the
> blocking count when mScriptGlobalObject is ready later on.

smaug might be able to better answer.
Flags: needinfo?(tnikkel) → needinfo?(bugs)
Calling ChangeDelayLoadStatus() in HTMLMediaElement::BindToTree() doesn't work for mScriptGlobalObject is still null at the moment. We need a fix in nsDocument::BlockOnload.
Flags: needinfo?(roc)
Oh, this is synthetic video document.
Looks like VideoDocument has unusual setup. It calls CreateSyntheticVideoDocument in StartDocumentLoad, 
ImageDocument creates the document in SetScriptGlobalObject after we have the global.
Flags: needinfo?(bugs)
Copy the solution from bug 198301 comment 9 to fix the problem described in comment 632.
Assignee: nobody → jwwang
Status: NEW → ASSIGNED
Attachment #8517174 - Flags: review?(bugs)
Attachment #8517174 - Flags: review?(bugs)
Comment on attachment 8517174 [details] [diff] [review]
608634_fix_test_error_in_video_document_html.patch

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

It looks like we can't delay CreateSyntheticVideoDocument() until SetScriptGlobalObject(). I hit come errors about nsIChannel. It looks like the setup of channel and stream listener could not be delayed.
Component: Audio/Video → Audio/Video: Playback
P5
Keywords: leave-open
Priority: -- → P5
Whiteboard: [test disabled on Android and OSX/Windows opt][leave open] → [test disabled on Android and OSX/Windows opt]
See Also: → 1295923
Comment on attachment 8781936 [details]
Bug 608634 - Fix redundant comments. .

https://reviewboard.mozilla.org/r/72254/#review69824
Attachment #8781936 - Flags: review?(jwwang) → review+
Comment on attachment 8781937 [details]
Bug 608634 - Enable test_error_in_video_document.html in all platform. .

https://reviewboard.mozilla.org/r/72256/#review69826
Attachment #8781937 - Flags: review?(jwwang) → review+
Comment on attachment 8781938 [details]
Bug 608634 - Add the bug number for the todo part.

https://reviewboard.mozilla.org/r/72258/#review69828
Attachment #8781938 - Flags: review?(jwwang) → review+
Assignee: jwwang → ctai
Keywords: leave-open
Whiteboard: [test disabled on Android and OSX/Windows opt]
Pushed by ryanvm@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/236306f26299
Fix redundant comments. r=jwwang.
https://hg.mozilla.org/integration/autoland/rev/278312a5a804
Enable test_error_in_video_document.html in all platform. r=jwwang.
https://hg.mozilla.org/integration/autoland/rev/2510a6257d7b
Add the bug number for the todo part. r=jwwang
Keywords: checkin-needed
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: