671934 - mochitest-chrome runs have two hidden failures

Status: RESOLVED INVALID

(Testing :: Mochitest, defect)

Description

[(no longer active)]

When _something_ fails in the mochitest-chrome, there are two failures happening in the suite all the time:

30041 INFO TEST-START | chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul
30042 ERROR TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul | Move DOWN to select_element. Found start
++DOMWINDOW == 767 (1FEF62C8) [serial = 2129] [outer = 081FC208]
30043 INFO TEST-INFO | chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul | before wait for focus -- loaded: uninitialized active window: ([object ChromeWindow @ 0x4630108 (native @ 0x2f450f0)]) chrome://browser/content/browser.xul focused window: ([object Window @ 0x1d1d1418 (native @ 0x1fef62c8)]) chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul desired window: ([object Window @ 0x1d1d1418 (native @ 0x1fef62c8)]) chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul child window: ([object Window @ 0x1d1d1418 (native @ 0x1fef62c8)]) chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul docshell visible: true
30044 INFO TEST-INFO | chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul | must wait for load
30045 INFO TEST-INFO | chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul | already focused
30046 INFO TEST-INFO | chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul | maybe run tests <load:false, focus:true> -- loaded: uninitialized active window: ([object ChromeWindow @ 0x4630108 (native @ 0x2f450f0)]) chrome://browser/content/browser.xul focused window: ([object Window @ 0x1d1d1418 (native @ 0x1fef62c8)]) chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul desired window: ([object Window @ 0x1d1d1418 (native @ 0x1fef62c8)]) chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul child window: ([object Window @ 0x1d1d1418 (native @ 0x1fef62c8)]) chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul docshell visible: true
30047 INFO TEST-INFO | chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul | waitForEvent called <type:load, target[object XULDocument @ 0x1d1d8570 (native @ 0x30f2948)]> -- loaded: complete active window: ([object ChromeWindow @ 0x4630108 (native @ 0x2f450f0)]) chrome://browser/content/browser.xul focused window: ([object Window @ 0x1d1d1418 (native @ 0x1fef62c8)]) chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul desired window: ([object Window @ 0x1d1d1418 (native @ 0x1fef62c8)]) chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul child window: ([object Window @ 0x1d1d1418 (native @ 0x1fef62c8)]) chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul docshell visible: true
30048 INFO TEST-INFO | chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul | maybe run tests <load:true, focus:true> -- loaded: complete active window: ([object ChromeWindow @ 0x4630108 (native @ 0x2f450f0)]) chrome://browser/content/browser.xul focused window: ([object Window @ 0x1d1d1418 (native @ 0x1fef62c8)]) chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul desired window: ([object Window @ 0x1d1d1418 (native @ 0x1fef62c8)]) chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul child window: ([object Window @ 0x1d1d1418 (native @ 0x1fef62c8)]) chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul docshell visible: true
WARNING: NS_ENSURE_SUCCESS(rv, 0) failed with result 0x8000FFFF: file e:/builds/moz2_slave/m-cen-w32-dbg/build/content/base/src/nsContentUtils.cpp, line 2528
WARNING: NS_ENSURE_TRUE(pusher.Push(aBoundElement)) failed: file e:/builds/moz2_slave/m-cen-w32-dbg/build/content/xbl/src/nsXBLProtoImplMethod.cpp, line 327
30049 INFO TEST-END | chrome://mochitests/content/chrome/toolkit/spatial-navigation/tests/test_snav_tightlinks.xul | finished in 1327ms
30050 INFO TEST-START | chrome://mochitests/content/chrome/widget/tests/test_bug343416.xul
30051 ERROR TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/widget/tests/test_bug343416.xul | Move DOWN to 5. Found 1
++DOMWINDOW == 768 (1FF03A50) [serial = 2130] [outer = 081FC208]
30052 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_bug343416.xul | nsIIdleService should exist and be implemented on all tier 1 platforms.
30053 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_bug343416.xul | Getting the idle time should not fail in normal circumstances on any tier 1 platform.
30054 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_bug343416.xul | The nsIIdleService should allow us to add an observer.
30055 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_bug343416.xul | The nsIIdleService should allow us to add the same observer again.
30056 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_bug343416.xul | The nsIIdleService should allow us to remove the observer just once.
WARNING: NS_ENSURE_SUCCESS(rv, 0) failed with result 0x8000FFFF: file e:/builds/moz2_slave/m-cen-w32-dbg/build/content/base/src/nsContentUtils.cpp, line 2528
WARNING: NS_ENSURE_TRUE(pusher.Push(aBoundElement)) failed: file e:/builds/moz2_slave/m-cen-w32-dbg/build/content/xbl/src/nsXBLProtoImplMethod.cpp, line 327
30057 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_bug343416.xul | Getting the idle time should not fail in normal circumstances on any tier 1 platform.
30058 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_bug343416.xul | The idle time should have increased by roughly the amount of time it took for the timeout to fire. You didn't touch the mouse or keyboard during thetest did you?
30059 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_bug343416.xul | The subject of the notification should be the nsIIdleService.
30060 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_bug343416.xul | We should be able to remove our observer here.
30061 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_bug343416.xul | We set a timeout and it should have fired by now.
30062 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_bug343416.xul | We added a listener and it should have been called by now.
30063 INFO TEST-END | chrome://mochitests/content/chrome/widget/tests/test_bug343416.xul | finished in 6686ms

For example: http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1310747547.1310752075.10615.gz&fulltext=1#err2

These failures do not exist in successful mochitest-chrome runs, but it seems like anything that fails in the mochitest-chrome tests would trigger these two failures.

Comment 1

[(no longer active)]

And by "hidden" I mean that these two failures are not accounted for in the total failure number count in TBPL.

Comment 2

[Joel Maher ( :jmaher ) (UTC -8)]

the toolkit/spatial-navigation tests seem to be not running anything when I look into them as a directory of tests.  I suspect that is part of the problem here.

Comment 4

[(no longer active)]

Any updates here?  This is seen on mozilla-central/inbound all the time, and is confusing lots of people.  :(

Comment 5

[Joel Maher ( :jmaher ) (UTC -8)]

heh, not even an hour ago I posted that snav tests were acting weird.  I do have some data.  I found that test_snav.xul was not doing a SimpleTest.waitForExplicitFinish() properly, even though the function was called.  What it looks like is that we need to call that function before we start the test, instead of near the end of the test.  All the other test files seem to be mis reporting, I will take a further look at this tonight and get a patch on try for an overnight run.

Comment 6

[Cameron McCormack (:heycam)]

It's worrying that these TEST-UNEXPECTED-FAIL lines don't contribute towards the number of test failures.  Does that mean tbpl shows the run as green if these tests are the only ones that fail?

Comment 7

[Joel Maher ( :jmaher ) (UTC -8)]

well, I want to fix the tests first, I can run through the tbpl error parsing code to see why this doesn't show up, but I suspect that these are failing with 0 tests run which is probably confusing the tbpl parser.

Comment 8

[Joel Maher ( :jmaher ) (UTC -8)]

odd, found bug 477250 which might be related to the failure in test_bug343416.xul.

Comment 9

[Joel Maher ( :jmaher ) (UTC -8)]

ok, test_bug343416.xul failure above looks like it is a message from test_snav_tightlinks.xul (the previous test) and since we never waitForExplicitFinish(), we get finish the test while we have a set_timeout(func, 100) which is called.  

I know there is some concern about these two failures not being counted by tbpl, I suspect that is a chrome harness problem

Comment 10

[Nicholas Nethercote [inactive]]

Bug 603517 comment 13 might be relevant here?

Comment 11

[Joel Maher ( :jmaher ) (UTC -8)]

Attachment: cleanup snav chrome tests (1.0)

These tests were not waiting for explicit finish as that call was made at the end of the test, not before we started the test.  Also I cleaned up some basic syntax errors.

This passes on try server.

Comment 12

[Joel Maher ( :jmaher ) (UTC -8)]

dougt tells me he is removing the snav stuff including the tests.  This issue might go away assuming that lands in the next day or so.

Comment 13

[Doug Turner (:dougt)]

see bug 670880

Comment 15

[Doug Turner (:dougt)]

snav has been expunged.