Closed Bug 1139795 Opened 5 years ago Closed 3 years ago

Intermittent TEST-UNEXPECTED-PASS | /html/dom/dynamic-markup-insertion/opening-the-input-stream/010.html | Salvagability of document.opened document - expected FAIL

Categories

(Core :: DOM: Core & HTML, defect, P3)

x86
Linux
defect

Tracking

()

RESOLVED FIXED
mozilla55
Tracking Status
firefox-esr52 --- fixed
firefox54 --- fixed
firefox55 --- fixed

People

(Reporter: cbook, Assigned: jmaher)

References

()

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell disabled])

Attachments

(1 file)

Ubuntu VM 12.04 mozilla-inbound opt test web-platform-tests-2

https://treeherder.mozilla.org/logviewer.html#?job_id=7231980&repo=mozilla-inbound

20:29:14 INFO - TEST-UNEXPECTED-PASS | /html/dom/dynamic-markup-insertion/opening-the-input-stream/010.html | Salvagability of document.opened document - expected FAIL
[Mass Closure] Closing Intermittent as a one off
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → WORKSFORME
Status: RESOLVED → REOPENED
Resolution: WORKSFORME → ---
Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.
Priority: -- → P3
Summary: Intermittent 010.html | Salvagability of document.opened document - expected FAIL → Intermittent TEST-UNEXPECTED-PASS | /html/dom/dynamic-markup-insertion/opening-the-input-stream/010.html | Salvagability of document.opened document - expected FAIL
Duplicate of this bug: 1292567
looking at the failures in the last 2 days, this is something that is high frequency.  This started on march 7th, doing some retriggers to find the root cause:
https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&filter-searchStr=web-platform%20osx%20debug&tochange=ea6e77985629c598335d142b6511b1361df290d9&fromchange=c10963d3a6872149f753738c265ef56b4394dda0&selectedJob=82229320

data from the raw log:
14:46:36     INFO - TEST-START | /html/dom/dynamic-markup-insertion/opening-the-input-stream/010.html
14:46:37     INFO - PROCESS | 1650 | [Child 1654] WARNING: NS_ENSURE_TRUE(mState == WCC_ONWRITE) failed: file /home/worker/workspace/build/src/netwerk/protocol/wyciwyg/WyciwygChannelChild.cpp, line 718
14:46:37     INFO - PROCESS | 1650 | ++DOCSHELL 0x11b0a1800 == 13 [pid = 1654] [id = {daf301fd-8247-1844-88ca-e7566329fd1a}]
14:46:37     INFO - PROCESS | 1650 | ++DOMWINDOW == 74 (0x11b045000) [pid = 1654] [serial = 783] [outer = 0x0]
14:46:37     INFO - PROCESS | 1650 | [Parent 1650] WARNING: NS_ENSURE_TRUE(standardURL) failed: file /home/worker/workspace/build/src/caps/nsPrincipal.cpp, line 229
14:46:37     INFO - PROCESS | 1650 | [Child 1654] WARNING: NS_ENSURE_TRUE(standardURL) failed: file /home/worker/workspace/build/src/caps/nsPrincipal.cpp, line 229
14:46:37     INFO - PROCESS | 1650 | ++DOMWINDOW == 75 (0x11b30e400) [pid = 1654] [serial = 784] [outer = 0x11b045000]
14:46:37     INFO - PROCESS | 1650 | [Child 1654] WARNING: NS_ENSURE_TRUE(standardURL) failed: file /home/worker/workspace/build/src/caps/nsPrincipal.cpp, line 229
14:46:37     INFO - PROCESS | 1650 | [Child 1654] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /home/worker/workspace/build/src/extensions/cookie/nsPermissionManager.cpp, line 107
14:46:37     INFO - PROCESS | 1650 | [Child 1654] WARNING: 'NS_FAILED(aResult)', file /home/worker/workspace/build/src/extensions/cookie/nsPermissionManager.cpp, line 614
14:46:37     INFO - PROCESS | 1650 | [Child 1654] WARNING: NS_ENSURE_TRUE(standardURL) failed: file /home/worker/workspace/build/src/caps/nsPrincipal.cpp, line 229
14:46:37     INFO - PROCESS | 1650 | [Child 1654] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /home/worker/workspace/build/src/extensions/cookie/nsPermissionManager.cpp, line 107
14:46:37     INFO - PROCESS | 1650 | [Child 1654] WARNING: 'NS_FAILED(aResult)', file /home/worker/workspace/build/src/extensions/cookie/nsPermissionManager.cpp, line 614
14:46:37     INFO - PROCESS | 1650 | [Child 1654] WARNING: NS_ENSURE_TRUE(standardURL) failed: file /home/worker/workspace/build/src/caps/nsPrincipal.cpp, line 229
14:46:37     INFO - PROCESS | 1650 | [Child 1654] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /home/worker/workspace/build/src/extensions/cookie/nsPermissionManager.cpp, line 107
14:46:37     INFO - PROCESS | 1650 | [Child 1654] WARNING: 'NS_FAILED(aResult)', file /home/worker/workspace/build/src/extensions/cookie/nsPermissionManager.cpp, line 614
14:46:37     INFO - PROCESS | 1650 | ++DOMWINDOW == 76 (0x11b3ca800) [pid = 1654] [serial = 785] [outer = 0x11b045000]
14:46:37     INFO - PROCESS | 1650 | ++DOCSHELL 0x11b26b800 == 14 [pid = 1654] [id = {af40a468-5990-874c-83ab-fbbe3abb7268}]
14:46:37     INFO - PROCESS | 1650 | ++DOMWINDOW == 77 (0x11b3d1000) [pid = 1654] [serial = 786] [outer = 0x0]
14:46:37     INFO - PROCESS | 1650 | ++DOMWINDOW == 78 (0x11b3d7c00) [pid = 1654] [serial = 787] [outer = 0x11b3d1000]
14:46:37     INFO - PROCESS | 1650 | ++DOMWINDOW == 79 (0x11b3cd800) [pid = 1654] [serial = 788] [outer = 0x11b3d1000]
14:46:37     INFO - PROCESS | 1650 | [Child 1654] WARNING: NS_ENSURE_TRUE(mState == WCC_ONWRITE) failed: file /home/worker/workspace/build/src/netwerk/protocol/wyciwyg/WyciwygChannelChild.cpp, line 718
14:46:38     INFO - PROCESS | 1650 | ++DOMWINDOW == 80 (0x11bdd9c00) [pid = 1654] [serial = 789] [outer = 0x11b3d1000]
14:46:38     INFO - 
14:46:38     INFO - TEST-UNEXPECTED-PASS | /html/dom/dynamic-markup-insertion/opening-the-input-stream/010.html | Salvagability of document.opened document - expected FAIL
14:46:38     INFO - TEST-INFO | expected FAIL
14:46:38     INFO - TEST-OK | /html/dom/dynamic-markup-insertion/opening-the-input-stream/010.html | took 1371ms
Flags: needinfo?(jmaher)
Flags: needinfo?(jmaher)
Whiteboard: [stockwell needswork]
still need my ni, jobs are taking a while to run due to backlog.
Flags: needinfo?(jmaher)
and data is in, we are seeing 1 failure every 20 jobs run:
https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&filter-searchStr=web-platform-tests-e10s-2%20osx%20debug&tochange=ea6e77985629c598335d142b6511b1361df290d9&fromchange=c10963d3a6872149f753738c265ef56b4394dda0&selectedJob=83746359

(doing a few more retriggers to validate what it looks like with 40 data points)

this looks like bug 1333799 is the culprit, :gabor, I see you are the patch author, can you take a look at this?
Blocks: 1333799
Flags: needinfo?(jmaher) → needinfo?(gkrizsanits)
(In reply to Joel Maher ( :jmaher) from comment #88)
> and data is in, we are seeing 1 failure every 20 jobs run:
> https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&filter-
> searchStr=web-platform-tests-e10s-
> 2%20osx%20debug&tochange=ea6e77985629c598335d142b6511b1361df290d9&fromchange=
> c10963d3a6872149f753738c265ef56b4394dda0&selectedJob=83746359
> 
> (doing a few more retriggers to validate what it looks like with 40 data
> points)
> 
> this looks like bug 1333799 is the culprit, :gabor, I see you are the patch
> author, can you take a look at this?

I must be missing something. But your push before mine already has 2 failures without my patch ( Tue Mar 7, 19:16:36 - jmaher@mozilla.com ), and I don't see any failures on aurora despite the fact that my patch was uplifted.
Flags: needinfo?(gkrizsanits)
yo uare right, thanks for pointing that out.  My extra retriggers yielded many more instances of this.  I think finding a root cause will be tough, I have done a few more retriggers, but possibly we just need to look into fixing the test case.

:overholt, I see you are the triage owner for this component, can you help find someone to look into this?
Flags: needinfo?(overholt)
and more retriggers and I see this as related to bug 1335751, I know there are a small number of regressions related to bug 1335751 and some work is being done to reduce these for Android, this is a case of windows 8-debug, possibly we need to adjust some timing in the test, or reduce the gc work?
Blocks: 1335751
No longer blocks: 1333799
If I'm reading this test correctly, it seems like it races two setTimeouts against each other (one at 500ms and the other at 1000ms). It then navigates the page with the 500ms iframe to a page that immediately goes back, which should cause the original setTimeout to fire. If loading the page (010-2.html) and going back take longer than one second, which seems very likely in our automation, then this test will fail whether or not we do the right thing. I think we should disable the test until we find a way to rewrite it that doesn't involve racing like this.
thanks for the analysis :mrbkap.  I will get a patch to disable this test.
Attached patch disable the testSplinter Review
:jgraham, can you do the review here.  I also see the history of this test has 1 author:
https://github.com/w3c/web-platform-tests/blob/56ea52b8668ceee63ec196c59dd11ad7797e4f0d/html/dom/dynamic-markup-insertion/opening-the-input-stream/010.html

Should I open an issue on github and ask @deniak to remove the timing issues from the test?
Assignee: nobody → jmaher
Attachment #8848172 - Flags: review?(james)
Comment on attachment 8848172 [details] [diff] [review]
disable the test

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

Disappointing, but I guess this could be non-trivial to fix.
Attachment #8848172 - Flags: review?(james) → review+
Pushed by jmaher@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/30ccad1cc93c
disable /html/dom/dynamic-markup-insertion/opening-the-input-stream/010.html due to bad timing. r=jgraham
https://hg.mozilla.org/mozilla-central/rev/30ccad1cc93c
Status: REOPENED → RESOLVED
Closed: 5 years ago3 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla55
Whiteboard: [stockwell needswork] → [stockwell disabled]
Flags: needinfo?(overholt)
Component: DOM → DOM: Core & HTML
You need to log in before you can comment on or make changes to this bug.