Closed Bug 996988 Opened 6 years ago Closed 6 years ago

Intermittent browser_995164_registerArea_during_customize_mode.js | Should be told about window closing.

Categories

(Firefox :: Toolbars and Customization, defect)

x86
Windows 8
defect
Not set

Tracking

()

RESOLVED FIXED
Firefox 32
Tracking Status
firefox30 --- wontfix
firefox31 --- fixed
firefox32 --- fixed
firefox-esr24 --- unaffected

People

(Reporter: RyanVM, Assigned: Gijs)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

https://tbpl.mozilla.org/php/getParsedLog.php?id=37888217&tree=Mozilla-Inbound

WINNT 6.2 mozilla-inbound opt test mochitest-browser-chrome-1 on 2014-04-15 18:49:49 PDT for push 1a2e5e4a6760
slave: t-w864-ix-119

18:59:00     INFO -  TEST-INFO | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Check that removing the area registration from within customize mode works
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Now that the toolbar is no longer registered, should be in default state.
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Toolbar shouldn't be known to customize mode.
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Now that the toolbar is registered again, should no longer be in default state.
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Toolbar should be known to customize mode again.
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Button moved out of palette
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Button's back on toolbar
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Sync button really is on toolbar.
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Sync button is on other toolbar, too.
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Button moved to the palette
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Sync button really is in palette.
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Sync button is in palette in other window, too.
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Button moved out of palette
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Button's back on toolbar
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Sync button really is on toolbar.
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Sync button is on other toolbar, too.
18:59:00  WARNING -  TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Should be told about window closing.
18:59:00     INFO -  Stack trace:
18:59:00     INFO -      JS frame :: chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js :: <TOP_LEVEL> :: line 88
18:59:00     INFO -      JS frame :: resource://gre/modules/Task.jsm :: TaskImpl_run :: line 282
18:59:00     INFO -      JS frame :: resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js :: Handler.prototype.process :: line 863
18:59:00     INFO -      JS frame :: resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js :: this.PromiseWalker.walkerLoop :: line 742
18:59:00     INFO -      native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Sync button's parent node should still be a wrapper.
18:59:00     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Toolbar should still be a customizable area for this customize mode instance.
18:59:01     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Should be informed about this window's toolbar
18:59:01     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Reason for final removal should be correct.
18:59:01     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Should be told about area being unregistered.
18:59:01     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Should be fine after exiting customize mode.
18:59:01     INFO -  TEST-INFO | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Leaving test
18:59:01     INFO -  TEST-INFO | MEMORY STAT vsize after test: 840990720
18:59:01     INFO -  TEST-INFO | MEMORY STAT vsizeMaxContiguous after test: 1893662720
18:59:01     INFO -  TEST-INFO | MEMORY STAT residentFast after test: 265408512
18:59:01     INFO -  TEST-INFO | MEMORY STAT heapAllocated after test: 94880746
18:59:01     INFO -  INFO TEST-END | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | finished in 3232ms
Flags: needinfo?(gijskruitbosch+bugs)
So I can't reproduce this locally, but the test was uplifted and is intermittent-ing on Aurora which makes me feel bad.

The confusing thing is, there's another test that does something similar (open window, close window, check that the onWindowClosed listener gets called) and AFAICT from bugzilla, it's not intermittent ( https://mxr.mozilla.org/mozilla-central/source/browser/components/customizableui/test/browser_987492_window_api.js ).

I looked at some logs:

https://tbpl.mozilla.org/php/getParsedLog.php?id=37913220&tree=Mozilla-Aurora (fails)
https://tbpl.mozilla.org/php/getParsedLog.php?id=37903728&tree=Mozilla-Aurora&full=1 (passes, therefore full log, takes a while to load...).

Relevant snippets:

Fail:
01:02:18     INFO -  ++DOMWINDOW == 80 (098FE168) [pid = 1008] [serial = 3723] [outer = 00000000]
01:02:18     INFO -  ++DOMWINDOW == 81 (13EDEAF0) [pid = 1008] [serial = 3724] [outer = 098FE168]

<snip>

01:02:18     INFO -  ++DOMWINDOW == 84 (123BA610) [pid = 1008] [serial = 3727] [outer = 098FE168]

<snip>

01:02:18     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Sync button is on other toolbar, too.
01:02:19     INFO -  ++DOMWINDOW == 85 (1F799108) [pid = 1008] [serial = 3728] [outer = 098FE168]
01:02:19  WARNING -  TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Should be told about window closing.


Pass:

20:44:40     INFO -  ++DOMWINDOW == 100 (1394B138) [pid = 4088] [serial = 3723] [outer = 00000000]
20:44:40     INFO -  ++DOMWINDOW == 101 (151F58E0) [pid = 4088] [serial = 3724] [outer = 1394B138]
20:44:40     INFO -  ++DOMWINDOW == 104 (211F5C98) [pid = 4088] [serial = 3727] [outer = 1394B138]
20:44:41     INFO -  ++DOMWINDOW == 105 (20C411A8) [pid = 4088] [serial = 3728] [outer = 1394B138]
20:44:41     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Sync button is on other toolbar, too.

<snip>

/test/browser_995164_registerArea_during_customize_mode.js | Sync button is on other toolbar, too.
20:44:41     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Should be informed about other toolbar
20:44:41     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Reason should be correct.
20:44:41     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js | Should be told about window closing.

In particular, it seems that in the failure case, right before the failure, we're still busy creating a DOM window for (a subframe of) the window that we just opened. In the passing case, we've dealt with that well before the window is closed again.

The test succeeding depends (amongst other things) on the unload event of the opened window firing before window.closed is set to true. I don't know if that's guaranteed to be the case, but certainly our other tests all use this pattern and aren't intermittently failing all over the place.

To verify that it's not something else that I've missed that's causing this, I'm going to push some more test checks to fx-team shortly which should help figure out whether my diagnosis is correct and the failures aren't due to something else that I'm missing.
Might as well take this...

remote:   https://hg.mozilla.org/integration/fx-team/rev/449e835346b5
Assignee: nobody → gijskruitbosch+bugs
Flags: needinfo?(gijskruitbosch+bugs)
Keywords: leave-open
(In reply to TBPL Robot from comment #8)
> edmorley
> https://tbpl.mozilla.org/php/getParsedLog.php?id=38020321&tree=Mozilla-
> Inbound
> WINNT 6.2 mozilla-inbound opt test mochitest-browser-chrome-1 on 2014-04-17
> 09:23:43
> revision: 7340e1b5c7e1
> slave: t-w864-ix-037
> 
> TEST-UNEXPECTED-FAIL |
> chrome://mochitests/content/browser/browser/components/customizableui/test/
> browser_995164_registerArea_during_customize_mode.js | Window should have
> sent onWindowClosed notification. - Got null, expected [object ChromeWindow]
> TEST-UNEXPECTED-FAIL |
> chrome://mochitests/content/browser/browser/components/customizableui/test/
> browser_995164_registerArea_during_customize_mode.js | Should be told about
> window closing.
> Return code: 1


So yeah, we're also not getting an onWindowClosed notification, which basically means unload isn't firing or is being caught before we get it, for whatever reason...

Blair, do you have any idea what's going on here, and why this test ( https://mxr.mozilla.org/mozilla-central/source/browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js) is breaking, but this test ( https://mxr.mozilla.org/mozilla-central/source/browser/components/customizableui/test/browser_987492_window_api.js ) isn't ?
Flags: needinfo?(bmcbride)
I have no clue :(
Flags: needinfo?(bmcbride)
Adding more logging:

remote:   https://hg.mozilla.org/integration/fx-team/rev/42b9ed6826ad
So, as far as I can tell, this is because 'unload' can, but doesn't always, fire after window.closed is set to true. Waiting for window.closed is therefore not enough. I'm changing this test, but also changing promiseWindowClosed, which will hopefully fix bug 1007304 and might help fix some of the other intermittent orange we've seen. Jared, does this look sane to you?
Attachment #8432794 - Flags: review?(jaws)
Comment on attachment 8432794 [details] [diff] [review]
use different method to wait for window closure,

Review of attachment 8432794 [details] [diff] [review]:
-----------------------------------------------------------------

::: browser/components/customizableui/test/browser_995164_registerArea_during_customize_mode.js
@@ +105,5 @@
>      },
>    };
>    CustomizableUI.addListener(listener);
> +  otherWin.close();
> +  let windowClosed = yield windowCloseDeferred.promise;

Shouldn't I be seeing promiseWindowClosed used here?
Attachment #8432794 - Flags: review?(jaws) → review-
Comment on attachment 8432794 [details] [diff] [review]
use different method to wait for window closure,

Review of attachment 8432794 [details] [diff] [review]:
-----------------------------------------------------------------

Talked it over with Gijs, and will grant r+ on this, but please include a comment in browser_995164 test to state why you're not using the head.js function.
Attachment #8432794 - Flags: review- → review+
Attachment #8432794 - Flags: checkin+
See Also: → 1007304
The silence here combined with the even more obvious silence on bug 1007304 means I'm pretty sure this is fixed now.
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Keywords: leave-open
Target Milestone: --- → Firefox 32
Blocks: 1007304
You need to log in before you can comment on or make changes to this bug.