Closed Bug 856366 Opened 11 years ago Closed 11 years ago

Intermittent browser_privatebrowsing_zoomrestore.js | Zoom level for about:blank should be changed - Didn't expect 1, but got it

Categories

(Firefox :: Private Browsing, defect)

Product:
Firefox
Component:
Private Browsing
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
Firefox 23
Tracking Flags:
Tracking Status
firefox22 --- fixed
firefox23 --- fixed

People

(Reporter: RyanVM, Assigned: adw)

References

Details

(Keywords: intermittent-failure) 

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

Rev4 MacOSX Lion 10.7 mozilla-inbound opt test mochitest-browser-chrome on 2013-03-30 14:39:21 PDT for push 0e7b1dd41868
slave: talos-r4-lion-028

14:47:07     INFO -  TEST-START | chrome://mochitests/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_zoomrestore.js
14:47:07     INFO -  TEST-INFO | chrome://mochitests/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_zoomrestore.js | Console message: OpenGL LayerManager Initialized Succesfully.
14:47:07     INFO -  Version: 2.1 NVIDIA-7.12.9
14:47:07     INFO -  Vendor: NVIDIA Corporation
14:47:07     INFO -  Renderer: NVIDIA GeForce 320M OpenGL Engine
14:47:07     INFO -  FBO Texture Target: TEXTURE_2D
14:47:07     INFO -  1364680027944	Sync.Status	DEBUG	Status.login: error.login.reason.no_username => error.login.reason.no_username
14:47:07     INFO -  1364680027944	Sync.Status	DEBUG	Status.service: service.client_not_configured => service.client_not_configured
14:47:08  WARNING -  TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_zoomrestore.js | Zoom level for about:blank should be changed - Didn't expect 1, but got it
14:47:08     INFO -  Stack trace:
14:47:08     INFO -      JS frame :: chrome://mochikit/content/browser-test.js :: test_isnot :: line 506
14:47:08     INFO -      JS frame :: chrome://mochitests/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_zoomrestore.js :: doTest/onLoad/< :: line 20
14:47:08     INFO -      JS frame :: chrome://browser/content/browser.js :: FullZoom__applySettingToPref/<.handleCompletion< :: line 1714
14:47:08     INFO -      JS frame :: resource://gre/modules/ContentPrefService2.jsm :: safeCallback :: line 769
14:47:08     INFO -      JS frame :: resource://gre/modules/ContentPrefService2.jsm :: cbHandleCompletion :: line 758
14:47:08     INFO -      JS frame :: resource://gre/modules/ContentPrefService2.jsm :: onDone :: line 263
14:47:08     INFO -      JS frame :: resource://gre/modules/ContentPrefService2.jsm :: handleCompletion :: line 635
14:47:08     INFO -      native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0
14:47:08     INFO -  TEST-INFO | chrome://mochitests/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_zoomrestore.js | Console message: OpenGL LayerManager Initialized Succesfully.
14:47:08     INFO -  Version: 2.1 NVIDIA-7.12.9
14:47:08     INFO -  Vendor: NVIDIA Corporation
14:47:08     INFO -  Renderer: NVIDIA GeForce 320M OpenGL Engine
14:47:08     INFO -  FBO Texture Target: TEXTURE_2D
14:47:08     INFO -  1364680028506	Sync.Status	DEBUG	Status.login: error.login.reason.no_username => error.login.reason.no_username
14:47:08     INFO -  1364680028506	Sync.Status	DEBUG	Status.service: service.client_not_configured => service.client_not_configured
14:47:08     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_zoomrestore.js | Zoom level for about:privatebrowsing should be reset
14:47:09     INFO -  INFO TEST-END | chrome://mochitests/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_zoomrestore.js | finished in 1417ms
OS: Mac OS X → All
Hardware: x86_64 → All
Going out on a limb that bug 829456 regressed this.
Blocks: 829456
Assignee: nobody → adw
Status: NEW → ASSIGNED
Pushed a bunch of logging to try.  Guess I'll keep rerunning tests until there's a failure.  https://tbpl.mozilla.org/?tree=Try&rev=c5ce93974cf2

Worst case, the test could be rewritten slightly not to assume the zoom level of the freshly loaded about:blank is 1.  That would probably fix the random failure, but it wouldn't fix whatever's causing it not to be 1.  It should be 1.

Looking at this, I noticed there's a problem with content pref observers.  Observers are notified when prefs change, but they aren't told if changes took place in the temporary private-browsing store or the normal permanent store.  FullZoom could hypothetically get tripped up by that (e.g., by applying a zoom level that changed in a PB window to a page outside of PB), but I don't think that's the problem here.
It's just not failing on try.

So I landed this change on inbound instead.  It does what comment 7 says -- it makes the test not assume the initial zoom is 1.  That should fix the failure, but the underlying problem is still there, so I also added some logging to the test.  I doubt it's enough to be helpful though.  I'll probably have to add debug-build logging to browser-fullZoom.js...

https://hg.mozilla.org/integration/mozilla-inbound/rev/98b7ab4fa80f
That didn't work, but the logging helped.  0 for 2.

The initial zoom is 1, but after FullZoom.enlarge, the zoom is still 1.  Is the enlarge just not working?  Is there some other async thing happening that sets the zoom after the enlarge finishes changing it but before it can call the callback?
OK, I think I may know what's happening.  FullZoom.onLocationChange is called as the result of the about:blank location change (by browser.js).  onLocationChange calls _applyPrefToSetting, which calls _getGlobalValue.  Because the test opened a new browser chrome window, FullZoom has not had a chance to cache the global zoom level value, so _getGlobalValue has to call cps2.getGlobal, which is async.  When that's done, the page's zoom is then set to 1, since there is no global value.

But the test doesn't wait for any of that to happen.  It only waits for page load.  So there are some runs where the zoom is set to 1 as described above between the time the test calls FullZoom.enlarge (also async) and the time it checks the zoom that's supposed to be enlarged.

I had to update a bunch of other tests to wait for onLocationChange's zoom set, so it's not surprising this test is failing this way, if I'm right.

https://hg.mozilla.org/integration/mozilla-inbound/rev/198a12d4affe
https://hg.mozilla.org/mozilla-central/rev/98b7ab4fa80f
https://hg.mozilla.org/mozilla-central/rev/198a12d4affe

No occurrences since this landing!
Status: ASSIGNED → RESOLVED
Closed: 11 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Target Milestone: --- → Firefox 23
You need to log in before you can comment on or make changes to this bug.