Closed Bug 1101287 Opened 5 years ago Closed 5 years ago

Intermittent browser_934951_zoom_in_toolbar.js | Default zoom is 100% for about:home - Got 110, expected 100

Categories

(Firefox :: Toolbars and Customization, defect)

defect
Not set
Points:
5

Tracking

()

RESOLVED FIXED
Firefox 37
Iteration:
37.2
Tracking Status
firefox35 --- unaffected
firefox36 --- fixed
firefox37 --- fixed
firefox-esr31 --- unaffected

People

(Reporter: KWierso, Assigned: Gijs)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file, 1 obsolete file)

13:01:36 INFO - 1044 INFO TEST-START | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_934951_zoom_in_toolbar.js
13:01:36 INFO - 1045 INFO checking window state
13:01:36 INFO - 1046 INFO Entering test
13:01:36 INFO - 1047 INFO TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_934951_zoom_in_toolbar.js | Default zoom is 100% for about:mozilla
13:01:36 INFO - 1048 INFO TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_934951_zoom_in_toolbar.js | Zoom is changed to 110% for about:mozilla
13:01:36 INFO - 1049 INFO TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_934951_zoom_in_toolbar.js | Default zoom is 100% for about:newtab
13:01:36 INFO - 1050 INFO TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_934951_zoom_in_toolbar.js | Default zoom is 100% for about:mozilla
13:01:36 INFO - 1051 INFO TEST-PASS | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_934951_zoom_in_toolbar.js | Zoom is changed to 110% for about:mozilla
13:01:36 INFO - 1052 INFO Wait for tab event: load
13:01:36 INFO - 1053 INFO Tab event received: load
13:01:36 INFO - 1054 INFO TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_934951_zoom_in_toolbar.js | Default zoom is 100% for about:home - Got 110, expected 100
13:01:36 INFO - Stack trace:
13:01:36 INFO - chrome://mochikit/content/browser-test.js:test_is:834
13:01:36 INFO - chrome://mochitests/content/browser/browser/components/customizableui/test/browser_934951_zoom_in_toolbar.js:null:46
13:01:36 INFO - self-hosted:InterpretGeneratorResume:960
13:01:36 INFO - self-hosted:next:918
13:01:36 INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:651:9
13:01:36 INFO - Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:577:7
13:01:36 INFO - SimpleTest.waitForFocus/maybeRunTests/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:683:49
13:01:36 INFO - 1055 INFO TEST-OK | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_934951_zoom_in_toolbar.js | took 439ms
13:01:36 INFO - 1056 INFO TEST-START | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_938980_navbar_collapsed.js
13:01:39 INFO - 1057 INFO TEST-OK | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_938980_navbar_collapsed.js | took 2740ms
13:01:39 INFO - 1058 INFO TEST-START | chrome://mochitests/content/browser/browser/components/customizableui/test/browser_938995_indefaultstate_nonremovable.js
Ohai unowned topfail.
Flags: needinfo?(gijskruitbosch+bugs)
Note to self: opt-only, OS X only, mostly 10.8 but a few 10.6 cases. Seems like an OS-X only race. Some APZ OSX commits but a while before this started hitting.

First hit on m-i, then m-c, then elsewhere.

Most recent m-i cset to be merged to m-c before it went orange was ab85b3342254.

Earliest m-i cset in here is a lie, and is really:

https://treeherder.mozilla.org/ui/index.html#/jobs?repo=mozilla-inbound&revision=f185bda1e516

(at least, the highest number of green 10.8 bc1 runs before then in https://treeherder.mozilla.org/ui/index.html#/jobs?repo=mozilla-inbound&fromchange=132909245ca8&tochange=83147bd55260&filter-searchStr=OS%20X%2010.8%20opt%20mochitest-browser-chrome-1 is 7, and there are 13-odd green runs before that one.

Going to do some retriggers to verify this happened on m-i around that time rather than somewhere else.
15 each on the following:

https://treeherder.mozilla.org/ui/#/jobs?repo=mozilla-inbound&revision=582d9b5011f9

https://treeherder.mozilla.org/ui/#/jobs?repo=mozilla-inbound&revision=0edc83d3670f

https://treeherder.mozilla.org/ui/#/jobs?repo=mozilla-inbound&revision=82dfe4ee980b

https://treeherder.mozilla.org/ui/#/jobs?repo=mozilla-inbound&revision=a59f355fe056

I'll adjust if I see more optimistic rates of failures to ensure I'm not missing anything.
Assignee: nobody → gijskruitbosch+bugs
Status: NEW → ASSIGNED
Iteration: --- → 37.2
Points: --- → 5
Flags: qe-verify-
Flags: needinfo?(gijskruitbosch+bugs)
Flags: in-testsuite+
Flags: firefox-backlog+
This looks like the run-by-dir enabling to me. Sadly, that doesn't really help with narrowing it down, and I can't reproduce this on my 10.9 machine if I run the test in isolation, and I can't use --repeat with a dir. :-\
Blocks: 1057512
Drew, looking at the code here:

44   is(parseInt(zoomResetButton.label, 10), 110, "Zoom is changed to 110% for about:mozilla");
45   yield promiseTabLoadEvent(tab1, "about:home");
46   is(parseInt(zoomResetButton.label, 10), 100, "Default zoom is 100% for about:home");

So this assumes that by the time "load fires on the content", and the yield asynchronously returns, we've fired:

http://mxr.mozilla.org/mozilla-central/source/browser/base/content/browser-fullZoom.js#517

because of

http://mxr.mozilla.org/mozilla-central/source/browser/components/customizableui/CustomizableWidgets.jsm#502

... and it looks like that just ain't true. Does that make sense, and is the appropriate fix here to fix the test? I think so, but I'd like confirmation...
Flags: needinfo?(adw)
I think that makes sense.  Probably the test should instead observe the expected label mutation on zoomResetButton?
Flags: needinfo?(adw)
(In reply to Drew Willcoxon :adw from comment #145)
> I think that makes sense.  Probably the test should instead observe the
> expected label mutation on zoomResetButton?

See, I was going to waitForCondition, but this is much better. I'll write it up later tonight or tomorrow.
I'd trypush but the tree is shut. Try string for reference (because 10.8 is disabled by default): "Bug 1101287 - try: -b o -p macosx64 -u mochitest-bc[10.8] -t none"
Comment on attachment 8534480 [details] [diff] [review]
fix browser_934951_zoom_in_toolbar.js to use a mutation observer to wait for a label change,

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

Looks good, just some nits.

::: browser/components/customizableui/test/browser_934951_zoom_in_toolbar.js
@@ +49,1 @@
>    yield promiseTabLoadEvent(tab1, "about:home");

It shouldn't be necessary anymore to wait until the page has loaded.  You still need to load the page of course, but waiting for load shouldn't be necessary because the attribute change should always happen after the page load.  We just can't say how long after page load it will take to happen.  But there shouldn't be any harm in waiting either, so up to you.

::: browser/components/customizableui/test/head.js
@@ +472,5 @@
> +  return new Promise((resolve, reject) => {
> +    info("waiting for mutation: " + JSON.stringify(aOptions));
> +    let obs = new MutationObserver((mutations) => {
> +      if (mutations.length > 0) {
> +        info("mutation occurred");

In similar situations in tests I always do an Assert.ok(true, "mutation occurred") since it's a success condition that the mutation did in fact occur.  (Of course the corresponding failure condition is a timeout.)
Attachment #8534480 - Flags: review?(adw) → review+
Unfortunately, this appears to have made the test basically permafail on e10s and introduced a new failure mode as well. Backed out.
https://hg.mozilla.org/integration/fx-team/rev/0d35326dfbae

https://treeherder.mozilla.org/logviewer.html#?job_id=1418056&repo=fx-team was the new failure mode. The other failures it was hitting were this bug and bug 962248.
(In reply to Drew Willcoxon :adw from comment #159)
> Comment on attachment 8534480 [details] [diff] [review]
> fix browser_934951_zoom_in_toolbar.js to use a mutation observer to wait for
> a label change,
> 
> Review of attachment 8534480 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> Looks good, just some nits.
> 
> ::: browser/components/customizableui/test/browser_934951_zoom_in_toolbar.js
> @@ +49,1 @@
> >    yield promiseTabLoadEvent(tab1, "about:home");
> 
> It shouldn't be necessary anymore to wait until the page has loaded.  You
> still need to load the page of course, but waiting for load shouldn't be
> necessary because the attribute change should always happen after the page
> load.  We just can't say how long after page load it will take to happen. 
> But there shouldn't be any harm in waiting either, so up to you.

While I would love for this to be true, it really isn't. Unfortunately, mutation observers really couldn't care less if you set an attribute to the same value 500 times - they will tell you about it 500 times.

So actually, because the zoom button code listens for a bunch of events, we change the label a bunch of times, to the same thing, which fires the mutation observer and boom. :-(

I'm going to reland this with the yield back in; Drew, please could you file a followup bug if you think the behaviour of the button itself is wrong here? (I'm not sure how expensive the label setting and/or cps checking is here and if/how we can do better)
Then I realized that the attribute promise was still going to race with the load promise and so this didn't actually fix anything apart from putting the expectation back on the load to have fully happened, and then doing another event queue cycle (which might still be enough in most cases, but nevermind that for now).
Attachment #8536889 - Flags: review?(adw)
Attachment #8534480 - Attachment is obsolete: true
All green, but let's see if I can get some more 10.8 runs:

remote:   https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=a5f4accf5362
Comment on attachment 8536889 [details] [diff] [review]
fix browser_934951_zoom_in_toolbar.js to use a mutation observer to wait for a label change,

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

Ah.  Thanks, Gijs.  Sorry for the review delay.
Attachment #8536889 - Flags: review?(adw) → review+
https://hg.mozilla.org/mozilla-central/rev/f9cafb3df61a
Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 37
You need to log in before you can comment on or make changes to this bug.