Closed Bug 947039 Opened 6 years ago Closed 4 years ago

Intermittent browser_913972_currentset_overflow.js | Should have an overflowing toolbar, | Should have fewer children.

Categories

(Firefox :: Toolbars and Customization, defect)

x86
Linux
defect
Not set

Tracking

()

RESOLVED WORKSFORME

People

(Reporter: philor, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, Whiteboard: [Australis:P-])

+++ This bug was initially created as a clone of Bug #941130 +++

https://tbpl.mozilla.org/php/getParsedLog.php?id=31526245&tree=Mozilla-Inbound
Ubuntu ASAN VM 12.04 x64 mozilla-inbound opt test mochitest-browser-chrome on 2013-12-05 14:11:24 PST for push fbc0b4c30fd0
slave: tst-linux64-ec2-317

https://tbpl.mozilla.org/php/getParsedLog.php?id=31528761&tree=Mozilla-Central
Ubuntu ASAN VM 12.04 x64 mozilla-central opt test mochitest-browser-chrome on 2013-12-05 15:09:23 PST for push ee425b3ccc29
slave: tst-linux64-ec2-318

14:25:15  WARNING -  TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_913972_currentset_overflow.js | Should have an overflowing toolbar.
14:25:15     INFO -  Stack trace:
14:25:15     INFO -      JS frame :: chrome://mochitests/content/browser/browser/components/customizableui/test/browser_913972_currentset_overflow.js :: gTests<.run :: line 17
14:25:15     INFO -      JS frame :: resource://gre/modules/Task.jsm :: TaskImpl_run :: line 233
14:25:15     INFO -      JS frame :: resource://gre/modules/Promise.jsm :: <TOP_LEVEL> :: line 767
14:25:15     INFO -      JS frame :: resource://gre/modules/Promise.jsm :: <TOP_LEVEL> :: line 531
14:25:15     INFO -      native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0
14:25:15     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_913972_currentset_overflow.js | Currentset should be the same when overflowing.
14:25:15     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_913972_currentset_overflow.js | Should still be in default state when overflowing.
14:25:15  WARNING -  TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_913972_currentset_overflow.js | Should have fewer children.
14:25:15     INFO -  Stack trace:
14:25:15     INFO -      JS frame :: chrome://mochitests/content/browser/browser/components/customizableui/test/browser_913972_currentset_overflow.js :: gTests<.run :: line 20
14:25:15     INFO -      JS frame :: resource://gre/modules/Task.jsm :: TaskImpl_run :: line 233
14:25:15     INFO -      JS frame :: resource://gre/modules/Promise.jsm :: <TOP_LEVEL> :: line 767
14:25:15     INFO -      JS frame :: resource://gre/modules/Promise.jsm :: <TOP_LEVEL> :: line 531
14:25:15     INFO -      native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0
This makes no sense whatso-f***ing-ever. Here's a relevant test snippet:

15       window.resizeTo(400, window.outerHeight);
16       yield waitForCondition(() => navbar.hasAttribute("overflowing"));
17       ok(navbar.hasAttribute("overflowing"), "Should have an overflowing toolbar.");

The test on line 17 fails. But the yield here will wait up to 5 seconds in total, and will then reject the promise (leading to an error being reported, not execution just continuing as if nothing happened). The test log shows that it waited only 1 second, and no error is reported, which presumably means the condition occurred at some point and the promise resolved. AIUI Task.jsm, that would mean the remainder of the function (at least until the next yield with a promise) would be run sync. In which case:

How on earth is it even possible for the yield to succeed but the test right after it to fail?

Yoric, am I missing something here?
Flags: needinfo?(dteller)
Right now, just one hypothesis from the top of my head: depending on the definition of |waitForCondition|, this |yield| can cause the rest of the task to be executed on the next tick. Could it happen that |navbar| stops having attribute "overflowing" in the meantime?
Flags: needinfo?(dteller)
(In reply to David Rajchenbach Teller [:Yoric] <currently on training, will be back on Friday 6th> from comment #2)
> Right now, just one hypothesis from the top of my head: depending on the
> definition of |waitForCondition|, this |yield| can cause the rest of the
> task to be executed on the next tick. Could it happen that |navbar| stops
> having attribute "overflowing" in the meantime?

I'm confused. waitForCondition returns a promise. We use a bunch of setTimeouts and resolve the promise as soon as the condition passed (as a function to evaluate) to waitForCondition is true.

When we resolve the promise, is the stuff after the yield for that promise not executed sync from the resolution onwards?
Flags: needinfo?(dteller)
(Worth fixing, but given its infrequency so far not worth tracking for Australis.)
Whiteboard: [Australis:P1] → [Australis:P-]
(In reply to :Gijs Kruitbosch (Extremely limited availability until Dec. 18, then PTO until January 2) from comment #3)
> I'm confused. waitForCondition returns a promise. We use a bunch of
> setTimeouts and resolve the promise as soon as the condition passed (as a
> function to evaluate) to waitForCondition is true.
> 
> When we resolve the promise, is the stuff after the yield for that promise
> not executed sync from the resolution onwards?

If I recall correctly, resolve() is async. Paolo, can you confirm?
Flags: needinfo?(dteller) → needinfo?(paolo.mozmail)
(In reply to David Rajchenbach Teller [:Yoric] (please use "needinfo?") from comment #5)
> (In reply to :Gijs Kruitbosch (Extremely limited availability until Dec. 18,
> then PTO until January 2) from comment #3)
> > I'm confused. waitForCondition returns a promise. We use a bunch of
> > setTimeouts and resolve the promise as soon as the condition passed (as a
> > function to evaluate) to waitForCondition is true.
> > 
> > When we resolve the promise, is the stuff after the yield for that promise
> > not executed sync from the resolution onwards?
> 
> If I recall correctly, resolve() is async. Paolo, can you confirm?

In Task.jsm we still use the Add-on SDK promises (bug 887923), thus at present the resolution might be synchronous.

Since we're planning to change that, code using Task.jsm should be designed assuming that every time "yield" is called other code can be executed in-between.
Flags: needinfo?(paolo.mozmail)
Hrm, those last four aren't actually this bug... Filed bug 960389 for this new stuff.
Nor are these last two. In any case, this test is now disabled on Linux:

remote:   https://hg.mozilla.org/integration/fx-team/rev/1eb1165f9a58
(In reply to :Paolo Amadini from comment #6)
> (In reply to David Rajchenbach Teller [:Yoric] (please use "needinfo?") from
> comment #5)
> > (In reply to :Gijs Kruitbosch (Extremely limited availability until Dec. 18,
> > then PTO until January 2) from comment #3)
> > > I'm confused. waitForCondition returns a promise. We use a bunch of
> > > setTimeouts and resolve the promise as soon as the condition passed (as a
> > > function to evaluate) to waitForCondition is true.
> > > 
> > > When we resolve the promise, is the stuff after the yield for that promise
> > > not executed sync from the resolution onwards?
> > 
> > If I recall correctly, resolve() is async. Paolo, can you confirm?
> 
> In Task.jsm we still use the Add-on SDK promises (bug 887923), thus at
> present the resolution might be synchronous.
> 
> Since we're planning to change that, code using Task.jsm should be designed
> assuming that every time "yield" is called other code can be executed
> in-between.

This has happened by now. We could potentially investigate reenabling this to see if they are less problematic than they were before.

I would also note that there's now several more tests that do similar things, that have all been summarily disabled on Linux even on landing to avoid causing headaches because we were shipping, and we were confident that if the code worked well on Windows/OSX, there shouldn't be an issue on Linux either.

Finally, note that while this happened both to this test and to the one for 918049 (relevant bug is in "see also"), it never happened for the first test that does this (the one for 909779, see https://hg.mozilla.org/integration/fx-team/rev/1eb1165f9a58), which was also disabled. I wonder if that test didn't/doesn't clean up properly or something.
See Also: → 940624
Inactive; closing (see bug 1180138).
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.