Closed Bug 567950 Opened 15 years ago Closed 13 years ago

Intermittent browser_keyevents_during_autoscrolling.js | Timed out

Categories

(Toolkit :: UI Widgets, defect)

Product:
Toolkit
Component:
UI Widgets
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla19
Tracking Flags:
Tracking Status
firefox18 --- fixed
firefox19 --- fixed

People

(Reporter: philor, Assigned: froydnj)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

fix intermittent browser_keyevents_during_autoscrolling.js timeout by properly cleaning up in browser_default_image_filename.js
1.22 KB, patch
Gavin
: review+
Details | Diff | Splinter Review
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1274749799.1274752191.2411.gz Rev3 MacOSX Leopard 10.5.8 mozilla-central debug test mochitest-other on 2010/05/24 18:09:59 s: talos-r3-leopard-045 TEST-PASS | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | maybe run tests <load:false, focus:true> -- loaded: interactive active window: ([object ChromeWindow @ 0x1498c300 (native @ 0x14a70ff4)]) chrome://browser/content/browser.xul focused window: ([object XPCNativeWrapper [object Window @ 0x17f0a5e0 (native @ 0x21371b04)]]) about:blank desired window: ([object XPCNativeWrapper [object Window @ 0x17f0a5e0 (native @ 0x21371b04)]]) about:blank child window: ([object XPCNativeWrapper [object Window @ 0x17f0a5e0 (native @ 0x21371b04)]]) about:blank docshell visible: true ++DOMWINDOW == 117 (0x189af414) [serial = 2278] [outer = 0x21371ad0] WARNING: Unable to retrieve the tooltip node document.: file /builds/slave/mozilla-central-macosx-debug/build/layout/xul/base/src/nsXULTooltipListener.cpp, line 613 --DOMWINDOW == 116 (0x216fa0f4) [serial = 2226] [outer = 0x215bfb20] [url = http://example.com/tests/toolkit/components/places/tests/browser/399606-window.location.href.html] (bunch more GC) ###!!! ASSERTION: bad hint in chrome code: 'hint != XOW && hint != SOW && hint != COW', file /builds/slave/mozilla-central-macosx-debug/build/js/src/xpconnect/src/xpcwrappednativescope.cpp, line 1043 (repeats three more times) TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | Timed out
The first recorded time this showed up was after the tracemonkey merge: 23b20b0eb9f3. Rob, do you know if you saw anything like this on the tracemonkey tree before merging?
Who could tell? There were no instances of this in the last 168 hours in TM's 10.5.2 opt and debug mochitest-other, but then it's only been frequent in mozilla-central's 10.6.2 tests, and TM doesn't have 10.6.2 yet.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1274847475.1274848557.1722.gz Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central opt test mochitest-other on 2010/05/25 21:17:55 s: talos-r3-snow-016 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | Timed out
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1274847672.1274850017.7934.gz Rev3 MacOSX Leopard 10.5.8 mozilla-central debug test mochitest-other on 2010/05/25 21:21:12 s: talos-r3-leopard-030 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | Timed out
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275013568.1275016216.14508.gz Rev3 MacOSX Leopard 10.5.8 mozilla-central debug test mochitest-other on 2010/05/27 19:26:08 s: talos-r3-leopard-043
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275074196.1275076517.10959.gz Rev3 MacOSX Leopard 10.5.8 mozilla-central debug test mochitest-other on 2010/05/28 12:16:36 s: talos-r3-leopard-021
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275098416.1275099994.14418.gz Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central opt test mochitest-other on 2010/05/28 19:00:16 s: talos-r3-snow-030
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275104200.1275105635.4191.gz Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central opt test mochitest-other on 2010/05/28 20:36:40 s: talos-r3-snow-009
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275107321.1275108589.15542.gz Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central opt test mochitest-other on 2010/05/28 21:28:41 s: talos-r3-snow-036
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275260442.1275262486.19241.gz Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central opt test mochitest-other on 2010/05/30 16:00:42
Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central opt test mochitest-other on 2010/06/05 00:53:29 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275724409.1275725343.10066.gz
I starred this (first, followed by philor and jesse) on tbpl, but the robot doesn't seem to have posted here: http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276040673.1276044100.30829.gz Rev3 MacOSX Leopard 10.5.8 mozilla-central debug test mochitest-other on 2010/06/08 16:44:33 s: talos-r3-leopard-036 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | Timed out
philringnalda%gmail.com http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276145645.1276147898.27508.gz Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central opt test mochitest-other on 2010/06/09 21:54:05 s: talos-r3-snow-017 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | Timed out
philringnalda%gmail.com http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276147605.1276149478.1096.gz Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central opt test mochitest-other on 2010/06/09 22:26:45 s: talos-r3-snow-014 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | Timed out
philringnalda%gmail.com http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276144705.1276148536.29935.gz Rev3 MacOSX Leopard 10.5.8 mozilla-central debug test mochitest-other on 2010/06/09 21:38:25 s: talos-r3-leopard-013 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | Timed out
philringnalda%gmail.com http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276152618.1276154544.21967.gz Rev3 MacOSX Leopard 10.5.8 mozilla-central debug test mochitest-other on 2010/06/09 23:50:18 s: talos-r3-leopard-024 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | Timed out
philringnalda%gmail.com http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276172502.1276173736.31703.gz Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central opt test mochitest-other on 2010/06/10 05:21:42 s: talos-r3-snow-016 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | Timed out
philringnalda%gmail.com http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276227754.1276228670.21833.gz Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central opt test mochitest-other on 2010/06/10 20:42:34 s: talos-r3-snow-007 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | Timed out
philringnalda%gmail.com http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276228060.1276229728.25270.gz Rev3 MacOSX Leopard 10.5.8 mozilla-central debug test mochitest-other on 2010/06/10 20:47:40 s: talos-r3-leopard-004 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | Timed out
philringnalda%gmail.com http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276233168.1276234983.9728.gz Rev3 MacOSX Leopard 10.5.8 mozilla-central debug test mochitest-other on 2010/06/10 22:12:48 s: talos-r3-leopard-019 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | Timed out
I think that this bug isn't toolkit/XUL widgets. The all logs show the cause is in specific code of Mac. > TEST-START | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js > TEST-PASS | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | before wait for focus -- loaded: interactive active window: ([object ChromeWindow]) chrome://browser/content/browser.xul focused window: ([object XPCNativeWrapper [object Window]]) about:blank desired window: ([object XPCNativeWrapper [object Window]]) about:blank child window: ([object XPCNativeWrapper [object Window]]) about:blank docshell visible: true > TEST-PASS | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | must wait for load > TEST-PASS | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | already focused > TEST-PASS | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | maybe run tests <load:false, focus:true> -- loaded: interactive active window: ([object ChromeWindow]) chrome://browser/content/browser.xul focused window: ([object XPCNativeWrapper [object Window]]) about:blank desired window: ([object XPCNativeWrapper [object Window]]) about:blank child window: ([object XPCNativeWrapper [object Window]]) about:blank docshell visible: true > TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | Timed out > TEST-INFO | checking window state > TEST-PASS | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | before wait for focus -- loaded: complete active window: ([object ChromeWindow]) chrome://browser/content/browser.xul focused window: ([object XPCNativeWrapper [object Window]]) data:text/html,<body%20style="height:10000px;"></body> desired window: ([object ChromeWindow]) chrome://browser/content/browser.xul child window: ([object XPCNativeWrapper [object Window]]) data:text/html,<body%20style="height:10000px;"></body> docshell visible: true > TEST-PASS | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | already focused > TEST-PASS | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | maybe run tests <load:true, focus:true> -- loaded: complete active window: ([object ChromeWindow]) chrome://browser/content/browser.xul focused window: ([object XPCNativeWrapper [object Window]]) data:text/html,<body%20style="height:10000px;"></body> desired window: ([object ChromeWindow]) chrome://browser/content/browser.xul child window: ([object XPCNativeWrapper [object Window]]) data:text/html,<body%20style="height:10000px;"></body> docshell visible: true > TEST-START | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_save_resend_postdata.js And looks like onFocus() of the test isn't called.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276586325.1276588298.6764.gz Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central opt test mochitest-other on 2010/06/15 00:18:45 s: talos-r3-snow-027 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | Timed out
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276675184.1276676887.8310.gz Rev3 Fedora 12x64 mozilla-central debug test mochitest-other on 2010/06/16 00:59:44
OS: Mac OS X → All
Hardware: x86 → All
I disabled this test, the intermittent orange is outweighing its test-coverage value. https://hg.mozilla.org/mozilla-central/rev/172a93563b1e
Whiteboard: [orange] → [orange][test disabled]
Disabling this test just seems to have caused bug 572954; perhaps both of them are caused by some earlier test leaving things in a bad state?
(In reply to comment #412) > Disabling this test just seems to have caused bug 572954; perhaps both of them > are caused by some earlier test leaving things in a bad state? So noticing this actually led me to what seems to have fixed bug 572954. In particular: This bug started on May 24, probably when the tracemonkey merge containing a patch, disabling a test in the same directory as this one, landed on mozilla-central: http://hg.mozilla.org/mozilla-central/rev/890c0d2e45b3 http://hg.mozilla.org/mozilla-central/rev/a8c721b2f221 When Callek re-enabled that test on June 9: http://hg.mozilla.org/mozilla-central/rev/31fbc861bcb9 he inadvertently(?) backed out enndeakin's change from May 18: http://hg.mozilla.org/mozilla-central/rev/eb49e81b9f4d When gavin disabled this test on June 17: https://hg.mozilla.org/mozilla-central/rev/172a93563b1e it caused the test in which Callek backed out Neil's fix to start failing. (That test was renamed on June 8 so that it falls after this one rather than before, though: http://hg.mozilla.org/mozilla-central/rev/99271495668e ) My patch today (June 19) fixed the error made on June 9: http://hg.mozilla.org/mozilla-central/rev/2fe127f49fec and seems to have fixed bug 572954. Does that mean that it's safe to undo the disabling of this test? It's really hard for me to tell; I feel like I'm missing a piece of what happened here.
(My best guess, I suppose, would be some cross-test dependency due to a test leaving something in a different state than it started in.)
Also, this bug was Mac-only prior to June 14, but on June 14 it became cross-platform (primarily Mac+Linux, but occasional on Windows).
Thanks for the synopsis, David! Now what is causing these cross-test dependencies is more clear to me than it was when I commented on bug 572954 comment 91. Browser-chrome tests used to clean up the environment for the next test by closing the tab they worked on and opening a new tab: gBrowser.addTab(); gBrowser.removeCurrentTab(); The fact is that this action is not really creating a clean environment, because when this code completes, there is still a pending page load for "about:blank" in the newly opened tab, that will generate load-related events later, interfering with the next test. I've seen a variety of solutions for this problem, for example it was fixed by changing the lines above to: gBrowser.addTab().linkedBrowser.stop(); gBrowser.removeCurrentTab(); I guess that calling stop() prevents all the load-related events from being raised while the next test runs. The shared "waitForFocus" function was also modified to ignore any "about:blank" load events, because they may be the consequence of a previous test not doing a proper clean-up. The fact is that apparently, since this test calls waitForFocus, it should be already shielded from these particular circumstances. However, there might be a problem with the fact that waitForFocus is called only after a "pageshow" event has already been raised. In the logs from comment 411, it seems that when this test times out, it is because waitForFocus never sees the "load" event for the "data:" URL. Note how readyState is "interactive" when waitForFocus is invoked. My theory (purely academic, as I don't have a build ready to try it) is that this test sometimes works because a "pageshow" event for "about:blank" bleeds from a previous test into this one. In this case, the "load" event for the "data:" URL can be properly intercepted by waitForFocus. I think the event that makes this test work might be present because of this change: http://hg.mozilla.org/mozilla-central/rev/14b0f9623642 Note that waitForFocus doesn't wait for "pageshow", only for "load". I'd change the code of this test to call waitForFocus immediately, without waiting for "pageload": waitForExplicitFinish(); var dataUri = 'data:text/html,<body style="height:10000px;"></body>'; gBrowser.loadURI(dataUri); waitForFocus(onLoad, content); If that works, then maybe the change contained in http://hg.mozilla.org/mozilla-central/rev/14b0f9623642 can be reverted.
(In reply to comment #413) > Does that mean that it's safe to undo the disabling of this test? Maybe? http://hg.mozilla.org/mozilla-central/rev/82c8f89d89ea
Whiteboard: [orange][test disabled] → [orange]
Status: NEW → RESOLVED
Closed: 15 years ago
Resolution: --- → WORKSFORME
s: talos-r3-xp-052 TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/toolkit/content/tests/browser/browser_keyevents_during_autoscrolling.js | Test timed out https://tbpl.mozilla.org/php/getParsedLog.php?id=15295715&tree=Mozilla-Inbound Haven't yet reopened in the hope that it's a one-off...
Status: RESOLVED → REOPENED
Resolution: WORKSFORME → ---
My work in bug 715376 resulted in perma-oranging this test. I don't pretend to understand the exact sequence of events, but the test reliably fails when run with the rest of the tests in toolkit/content/tests/browser/ and passes reliably when run standalone. That fact, along with comment 416, leads me to believe that the problem is really in browser_default_image_filename.js, which is the test run before this test. And indeed, if you look at the commit history for that test, you'll find that it was committed on 17 Sept 2012...just before this test started intermittently oranging again. I'm not really sure who's qualified to review this. Picking ttaubert as a willing victim.
Attachment #674691 - Flags: review?(ttaubert)
Comment on attachment 674691 [details] [diff] [review] fix intermittent browser_keyevents_during_autoscrolling.js timeout by properly cleaning up in browser_default_image_filename.js I've been looking into a patch that detects tests that do this, since it's a common pattern: https://hg.mozilla.org/try/rev/e897764a7cdb Indeed this tests shows up in that patches output: https://tbpl.mozilla.org/?tree=Try&rev=e897764a7cdb
Attachment #674691 - Flags: review?(ttaubert) → review+
(In reply to :Gavin Sharp (use gavin@gavinsharp.com for email) from comment #442) > I've been looking into a patch that detects tests that do this, since it's a > common pattern: > https://hg.mozilla.org/try/rev/e897764a7cdb I filed bug 805068 for this.
https://hg.mozilla.org/mozilla-central/rev/92ebd9011e11
Status: REOPENED → RESOLVED
Closed: 15 years ago → 13 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Target Milestone: --- → mozilla19
Whiteboard: [orange]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: