Intermittent test_bug632379.xul | Test timed out

NEW
Assigned to

Status

()

defect
P3
normal
4 years ago
9 months ago

People

(Reporter: philor, Assigned: tschneider)

Tracking

({intermittent-failure, leave-open})

Trunk
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox44 wontfix, firefox47 wontfix, firefox48 wontfix, firefox49 affected, firefox50 disabled, firefox51 disabled)

Details

(Whiteboard: [test disabled on linux])

Attachments

(1 attachment)

Reporter

Description

4 years ago
No description provided.
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Summary: Intermittent test_bug632379.xul | Test timed ou → Intermittent test_bug632379.xul | Test timed out
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Daniel, this is drifting to the top of the orange list as other things get fixed.  Can anyone from layout take a look?  Thanks!
Flags: needinfo?(dholbert)
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.
Depends on: 632379
Flags: needinfo?(dholbert) → needinfo?(tschneider)
[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.]
Depends on: 675201, 816065
(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.
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Assignee

Updated

3 years ago
Assignee: nobody → tschneider
Flags: needinfo?(tschneider)
Comment hidden (Intermittent Failures Robot)
Adds logging to each step in this test.
Assignee

Updated

3 years ago
Keywords: checkin-needed
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.)
Keywords: checkin-needed
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)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (obsolete)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
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
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Reporter

Updated

3 years ago
Whiteboard: [test disabled on linux]

Comment 104

3 years ago
Pushed by philringnalda@gmail.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/b6478ff0daad
Skip test_bug632379.xul on Linux for constant timeouts
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)

Comment 110

3 years ago
Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.
Priority: -- → P3
Comment hidden (Intermittent Failures Robot)
You need to log in before you can comment on or make changes to this bug.