Closed Bug 490062 Opened 11 years ago Closed 7 years ago

random focus-related orange on mochitests ("unable to restore focus, expect failures and timeouts")

Categories

(Core :: General, defect)

defect
Not set

Tracking

()

RESOLVED WORKSFORME

People

(Reporter: dbaron, Unassigned)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1240593218.1240602509.20416.gz
Linux mozilla-central unit test on 2009/04/24 10:13:38  

shows random focus-related orange on a Linux mochitest-plain run.


There were various errors indicating the focus was in the wrong place, such as:

*** 43643 INFO Error: Unable to restore focus, expect failures and timeouts.
*** 43645 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/generic/test/test_movement_by_characters.html | Right movement broken in H K - got 0, expected 1
*** 43980 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/generic/test/test_movement_by_words.html | Left movement broken with eatSpace=true in "漢字、漢字。漢字"; sel.anchorNode.parentNode=[object HTMLDivElement] - got 0, expected 3
*** 43985 INFO Error: Unable to restore focus, expect failures and timeouts.

finally ending with:

*** 74276 INFO Running /tests/layout/xul/base/test/test_bug477754.xul...
*** 74277 INFO Error: Unable to restore focus, expect failures and timeouts.

command timed out: 300 seconds without output, killing pid 14770
process killed by signal 9
Whiteboard: [orange]
Just saw this on Windows:

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1248059920.1248062949.30474.gz
WINNT 5.2 mozilla-central test mochitests on 2009/07/19 20:18:40  
18525 INFO Error: Unable to restore focus, expect failures and timeouts.
18529 INFO Error: Unable to restore focus, expect failures and timeouts.
29990 ERROR TEST-UNEXPECTED-FAIL | /tests/docshell/test/navigation/test_bug430723.html | Page2: Ensure we could scrol. - Didn't expect 0, but got it.
29993 ERROR TEST-UNEXPECTED-FAIL | /tests/docshell/test/navigation/test_bug430723.html | Page2Again: Ensure we can still scroll. - Didn't expect 0, but got it.
85749 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menubar.xul | Test timed out.
85752 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menuchecks.xul | Test timed out.
85984 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_popup_attribute.xul | Test timed out.
85987 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_popup_button.xul | Test timed out.
85988 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | 4 test timeouts, giving up.
85989 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | Skipping 36 remaining tests.

... and this run also leaked stuff on content/base/test/test_bug375314.html
OS: Linux → All
Hardware: x86 → All
Summary: random focus-related orange on Linux mochitests ("unable to restore focus, expect failures and timeouts") → random focus-related orange on mochitests ("unable to restore focus, expect failures and timeouts")
There are other [orange] bugs on related focus issues (bug 451482 and bug 487817, maybe more). So there might be overlap in the reporting.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1248725494.1248728615.32602.gz
Linux mozilla-central test mochitests on 2009/07/27 13:11:34

86456 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menuchecks.xul | Test timed out.
86459 INFO Error: Unable to restore focus, expect failures and timeouts.
86460 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | cursor down command event fired - got false, expected true
86461 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | cursor down selectedItem - got [object XULElement], expected [object XULElement]
86462 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | cursor down skip disabled command event fired - got false, expected true
86463 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | cursor down skip disabled selectedItem - got [object XULElement], expected [object XULElement]
86464 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | cursor up skip disabled command event fired - got false, expected true
86465 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | cursor up skip disabled selectedItem - got [object XULElement], expected [object XULElement]
86466 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | cursor up command event fired - got false, expected true
86468 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | cursor up wrap command event fired - got false, expected true
86469 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | cursor up wrap selectedItem - got [object XULElement], expected [object XULElement]
86470 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | cursor down wrap command event fired - got false, expected true
86475 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | letter pressed command event fired - got false, expected true
86476 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | letter pressed selectedItem - got [object XULElement], expected [object XULElement]
86477 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | letter pressed command event fired - got false, expected true
86478 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | letter pressed selectedItem - got [object XULElement], expected [object XULElement]
86479 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | letter pressed again command event fired - got false, expected true
86480 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | letter pressed again selectedItem - got [object XULElement], expected [object XULElement]
86481 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | second letter pressed command event fired - got false, expected true
86482 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | second letter pressed selectedItem - got [object XULElement], expected [object XULElement]
86483 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | different letter pressed command event fired - got false, expected true
86485 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | focus to menulist focus event fired - got false, expected true
86486 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | focus to button focus event fired - got false, expected true
86487 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_menulist_keynav.xul | tab from menulist focused button - got [object XULElement], expected [object XULElement]
86490 INFO Error: Unable to restore focus, expect failures and timeouts.
86511 INFO Error: Unable to restore focus, expect failures and timeouts.
86574 INFO Error: Unable to restore focus, expect failures and timeouts.
86667 INFO Error: Unable to restore focus, expect failures and timeouts.
86668 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_panelfrommenu.xul | Test timed out.
86671 INFO Error: Unable to restore focus, expect failures and timeouts.
87121 INFO Error: Unable to restore focus, expect failures and timeouts.
87631 INFO Error: Unable to restore focus, expect failures and timeouts.
87632 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_popup_coords.xul | Test timed out.
87635 INFO Error: Unable to restore focus, expect failures and timeouts.
87638 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_popup_keys.xul | Test timed out.
87639 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | 4 test timeouts, giving up.
87640 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | Skipping 34 remaining tests.
Just got two in a row on mozilla-central Linux (though running on different slaves):

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1251207141.1251210052.7665.gz
Linux mozilla-central test mochitests on 2009/08/25 06:32:21  

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1251210051.1251212556.7452.gz
Linux mozilla-central test mochitests on 2009/08/25 07:20:51
Linux mozilla-central test everythingelse on 2009/09/07 13:40:08
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1252356008.1252358105.19274.gz

Failure of caret test, probably caused by focus problems:

2765 INFO Error: Unable to restore focus, expect failures and timeouts.
2787 INFO Error: Unable to restore focus, expect failures and timeouts.
2788 ERROR TEST-UNEXPECTED-FAIL | chrome://mochikit/content/chrome/toolkit/content/tests/chrome/test_showcaret.xul | [SimpleTest/SimpleTest.js, window.onerror] An error occurred - document.commandDispatcher.getControllerForCommand("cmd_scrollBottom") is null
2791 INFO Error: Unable to restore focus, expect failures and timeouts.
OS X 10.5.2 mozilla-central test mochitests on 2009/10/02 16:06:04
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1254524764.1254527536.7166.gz

113163 INFO Running /tests/uriloader/exthandler/tests/mochitest/test_unsafeBidiChars.xhtml...
113164 INFO Error: Unable to restore focus, expect failures and timeouts.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256367019.1256370153.23999.gz

7657 INFO Error: Unable to restore focus, expect failures and timeouts.
...
7661 ERROR TEST-UNEXPECTED-FAIL | chrome://mochikit/content/chrome/toolkit/content/tests/chrome/test_showcaret.xul | scrollY for showcaret - got 7916, expected 0
7662 ERROR TEST-UNEXPECTED-FAIL | chrome://mochikit/content/chrome/toolkit/content/tests/chrome/test_showcaret.xul | focusNode for showcaret - Didn't expect [object XPCNativeWrapper [object HTMLBodyElement]], but got it.
7663 ERROR TEST-UNEXPECTED-FAIL | chrome://mochikit/content/chrome/toolkit/content/tests/chrome/test_showcaret.xul | focusOffset for showcaret
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6-Unittest/1257445708.1257446650.10178.gz
OS X 10.5.2 mozilla-1.9.2 test mochitests on 2009/11/05 10:28:28

It's a little irritating that the build summarizer produces nothing useful for this failure.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270481975.1270485500.11379.gz
OS X 10.5.2 mozilla-central debug test mochitests-4/5 on 2010/04/05 08:39:35
s: moz2-darwin9-slave16

78247 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/tables/test/test_bug541668_table_event_delivery.html | Test timed out.
78249 INFO Running /tests/layout/xul/base/test/test_bug381167.xhtml...
78250 INFO Error: Unable to restore focus, expect failures and timeouts.

78306 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/xul/base/test/test_bug477754.xul | Test timed out.
78308 INFO Running /tests/layout/xul/base/test/test_resizer.xul...
78309 INFO Error: Unable to restore focus, expect failures and timeouts.

78316 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/xul/base/test/test_resizer.xul | Test timed out.
78318 INFO Running /tests/layout/xul/base/test/test_stack.xul...
78319 INFO Error: Unable to restore focus, expect failures and timeouts.
This bug doesn't seem specific enough to be useful.
Well, I suspect what is really happening here is that something unrelated to the product being tested is happening on the slave running the test that is taking focus away form the application being tested.

One thing that would really help, would be to either change the logfile parser to add this message to what is linked int eh summary, so that it shows up in tbpl.

Alternatively, the message could be re-worded to sthat the log parser picks it up without requiring a change to the parser.

Would adding the word "UNEXPECTED"  make this work?
This does nothing to fix the issue.  It just re-formats this message so that it ends up in the logfile summary, so that orange builds hitting this issue will be linked here instead of new useless random orange bugs being opened because of the fallout form this issue.
OK it seems this message is appearing on green builds as well, so making it a recognized errors will probably just turn green builds orange.

I need to do more work to figure out what is going on here.

I still think this is a good change, once we get this message to only appear if there is a real issue.
Mass marking whiteboard:[orange] bugs WFM (to clean up TBPL bug suggestions) that:
* Haven't changed in > 6months
* Whose whiteboard contains none of the strings: {disabled,marked,random,fuzzy,todo,fails,failing,annotated,leave open,time-bomb}
* Passed a (quick) manual inspection of bug summary/whiteboard to ensure they weren't a false positive.

I've also gone through and searched for cases where the whiteboard wasn't labelled correctly after test disabling, by using attachment description & basic comment searches. However if the test for which this bug was about has in fact been disabled/annotated/..., please accept my apologies & reopen/mark the whiteboard appropriately so this doesn't get re-closed in the future (and please ping me via IRC or email so I can try to tweak the saved searches to avoid more edge cases).

Sorry for the spam! Filter on: #FFA500
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → WORKSFORME
Whiteboard: [orange]
This seems to be affecting B2G:

https://tbpl.mozilla.org/php/getParsedLog.php?id=18414458&tree=Services-Central

16:49:46     INFO -  loading http://mochi.test:8888/tests/?autorun=1&closeWhenDone=1&logFile=%2Fdata%2Flocal%2Ftests%2Flogs%2Fmochitest.log&fileLevel=INFO&consoleLevel=INFO&totalChunks=6&thisChunk=3&hideResultsTable=1&testManifest=b2g.json&runOnly=true, 1
16:49:46     INFO -  creating 1!
16:49:46     INFO -  0 INFO Running tests 603-903/1805
16:49:46     INFO -  1 INFO SimpleTest START
16:49:46     INFO -  2 INFO TEST-START | /tests/dom/tests/mochitest/dom-level2-core/test_documentimportnode19.html
16:49:46     INFO -  3 INFO Error: Unable to restore focus, expect failures and timeouts.
16:49:46     INFO -  4 INFO TEST-PASS | /tests/dom/tests/mochitest/dom-level2-core/test_documentimportnode19.html | entitiesNotNull
16:49:46     INFO -  5 INFO TEST-KNOWN-FAIL | /tests/dom/tests/mochitest/dom-level2-core/test_documentimportnode19.html | [failure as todo] Test threw exception: TypeError: nodeMap is undefined
16:49:46     INFO -  6 INFO TEST-PASS | /tests/dom/tests/mochitest/dom-level2-core/test_documentimportnode19.html | test marked todo should have failed somewhere
16:49:46     INFO -  7 INFO TEST-END | /tests/dom/tests/mochitest/dom-level2-core/test_documentimportnode19.html | finished in 5045ms
16:49:46     INFO -  8 INFO TEST-START | /tests/dom/tests/mochitest/dom-level2-core/test_documentimportnode20.html
16:49:46     INFO -  9 INFO Error: Unable to restore focus, expect failures and timeouts.

…

17:08:19     INFO -  964 INFO TEST-END | /tests/dom/tests/mochitest/dom-level2-core/test_setAttributeNS05.html | finished in 4410ms
17:08:19     INFO -  965 INFO TEST-START | /tests/dom/tests/mochitest/dom-level2-core/test_setAttributeNS06.html
17:08:19  WARNING -  TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/dom-level2-core/test_setAttributeNS06.html | application timed out after 330 seconds with no output
17:08:19  WARNING -  This is a harness error.
17:08:19     INFO -  INFO | automation.py | Application ran for: 0:20:05.985000
17:08:19     INFO -  INFO | automation.py | Reading PID log: /tmp/tmp3Xxbddpidlog
17:11:28     INFO -  WARNING | automationutils.processLeakLog() | refcount logging is off, so leaks can't be detected!
17:11:28     INFO -  INFO | runtests.py | Running tests: end.
17:11:29    ERROR - Return code: 1
Status: RESOLVED → REOPENED
Resolution: WORKSFORME → ---
It might be more useful to file a new bug for that b2g-specific issue, rather than to reopen a bug that's had no new reports for 2 1/2 years.  (especially when it's a vague kind of failure like this one)
(In reply to Daniel Holbert [:dholbert] from comment #16)
> It might be more useful to file a new bug for that b2g-specific issue,
> rather than to reopen a bug that's had no new reports for 2 1/2 years. 
> (especially when it's a vague kind of failure like this one)

I'll take your word for it!
Status: REOPENED → RESOLVED
Closed: 7 years ago7 years ago
Resolution: --- → INCOMPLETE
Resolution: INCOMPLETE → WORKSFORME
You need to log in before you can comment on or make changes to this bug.