Daniel, this is drifting to the top of the orange list as other things get fixed. Can anyone from layout take a look? Thanks!

Punting to tobytailor. Looking at a recent log, it seems we never print anything for this test: 14:26:24 INFO - 2784 INFO TEST-START | layout/generic/test/test_bug632379.xul 14:31:52 INFO - TEST-INFO | started process screentopng 14:31:53 INFO - TEST-INFO | screentopng: exit 0 14:31:53 INFO - 2785 INFO must wait for load 14:31:53 INFO - 2786 INFO TEST-UNEXPECTED-FAIL | layout/generic/test/test_bug632379.xul | Test timed out. https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=19964651 For the record, here's a screenshot from when we fail (which is linked alongside "artifact uploaded" in the log above). Doesn't look like anything's out of the ordinary: http://mozilla-releng-blobs.s3.amazonaws.com/blobs/mozilla-inbound/sha512/2bf7aa68b2804a257b1f02b6a2cae2f3fa6858eb4c8f3fb7cbec366316b4ac07d014320cba26b9e128d7c3a5c0bcc85aa2b74f685c07b79305cb9a0a3ca9d58f The test itself is here: http://mxr.mozilla.org/mozilla-central/source/layout/generic/test/test_bug632379.xul ...and it looks like all of its work is chained off of a call to "SimpleTest.waitForFocus(doTest);" (added in bug 675201). So my strawman idea is that we're never receiving focus, and hence never proceeding with the test. tobytailor, could you add some logging to this test to confirm/deny that hypothesis (and see just how far we get)? I think you can add logging like e.g. info("about to wait for focus"), info("made it to doTest)", etc.

[I've added a dependency on the bug which added this test, as well as 2 other bugs about intermittent timeouts in this test over the years -- one of which (bug 675201) was supposedly fixed via this waitForFocus invocation.]

(In reply to Daniel Holbert [:dholbert] from comment #42) > So my strawman idea is that we're never receiving focus, and hence never > proceeding with the test. (Note: in the post-failure screenshot, it does *look* like the Firefox window has focus. But it seems possible that waitForFocus is failing somehow despite the fact that we have focus.)

Actually, we probably want to add logging to all of the chained async functions here, since any one of them could be the point of failure. Looks like the expected test flow is approximately: * waitForFocus() --> async call to doTest(), which opens a menu. --> async calls to openSubmenu() (via "onpopupshown" attribute), which opens a submenu via a keypress. --> async calls to snapshot(), which either opens a different submenu or invokes the actual test function ("is()"), and eventually calls SimpleTest.finish() which ends the test (and avoids the timeout failure) Something like that. So, we need to add info() logging to each of these steps, to see how far we get & where things fall apart.

Adds logging to each step in this test.

I'll land this for you. (Not sure sheriffs are comfortable landing unreviewed "checkin-needed" patches, even in cases where serious review isn't really merited.)

Comment on attachment 8714538 [details] [diff] [review] Debugging patch. BTW, the commit message here wasn't really in the right format. Here's the full commit message: >Subject: [PATCH] Bug 1207914 - Intermittent test_bug632379.xul | Test timed > out. try: -b d -p linux -u mochitest-o -t none > >--- > layout/generic/test/test_bug632379.xul | 10 ++++++++++ > 1 file changed, 10 insertions(+) > * It shouldn't have the [PATCH] at the beginning. * It should have a description of the change (and in this case, a hint that it's not actually a fix) rather than the bug title. * It probably shouldn't have the "1 file changed, 10 insertions(+)" etc. cruft included in the commit message, if possible. (I assume some hg<-->git tool must be adding that?) That's probably less of an issue, though.

(I tweaked the commit message to address comment 53 before landing)

I tried running this under rr chaos mode too, and even tho I was as well able to reproduce it on the first try, my results are a bit different. For me, the first "openSubmenu()" call actually does show up, the following "synthesizeKey" doesn't seem to have any effect.

Sorry, I meant to follow up here -- I believe the issue that I captured in rr in comment 60 was different as well, and was just from the window not having focus inside my xvfb session. :-/ This issue seems to start happening after I've done a few xvfb-run commands -- presumably some window inside of the xvfb session starts stealing focus, or something else about xvfb gets crufty. I repeated comment 60's "xvfb-run rr record -h" experiment after a fresh boot (with a presumably-clean xvfb session), using an increased --run-until-failure repetition-count (500 repetitions I think), and I didn't run into any problems, unfortunately. --> marking comment 60 as obsolete

Pushed by philringnalda@gmail.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/b6478ff0daad Skip test_bug632379.xul on Linux for constant timeouts

Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.