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

RESOLVED FIXED in mozilla9

Status

()

defect
RESOLVED FIXED
8 years ago
4 years ago

People

(Reporter: mbrubeck, Assigned: mounir)

Tracking

(Blocks 1 bug, {intermittent-failure})

Trunk
mozilla9
All
Linux
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(4 attachments)

Posted 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.
Posted 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: 8 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla9
Afraid not.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Assignee: ehsan → nobody