Closed Bug 675201 Opened 13 years ago Closed 13 years ago

Intermittent ERROR TEST-UNEXPECTED-FAIL | layout/generic/test/test_bug632379.xul | Test timed out.

Categories

(Core :: Layout, defect)

Product:
Core
Component:
Layout
Platform:
All
Linux
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla9

People

(Reporter: mbrubeck, Assigned: mounir)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure)

Attachments

(4 files)

screenshot
588.16 KB, image/png
Details
Patch (v1)
1.59 KB, patch
mounir
: review+
Details | Diff | Splinter Review
Some info about what is happening
2.11 KB, patch
ehsan.akhgari
: review+
Details | Diff | Splinter Review
Use waitForFocus
632 bytes, patch
ehsan.akhgari
: review+
mounir
: checkin+
Details | Diff | Splinter Review
Attached image screenshot — 
http://tinderbox.mozilla.org/showlog.cgi?log=Mozilla-Inbound/1311877589.1311881975.1310.gz
Rev3 Fedora 12 mozilla-inbound debug test mochitest-other on 2011/07/28 11:26:29 
s: talos-r3-fed-063

10570 INFO TEST-END | chrome://mochitests/content/chrome/layout/generic/test/test_bug514732-2.xul | finished in 689ms
10571 INFO TEST-START | chrome://mochitests/content/chrome/layout/generic/test/test_bug632379.xul
++DOMWINDOW == 565 (0xbf1ab08) [serial = 1098] [outer = 0x92e1358]
WARNING: NS_ENSURE_SUCCESS(rv, 0) failed with result 0x8000FFFF: file ../../../../content/base/src/nsContentUtils.cpp, line 2583
WARNING: NS_ENSURE_TRUE(pusher.Push(aBoundElement)) failed: file ../../../../content/xbl/src/nsXBLProtoImplMethod.cpp, line 327
--DOMWINDOW == 564 (0x9201430) [serial = 1096] [outer = 0xbbfdb58] [url = about:blank]
--DOMWINDOW == 563 (0xbfef658) [serial = 1088] [outer = 0xc09c0c0] [url = about:blank]
--DOMWINDOW == 562 (0xc09c108) [serial = 1087] [outer = (nil)] [url = about:blank]
--DOMWINDOW == 561 (0xa775318) [serial = 1084] [outer = (nil)] [url = chrome://mochitests/content/chrome/layout/forms/test/bug665540_window.xul]
--DOMWINDOW == 560 (0xc00cf00) [serial = 1085] [outer = (nil)] [url = about:blank]
WARNING: An event was posted to a thread that will never run it (rejected): file ../../../xpcom/threads/nsThread.cpp, line 388
WARNING: leaking reference to nsTimerImpl: file ../../../xpcom/threads/nsTimerImpl.cpp, line 494
WARNING: GetDefaultCharsetForLocale: need to add multi locale support: file ../../../../../intl/locale/src/unix/nsUNIXCharset.cpp, line 145
10572 ERROR TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/layout/generic/test/test_bug632379.xul | Test timed out.
XScreenSaver state: Disabled
User input has been idle for 983 seconds
args: ['/home/cltbld/talos-slave/test/build/bin/screentopng']
10573 INFO TEST-END | chrome://mochitests/content/chrome/layout/generic/test/test_bug632379.xul | finished in 304281ms
10574 INFO TEST-START | chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html
++DOMWINDOW == 561 (0xb09a438) [serial = 1099] [outer = 0x92e1358]
10575 INFO TEST-INFO | chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html | before wait for focus -- loaded: loading active window: ([object ChromeWindow @ 0x8bdacd8 (native @ 0x8bd8b18)]) chrome://browser/content/browser.xul focused window: ([object Window @ 0xbfa4210 (native @ 0xb09a438)]) chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html desired window: ([object Window @ 0xbfa4210 (native @ 0xb09a438)]) chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html child window: ([object Window @ 0xbfa4210 (native @ 0xb09a438)]) chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html docshell visible: true
10576 INFO TEST-INFO | chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html | must wait for load
10577 INFO TEST-INFO | chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html | already focused
10578 INFO TEST-INFO | chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html | maybe run tests <load:false, focus:true> -- loaded: loading active window: ([object ChromeWindow @ 0x8bdacd8 (native @ 0x8bd8b18)]) chrome://browser/content/browser.xul focused window: ([object Window @ 0xbfa4210 (native @ 0xb09a438)]) chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html desired window: ([object Window @ 0xbfa4210 (native @ 0xb09a438)]) chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html child window: ([object Window @ 0xbfa4210 (native @ 0xb09a438)]) chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html docshell visible: true
10579 INFO TEST-INFO | chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html | waitForEvent called <type:load, target[object HTMLDocument @ 0xbc4ac68 (native @ 0xb2b8568)]> -- loaded: complete active window: ([object ChromeWindow @ 0x8bdacd8 (native @ 0x8bd8b18)]) chrome://browser/content/browser.xul focused window: ([object Window @ 0xbfa4210 (native @ 0xb09a438)]) chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html desired window: ([object Window @ 0xbfa4210 (native @ 0xb09a438)]) chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html child window: ([object Window @ 0xbfa4210 (native @ 0xb09a438)]) chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html docshell visible: true
10580 INFO TEST-INFO | chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html | maybe run tests <load:true, focus:true> -- loaded: complete active window: ([object ChromeWindow @ 0x8bdacd8 (native @ 0x8bd8b18)]) chrome://browser/content/browser.xul focused window: ([object Window @ 0xbfa4210 (native @ 0xb09a438)]) chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html desired window: ([object Window @ 0xbfa4210 (native @ 0xb09a438)]) chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html child window: ([object Window @ 0xbfa4210 (native @ 0xb09a438)]) chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html docshell visible: true
WARNING: NS_ENSURE_SUCCESS(rv, 0) failed with result 0x8000FFFF: file ../../../../content/base/src/nsContentUtils.cpp, line 2583
WARNING: NS_ENSURE_TRUE(pusher.Push(aBoundElement)) failed: file ../../../../content/xbl/src/nsXBLProtoImplMethod.cpp, line 327
10581 INFO TEST-PASS | chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html | not crashed
10582 INFO TEST-END | chrome://mochitests/content/chrome/layout/generic/test/test_bug670058.html | finished in 6015ms
84 failures in 10 days, I'm about ready to say that we'd rather not run this test than run it.
Blocks: 632379
If it's failing that often, the window for when it started should be pretty small.
Heh. I just glanced at the first digit of the bug number, and assumed the window was "when the test landed" rather than "six months after it landed."
The first failure was on 35bd1513465d on mozilla-inbound.  If we assume the first failure came within 24 hours of the regression being pushed, then the regression range is something like:

https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=2148365fbb7c&tochange=35bd1513465d

I don't see anything obviously related there, or in the preceding day's pushes.  But I've only skimmed the commit log quickly.
Attached patch Patch (v1) — — Splinter Review 
layout/generic/test/test_bug514732.html is the test which gets executed right before this one.  It opens up a window, and when the test is done, it calls window.close() and finishes.  But closing a window is async, so it is possible for the window to remain on the screen when the next test starts, in which case, the test will fail to open its popups.

I believe that this patch should fix this issue.  What I'm doing is simply waiting until the window is closed, and then focusing the main window again and finishing.
Assignee: nobody → ehsan
Status: NEW → ASSIGNED
Attachment #553894 - Flags: review?(mounir)
Comment on attachment 553894 [details] [diff] [review]
Patch (v1)

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

r=mounir with waitForFocus being explained or fixed.

::: docshell/test/chrome/docshell_helpers.js
@@ +332,5 @@
> +      if (topic == "domwindowclosed") {
> +        os.removeObserver(this, topic);
> +        SimpleTest.waitForFocus(function() {
> +          SimpleTest.finish();
> +        });

Don't you want to check for |opener| being focused instead of |window|? Actually, I even wonder how |finish();| could be called...

@@ +336,5 @@
> +        });
> +      }
> +    }
> +  };
> +  os.addObserver(observer, "domwindowclosed", false);

FWIW, you can also use mozilla.org/embedcomp/window-watcher like:
let ww = Cc["@mozilla.org/embedcomp/window-watcher;1"].getService(Ci.nsIWindowWatcher);
ww.registerNotification(function(aSubject, aTopic, aData) {
  if (topic == "domwindowclosed") {
    ww.unregisterNotification(arguments.callee);
    ...
  }
});

I would prefer window-watcher because it makes the syntax easier but it's fine either way.
Attachment #553894 - Flags: review?(mounir) → review+
(In reply to Mounir Lamouri (:volkmar) from comment #223)
> Comment on attachment 553894 [details] [diff] [review]
> Patch (v1)
> 
> Review of attachment 553894 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> r=mounir with waitForFocus being explained or fixed.
> 
> ::: docshell/test/chrome/docshell_helpers.js
> @@ +332,5 @@
> > +      if (topic == "domwindowclosed") {
> > +        os.removeObserver(this, topic);
> > +        SimpleTest.waitForFocus(function() {
> > +          SimpleTest.finish();
> > +        });
> 
> Don't you want to check for |opener| being focused instead of |window|?
> Actually, I even wonder how |finish();| could be called...

Hmm, yes.  I wonder how this patch passed locally for me!!!  Which makes me wanna test it on try too (with this fixed).

> @@ +336,5 @@
> > +        });
> > +      }
> > +    }
> > +  };
> > +  os.addObserver(observer, "domwindowclosed", false);
> 
> FWIW, you can also use mozilla.org/embedcomp/window-watcher like:
> let ww =
> Cc["@mozilla.org/embedcomp/window-watcher;1"].getService(Ci.
> nsIWindowWatcher);
> ww.registerNotification(function(aSubject, aTopic, aData) {
>   if (topic == "domwindowclosed") {
>     ww.unregisterNotification(arguments.callee);
>     ...
>   }
> });
> 
> I would prefer window-watcher because it makes the syntax easier but it's
> fine either way.

Will do.
http://hg.mozilla.org/mozilla-central/rev/e79dbde50f8e
Status: ASSIGNED → RESOLVED
Closed: 13 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla9
Afraid not.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Assignee: ehsan → nobody
Before trying to investigate farther, it might be interesting to know when the test actually get timed out. Given that there is one test and at the end, we do not have this information.
Attachment #555994 - Flags: review?(ehsan)
Attachment #555994 - Flags: review?(ehsan) → review+
It's unlikely related but the test just before has this:
10858 INFO TEST-INFO | chrome://mochitests/content/chrome/layout/generic/test/test_bug514732-2.xul | [SimpleTest/SimpleTest.js, window.onerror] An error occurred: SpecialPowers is not defined at chrome://mochikit/content/tests/SimpleTest/docshell_helpers.js:403
JavaScript error: chrome://mochikit/content/tests/SimpleTest/docshell_helpers.js, line 403: SpecialPowers is not defined

Otherwise, there is no |ok| being run that means |$("mainMenu").open = true;| doesn't always do what is expected.
Attached patch Use waitForFocus — — Splinter Review 
I think waitForFocus is needed because we call synthesizeKey. Though, the tests times out before those calls so it might not fix the issue.
But it's possible that popupshown event doesn't appear if the page doesn't have the focus...

Let's try ;)
Attachment #559782 - Flags: review?(ehsan)
Attachment #559782 - Flags: review?(ehsan) → review+
Comment on attachment 559782 [details] [diff] [review]
Use waitForFocus

I believe Ehsan pushed that to m-i.
Attachment #559782 - Flags: checkin+
https://hg.mozilla.org/mozilla-central/rev/01a9f0ee2234

Resolving because this has been quiet on inbound for the past day, so it looks likely that it is fixed.
Status: REOPENED → RESOLVED
Closed: 13 years ago → 13 years ago
Resolution: --- → FIXED
Assignee: nobody → mounir
Hardware: x86 → All
Pushed a revert for the debug info patch to inbound.
Note that this change caused the close() call to never run in a bunch of tests, because Cc and Ci were not defined in them....

The patch in bug 688681 fixed that.
Depends on: 688681
(In reply to Boris Zbarsky (:bz) from comment #572)
> Note that this change caused the close() call to never run in a bunch of
> tests, because Cc and Ci were not defined in them....
> 
> The patch in bug 688681 fixed that.

Boris, did you mean to put this comment and dependency on bug 674321?
No, this was the right bug.  Bug 674321 broke other stuff in docshell_helpers, but comment 572 is correct for the "failing to close" bit.  Of course with the bug 674321 changes we never got to the code this bug added, so it didn't use to matter that much, I guess.
Specifically, the "Patch (v1)" from this bug was the issue.
No longer blocks: 735805
Depends on: 735805
Whiteboard: [orange]
Blocks: 816065
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: