442125 - ensure focus test failing, but no other tests failing (on unittest VMs)

Status: RESOLVED FIXED

(Testing :: Mochitest, defect)

Description

[(not currently active) Ted Mielczarek]

For some reason the "ensure focus" test from bug 431464 has been failing intermittently on the Linux moz2 unittest box, but none of the other focus-related tests are failing.

Comment 1

[Andrew Schultz]

It seems a bit strange not only that there are no real failures, but also that focus gets fixed after the next test... I haven't seen this locally.

Comment 2

[(not currently active) Ted Mielczarek]

This only seems to happen on the VMs. We probably need to figure out what weirdness is happening here and make it more reliable in that environment. Andrew: any thoughts on extra debug output we could put into that test to figure out what's happening here?

Comment 3

[Andrew Schultz]

It'd be nice to know what does have focus.  Is it failing because !document.hasFocus() or because document.activeElement is not the iframe (and if not, what is document.activeElement)?

Might it help to move the window.scrollTo inside the if block (before window.focus())?

Comment 4

[(not currently active) Ted Mielczarek]

I don't know, I'm asking you. :) We can add any output that you think would be useful, or modify the test to make it more reliable. The Linux unittest VMs hit this fairly often, we need to track down the cause and fix it.

Comment 6

[Andrew Schultz]

Attachment: patch

this moves the window.scrollTo and adds what has focus to the failure message.

Comment 7

[(not currently active) Ted Mielczarek]

Comment on attachment 330570 [details] [diff] [review]
patch

Please land this so we can start to track down this failure!

Comment 8

[Andrew Schultz]

Comment on attachment 330570 [details] [diff] [review]
patch

I landed this.

Comment 9

[(not currently active) Ted Mielczarek]

*** 477 ERROR TEST-UNEXPECTED-FAIL | chrome://mochikit/content/chrome/toolkit/content/tests/chrome/test_bug331215.xul | Unable to restore focus ([none]), expect failures and timeouts.

from http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1216757778.1216761362.9039.gz

Comment 10

[Andrew Schultz]

OK... so some other window (dialog?) has focus.  Perhaps a new window from the previous test took a long time to close (the ensure focus bits already wait 3 seconds, which seems like plenty).  Focus might get restored when a test opens a window.  In this case the previous test (test_bug304188.xul) did open a new window).  And it looks like the ensure-focus part failed for two tests in a row after that (so that's 6 seconds).  The first test (test_bug331215.xul) didn't open a window while the second (test_bug360437.xul) did.

I'm not sure what else can be added to provide more info.  We need to figure out what has focus, which probably involves someone seeing it fail.  That, or add something like my hack to automation.py.in that takes a screenshot when it sees something in the log.

http://rheneas.eng.buffalo.edu/~andrew/screenshot_hack

Comment 11

[(not currently active) Ted Mielczarek]

We saw in another bug where setTimeout(N, ...) would fire the associated function, but Date.now() would show that no time had actually elapsed. I wonder if we're hitting something similar here, where our timeout fires, but to the VM, no time has really elapsed. (I don't know how that happens, but apparently it does!) Maybe you could add something here to store the current time, and display how much time Date.now() thinks has elapsed between setTimeout calls? Might help us narrow it down.

Comment 12

[Andrew Schultz]

Attachment: check Date.now()

Comment 13

[(not currently active) Ted Mielczarek]

Comment on attachment 330889 [details] [diff] [review]
check Date.now()

Worth a shot, for sure.

Comment 14

[Andrew Schultz]

Comment on attachment 330889 [details] [diff] [review]
check Date.now()

OK, landed this too.

Comment 15

[Andrew Schultz]

looks like it is waiting 3 seconds:

*** 477 ERROR TEST-UNEXPECTED-FAIL | chrome://mochikit/content/chrome/toolkit/content/tests/chrome/test_bug331215.xul | Unable to restore focus after 2.974 seconds ([none]), expect failures and timeouts.

Comment 16

[(not currently active) Ted Mielczarek]

So I was thinking, how do you feel about changing this to a purely informational message, instead of using ok()? While it's a useful diagnostic, it's not worth having random orange over. We could change it to just log "Error: unable to restore focus...", so that it'd show up in the brief tinderbox log, but not be counted as a testfail.

Comment 17

[Andrew Schultz]

Attachment: reverts previous patches and turns failure into a warning

Comment 18

[(not currently active) Ted Mielczarek]

Comment on attachment 331307 [details] [diff] [review]
reverts previous patches and turns failure into a warning

+            TestRunner.logger.log("Unable to restore focus, expect failures and timeouts.");

Please make this start with "Error: " so that the tinderbox error parser will still show it in the brief log.

Thanks!

Comment 19

[(not currently active) Ted Mielczarek]

I checked this in for you with my suggested change:
http://hg.mozilla.org/mozilla-central/index.cgi/rev/bfd3534f3473
http://hg.mozilla.org/mozilla-central/index.cgi/rev/654ad593ecd2

(in two changesets because I forgot to make my suggested change the first time)

Comment 20

[Serge Gautherie (:sgautherie)]

(In reply to comment #18)
> (From update of attachment 331307 [details] [diff] [review])
> +            TestRunner.logger.log("Unable to restore focus, expect failures
> and timeouts.");

While the elapsed time proved to be working as expected, so not useful anymore;
and same for the focus owner which seemed to always be "none";
wasn't the name of the test interesting to (still) have on that line too ?

Could it be re-added ?
(even if it used(?) to be provided by a function we're not using anymore.)

Comment 21

[(not currently active) Ted Mielczarek]

I checked in the effective diff of all these patches into CVS (produced by doing  hg diff -r 3a6edfb3fa9f -r 654ad593ecd2 testing/mochitest/tests/SimpleTest/TestRunner.js):

Checking in testing/mochitest/tests/SimpleTest/TestRunner.js;
/cvsroot/mozilla/testing/mochitest/tests/SimpleTest/TestRunner.js,v  <--  TestRu
nner.js
new revision: 1.17; previous revision: 1.16
done