Closed Bug 555120 Opened 15 years ago Closed 11 years ago

Intermittent failure in browser_bug441778.js | zoom is retained after sub-document load - Got 1, expected 1.100000023841858

Categories

(Firefox :: General, defect)

defect
Not set
normal

Tracking

()

RESOLVED FIXED
Firefox 24

People

(Reporter: philor, Assigned: adw)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

WINNT 5.2 mozilla-central opt test mochitest-other on 2010/03/25 18:07:11 s: win32-slave05 TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/base/content/test/browser_bug441778.js | zoom is retained after sub-document load - Got 1, expected 1.100000023841858
I wonder if this is related to bug 555224.
Assignee: nobody → rflint
Status: NEW → ASSIGNED
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270230696.1270231530.765.gz WINNT 5.2 mozilla-central opt test mochitest-other on 2010/04/02 10:51:36 s: win32-slave29
OS: Windows Server 2003 → All
Hardware: x86 → All
Whiteboard: [orange]
Timothy, can you recommend someone to look into this? I'm thinking Ryan isn't.
Assignee: rflint → nobody
Flags: needinfo?(tnikkel)
It looks like in the failing cases the zoom before the load can be both 1 and 1.1, so that the zoom value is not updated after the enlarge by the time the test expects it to be. I don't think any specialized knowledge is needed to debug this, just javascript.
Flags: needinfo?(tnikkel)
Gavin or Myk, I see you were involved in writing/reviewing this test. Can you take a look?
Flags: needinfo?(myk)
Flags: needinfo?(gavin.sharp)
Drew's been fixing zoom-related intermittent's recently, maybe he can look into this one!
Flags: needinfo?(myk)
Flags: needinfo?(gavin.sharp)
Assignee: nobody → adw
I've been looking at this today and I don't see anything wrong yet. It may be that a prior test is interfering with this one by triggering a content prefs operation that happens to sometimes finish during this test. Though I looked at prior tests and nothing jumped out. In bug 856595 I'm trying a patch that removes some incorrect (I think) async zoom updates. Maybe it will help here, too.
Something strange has happened here -- the got and expected values have switched over time. The first comment (and the bug title) has "Got 1, expected 1.10...", where as https://bugzilla.mozilla.org/show_bug.cgi?id=555120#c585 has "Got 1.10..., expected 1."
Interesting, I didn't notice that. It's a matter of timing. The test calls enlarge, waits for the content pref to be updated, and then captures the current zoom level to compare it to the zoom later on. Something is causing the zoom to be reset to 1, and there are two interleavings of events in the logs: 1. enlarge() => zoom > 1 2. mystery reset event => zoom == 1 3. enlarge's pref update completes, current zoom captured == 1 4. FullZoom sees the pref update and sets the zoom *again* to match the pref => zoom > 1 5. result: Got > 1, expected 1 1. enlarge() => zoom > 1 2. enlarge's pref update completes, current zoom captured > 1 3. FullZoom sees the pref update and sets the zoom *again* to match the pref => zoom still > 1 4. mystery reset event => zoom == 1 5. result: Got 1, expected > 1 If the way I've described that second interleaving is right, then bug 856595 probably won't help after all (i.e., by removing step 3). Need to figure out the mystery reset event.
Attached patch patchSplinter Review
https://tbpl.mozilla.org/?tree=Try&rev=c6a52dbe7e9f The basic problem is async operations completing and then updating the zoom, clobbering previous zoom updates that happened after those async operation started. That shouldn't happen. This patch fixes that by recording the FullZoom state when async ops start and then checking that state against the current state when they finish. If the states match, then it's OK to update the zoom. The first half of a "state" is the domain of the URI of the selected browser. So if an op finishes but the current domain doesn't match the one when it started, the zoom isn't updated. The second half is an integer token. Whenever FullZoom updates the zoom, it increments this token. So if an async op finishes and sees that the zoom has been updated in the meantime, the zoom isn't updated. There's one case that isn't handled by checking states, which is that when FullZoom changes the zoom and changes a content pref as a result, it should not then observe that very change and update the zoom again to match the pref. This patch makes one other improvement that lets FullZoom get rid of some unnecessary asynchronicity. Whenever ContentPrefService2 mutates the data store, it invalidates related cache entries. That way it's not possible for a consumer to observe prefs that are in the process of becoming out of date. Whereas before a consumer could see such values by accessing the cache, now it'll try to access the cache, not find anything, and then fall back to an async getter method, which will be queued by Storage after the mutation method that's in the process of changing the pref. Consumers can read and write to content prefs without worrying about waiting for operations to finish. This also fixes the other zoom-related orange bug 856595.
Attachment #754063 - Flags: review?(mak77)
Marco, any idea when you might be able to review this? (the review has been pending 11 days) A top orange (bug 856595) is dependent on this. Thanks! :-)
Flags: needinfo?(mak77)
Blocks: 856595
Comment on attachment 754063 [details] [diff] [review] patch Review of attachment 754063 [details] [diff] [review]: ----------------------------------------------------------------- The idea makes sense, tracking state through a global token looks a bit fragile, though it's not something easy to achieve. In future we may evaluate a different architecture enforcing serialization, either through promises or a message queue, though that would introduce other issues related to coalescing the request being under execution with the incoming ones, to avoid unneeded sequential changes. And could also increase the code size a bit. In spite of that, I think this is an acceptable solution.
Attachment #754063 - Flags: review?(mak77) → review+
Flags: needinfo?(mak77)
Status: ASSIGNED → RESOLVED
Closed: 11 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 24
Depends on: 880226
Depends on: 880361
See Also: → 1604236
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: