Closed Bug 874073 Opened 11 years ago Closed 11 years ago

Intermittent crashtests/852293.html | load failed: timed out waiting for reftest-wait to be removed followed by others and a 7200 second timeout

Categories

(Core :: General, defect)

Product:
Core
Component:
General
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla26
Tracking Flags:
Tracking Status
firefox24 --- fixed
firefox25 --- fixed
firefox26 --- fixed

People

(Reporter: RyanVM, Assigned: MatsPalmgren_bugz)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure)

Attachments

(5 files)

wip
2.13 KB, patch
Details | Diff | Splinter Review
dump() logging
2.56 KB, patch
Details | Diff | Splinter Review
screenshot
1.01 MB, text/html
Details
Patch to take a screenshot
27.03 KB, patch
Details | Diff | Splinter Review
fix
1.14 KB, patch
RyanVM
: review+
Details | Diff | Splinter Review 
+++ This bug was initially created as a clone of Bug #873083 +++

https://tbpl.mozilla.org/php/getParsedLog.php?id=23149360&tree=Mozilla-Inbound

Rev3 WINNT 6.1 mozilla-inbound pgo test crashtest on 2013-05-20 00:17:07 PDT for push 25a1e66c0f1d
slave: talos-r3-w7-115

00:24:40     INFO -  REFTEST TEST-START | file:///C:/talos-slave/test/build/tests/reftest/tests/layout/base/crashtests/852293.html | 1091 / 2442 (44%)
00:29:40     INFO -  REFTEST TEST-UNEXPECTED-FAIL | file:///C:/talos-slave/test/build/tests/reftest/tests/layout/base/crashtests/852293.html | load failed: timed out waiting for reftest-wait to be removed
00:29:40     INFO -  REFTEST INFO | Saved log: START file:///C:/talos-slave/test/build/tests/reftest/tests/layout/base/crashtests/852293.html
00:29:40     INFO -  REFTEST INFO | Saved log: [CONTENT] OnDocumentLoad triggering WaitForTestEnd
00:29:40     INFO -  REFTEST INFO | Saved log: [CONTENT] WaitForTestEnd: Adding listeners
00:29:40     INFO -  REFTEST INFO | Saved log: Initializing canvas snapshot
00:29:40     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_TO_FIRE_INVALIDATE_EVENT
00:29:40     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: dispatching MozReftestInvalidate
00:29:40     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
00:29:40     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
00:29:40     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///C:/talos-slave/test/build/tests/reftest/tests/layout/base/crashtests/852293.html
00:29:40     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///C:/talos-slave/test/build/tests/reftest/tests/layout/base/crashtests/852293.html
00:29:40     INFO -  REFTEST INFO | Saved log: [CONTENT] AfterPaintListener in file:///C:/talos-slave/test/build/tests/reftest/tests/layout/base/crashtests/852293.html
00:29:40     INFO -  REFTEST INFO | Saved log: [CONTENT] SendUpdateCanvasForEvent with 1 rects
00:29:40     INFO -  REFTEST INFO | Saved log: [CONTENT] Rect: 0 0 800 1000
00:29:40     INFO -  REFTEST INFO | Saved log: Updating canvas for invalidation
00:29:40     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: STATE_WAITING_FOR_REFTEST_WAIT_REMOVAL
00:29:40     INFO -  REFTEST INFO | Saved log: [CONTENT] MakeProgress: waiting for reftest-wait to be removed
00:29:40     INFO -  REFTEST INFO | Loading a blank page
This test does remove/add the documentElement:
  var de = document.documentElement;
  document.removeChild(de);
  document.appendChild(de);

I guess that could be confusing for the reftest framework.

A workaround could be to move this file to 852293-iframe.html
and make a new 852293.html that loads it in an <iframe>.
And move the class="reftest-wait" to the new top file.
(In reply to Mats Palmgren (on vacation) from comment #1)
> This test does remove/add the documentElement:
>   var de = document.documentElement;
>   document.removeChild(de);
>   document.appendChild(de);
> 
> I guess that could be confusing for the reftest framework.
> 
> A workaround could be to move this file to 852293-iframe.html
> and make a new 852293.html that loads it in an <iframe>.
> And move the class="reftest-wait" to the new top file.

Were you going to attempt this? I'm going to be disabling this test in short order soon.
Flags: needinfo?(matspal)
Disabled due to frequent failures.
https://hg.mozilla.org/integration/mozilla-inbound/rev/5764a13f3567
Whiteboard: [test disabled][leave open]
Attached patch wip — — Splinter Review 
I tried the workaround in comment 1:
https://tbpl.mozilla.org/?tree=Try&rev=475a7eab052b

It didn't help. You can ignore the orange runs (they are from the patch
for bug 898913), but there's one red C that has the same error as before.

I'll add some logging to the see what's going on...
Flags: needinfo?(matspal)
Attached patch dump() logging — — Splinter Review 
It failed also with logging:
https://tbpl.mozilla.org/?tree=Try&rev=8470fba22d5d

From the Full log:
https://tbpl.mozilla.org/php/getParsedLog.php?id=26126972&tree=Try&full=1
...
11:54:31     INFO -  REFTEST TEST-LOAD | file:///builds/slave/test/build/tests/reftest/tests/layout/base/crashtests/852293.html | 1133 / 2507 (45%)
11:54:31     INFO -  ++DOMWINDOW == 154 (0x38b62c8) [serial = 2718] [outer = 0x2951968]
11:54:31     INFO -  start
11:54:31     INFO -  start DONE
11:54:33     INFO -  ++DOCSHELL 0x3fe95d0 == 8 [id = 192]
...

There are no debug log messages after that.
With a 10 ms timeout makeChanges() should have been called in the 1-2 second
interval before the "++DOCSHELL" line above, so either
1. we never reached the setTimeout() call for some reason
2. setTimeout() silently failed?
3. the timeout was canceled for some reason (window destroyed?)
4. ?

Looking at the log, it appears the reftest framework logs uncaught JS
exceptions in other tests but I don't see any logged for this test, and
the code in start() is trivial, so I don't see how it can be 1.

I don't see how 3 could have occurred in the 10 ms interval before
the first makeChanges() call.
Here's a Try run that ONLY runs this specific crash test:
https://tbpl.mozilla.org/?tree=Try&rev=8f33537479d2
Each "C" loaded the test 200 times so there's several thousand test runs
in that batch, all of which succeeded.  I don't think there's anything
wrong with this test, it's some earlier test that mess things up somehow.
With some printfs in relevant code:
https://tbpl.mozilla.org/?tree=Try&rev=91b58b22e9e2
we get to nsGlobalWindow::RunTimeout but return early because
"IsInModalState()=1" here:
http://hg.mozilla.org/mozilla-central/annotate/0a63cd911b4f/dom/base/nsGlobalWindow.cpp#l10389
and I suspect we never get out of that modal state before the framework
decides to kill us.  It would have been nice with a full screen
screenshot before it did that so we can see which dialog it is...
I think mochitest has that, does anyone know how that works?
Attached file screenshot — 
The dialog says "Scroll down as soon as you press ok!" which points to
an earlier test layout/base/crashtests/802902.html
Attached patch fix — — Splinter Review 
I'll file a bug on 802902.html ...
Attachment #785923 - Flags: review?(ryanvm)
I haven't tried, but this might fix bug 873083 too...
Comment on attachment 785923 [details] [diff] [review]
fix

Worth a shot.

Also, we recently disabled layout/forms/crashtests/366537-1.xhtml in bug 899349 due to the same issue, only for 367587-1.html to start failing instead. Maybe another related problem?
Attachment #785923 - Flags: review?(ryanvm) → review+
Blocks: 901752
https://hg.mozilla.org/integration/mozilla-inbound/rev/caa19279dbb6
Flags: in-testsuite+
Whiteboard: [test disabled][leave open]
https://hg.mozilla.org/mozilla-central/rev/caa19279dbb6
Assignee: nobody → matspal
Status: NEW → RESOLVED
Closed: 11 years ago
Flags: in-testsuite+ → in-testsuite-
Resolution: --- → FIXED
Target Milestone: --- → mozilla26
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: