Closed Bug 594821 Opened 14 years ago Closed 13 years ago

Initial paint of browser window delayed compared with 3.6

Categories

(Core :: Web Painting, defect)

x86
Windows 7
defect
Not set
normal

Tracking

()

RESOLVED FIXED
Tracking Status
blocking2.0 --- final+

People

(Reporter: jimm, Assigned: jimm)

References

(Blocks 1 open bug)

Details

(Keywords: perf, regression, Whiteboard: [hardblocker][has patch])

Attachments

(4 files, 2 obsolete files)

This is a spin off from bug 574638.

STR: open a fresh browser window. Note how content renders after the window opens. (The initial content area is white.) 

With 3.6, chrome paints before the window opens, so when the window fades in via the standard window display effect, chrome is already present. On 4.0, the window fades in and then chrome paints, causing a brief white flash.

On faster systems this is hard to notice, but on slower systems, users see a white window for an extended period of time. If you enable the new titlebar button, it's easier to see since the white area extends all the way to the top of the window.

ts for 3.6 and 4.0 on winnt 6.1 match up. So this appears to have something to do with initial paint timing.

Initial testing of some older builds indicates this regressed prior to feb 2010.
Alex, you produced some video captures of our startup experience. Curious if you have anything that shows this. It's fairly obvious if you're looking for it on the latest betas. It appears to be present on early alphas as well.

So far I've only testing on win7, glass enabled.
If it's Win7 only, Bug 535212 might be of Interest.
I've been trying to get this recorded using a free ware screen recorder. Unfortunately when the recorder is running the problem goes away, my guess is it's triggering an earlier paint.
It would be great of someone who can see this could confirm those dates by downloading the zips of the 7th and 8th and test.

http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/2009/10/
Hmm, appears I've got two regressions to deal with. One is my own doing - the jump list module initialization seems to have regressed the delay in painting I tracked down to october of 2009. But disabling that doesn't help the current 4.0 issue.
(In reply to comment #7)
> Hmm, appears I've got two regressions to deal with. One is my own doing - the
> jump list module initialization seems to have regressed the delay in painting I
> tracked down to october of 2009. But disabling that doesn't help the current
> 4.0 issue.

Maybe bug 535212?
(In reply to comment #8)
> (In reply to comment #7)
> > Hmm, appears I've got two regressions to deal with. One is my own doing - the
> > jump list module initialization seems to have regressed the delay in painting I
> > tracked down to october of 2009. But disabling that doesn't help the current
> > 4.0 issue.
> 
> Maybe bug 535212?

Doesn't look like it, appears to be something that landed in may of 2010.
(In reply to comment #9)
> (In reply to comment #8)
> > (In reply to comment #7)
> > > Hmm, appears I've got two regressions to deal with. One is my own doing - the
> > > jump list module initialization seems to have regressed the delay in painting I
> > > tracked down to october of 2009. But disabling that doesn't help the current
> > > 4.0 issue.
> > 
> > Maybe bug 535212?
> 
> Doesn't look like it, appears to be something that landed in may of 2010.

I should add, I can reproduce what you reported in that bug. It's only on the first startup on a fresh profile. I'm looking for delays after the profile has been loaded once.
First time I see it coincides with enabling aero glass in chrome:

http://hg.mozilla.org/mozilla-central/pushloghtml?startdate=5%2F23%2F2010&enddate=5%2F24%2F2010
Attached image screen shots
It's interesting that in my experience, the white rectangle actually covers the minimize/maximize/close buttons at the top of the window, but that doesn't seem to be happening in your screenshots.
(In reply to comment #13)
> Created attachment 473825 [details]
> Example of white window on startup
> 
> It's interesting that in my experience, the white rectangle actually covers the
> minimize/maximize/close buttons at the top of the window, but that doesn't seem
> to be happening in your screenshots.

That makes sense, I have the tab bar enabled, so the content area stops at the system managed titlebar in my shot.
Attached patch skip the initial jumplist update (obsolete) — Splinter Review
This shaves off a little bit of time between window display and the initial paint.
Attachment #473826 - Flags: review?(dao)
crap, sorry Dao. Here's the real patch.
Attachment #473826 - Attachment is obsolete: true
Attachment #473828 - Flags: review?(dao)
Attachment #473826 - Flags: review?(dao)
Attachment #473828 - Attachment is patch: true
(In reply to comment #14)
> (In reply to comment #13)
> > Created attachment 473825 [details] [details]
> > Example of white window on startup
> > 
> > It's interesting that in my experience, the white rectangle actually covers the
> > minimize/maximize/close buttons at the top of the window, but that doesn't seem
> > to be happening in your screenshots.
> 
> That makes sense, I have the tab bar enabled, so the content area stops at the
> system managed titlebar in my shot.

*menu bar
(In reply to comment #17)
> (In reply to comment #14)
> > (In reply to comment #13)
> > > Created attachment 473825 [details] [details] [details]
> > > Example of white window on startup
> > > 
> > > It's interesting that in my experience, the white rectangle actually covers the
> > > minimize/maximize/close buttons at the top of the window, but that doesn't seem
> > > to be happening in your screenshots.
> > 
> > That makes sense, I have the tab bar enabled, so the content area stops at the
> > system managed titlebar in my shot.
> 
> *menu bar

Ah, that makes sense.  What I've noticed is that the length of time the white shows up doesn't seem to be proportional to the number of tabs that FF is restoring, but is somewhat linked to how many installed extensions you have (i.e., with Adblock Plus and Tab Mix Plus installed, the white lasts longer).  Also, it seems to have gotten worse (stays white longer) between the first build with Aero glass enabled (May 24, 2010) and now - compared with a fresh profile with no extensions.

And I can confirm your regression window.  The enabling of glass does seem to be the culprit here.
The timing of extending glass down into the chrome also contributes. The left and right glass window borders change 'texture' when glass is pushed down.
Attachment #473828 - Flags: review?(dao) → review+
blocking2.0: --- → ?
This might be related to something I saw today.

I launched Firefox and immediately locked my system before the ui was displayed (this is extremely easy to duplicate after the initial OS startup). When I came back to my system after a few minutes and unlocked it the ui was completely blank except for the title bar. Mousing over elements caused them to be displayed and minimizing then maximizing caused the entire ui to be displayed.
Rob, that's bug 593674.
Attachment #473828 - Flags: approval2.0?
Comment on attachment 473828 [details] [diff] [review]
[checked in] skip the initial jumplist update

a=beltzner, would be good to report back here with before/after timings of the effect of this patch.
Attachment #473828 - Flags: approval2.0? → approval2.0+
(In reply to comment #22)
> Comment on attachment 473828 [details] [diff] [review]
> skip the initial jumplist update
> 
> a=beltzner, would be good to report back here with before/after timings of the
> effect of this patch.

http://hg.mozilla.org/mozilla-central/rev/ac0f0d30e66a
Attachment #473828 - Attachment description: skip the initial jumplist update → [checked in] skip the initial jumplist update
So, using an hourly with this patch included, the white screen definitely still appears, but for less time (as expected).  I'd say it's ~1/2 of the length of time it used to appear - but it is definitely still noticeable.
(In reply to comment #24)
> So, using an hourly with this patch included, the white screen definitely still
> appears, but for less time (as expected).  I'd say it's ~1/2 of the length of
> time it used to appear - but it is definitely still noticeable.

good to hear we're making some progress.
For me the initial cold boot start is still very much delayed compared to 3.6, but all starts thereafter are about twice as fast as before. I think there still needs to be some improvements to cold starts. Perhaps this is a different bug entirely and not related to initial painting?
(In reply to comment #22)
> Comment on attachment 473828 [details] [diff] [review]
> [checked in] skip the initial jumplist update
> 
> a=beltzner, would be good to report back here with before/after timings of the
> effect of this patch.

Talos Improvement! Ts, Cold MIN Dirty Profile decrease 6.53% on Win7 Firefox
wow!

Improvement! Ts, Cold MED Dirty Profile decrease 36.9% on Win7 Firefox 
Improvement! Ts, Cold MAX Dirty Profile decrease 79.7% on Win7 Firefox 
Improvement! Ts, Cold MIN Dirty Profile decrease 6.53% on Win7 Firefox 
Improvement! Ts, MED Dirty Profile decrease 36.6% on Win7 Firefox 
Improvement! Ts, MAX Dirty Profile decrease 80.1% on Win7 Firefox 
Improvement! Ts, MIN Dirty Profile decrease 5.37% on Win7 Firefox
Shawn, I think you did a lot of work on the favorites db. Curious if you could offer any suggestions on how I could improve the performance of these lookups:

http://mxr.mozilla.org/mozilla-central/source/browser/components/wintaskbar/WindowsJumpLists.jsm#384
(In reply to comment #26)
> For me the initial cold boot start is still very much delayed compared to 3.6,
> but all starts thereafter are about twice as fast as before. I think there
> still needs to be some improvements to cold starts. Perhaps this is a different
> bug entirely and not related to initial painting?

Are you using a hourly? This patch isn't in a nightly yet.
I was wondering the rest of it falls under the bugs like bug 582005 for instance, and browser chrome area now must be waiting for content to do initial paint.
(In reply to comment #30)
> (In reply to comment #26)
> > For me the initial cold boot start is still very much delayed compared to 3.6,
> > but all starts thereafter are about twice as fast as before. I think there
> > still needs to be some improvements to cold starts. Perhaps this is a different
> > bug entirely and not related to initial painting?
> 
> Are you using a hourly? This patch isn't in a nightly yet.

Yes that was the latest hourly, I just got the latest hourly as of current time to be sure. Same result. I am using the .zip version and fresh profile.

Mozilla/5.0 (Windows NT 6.1; WOW64; rv:2.0b7pre) Gecko/20100920 Firefox/4.0b7pre
(In reply to comment #29)
> Shawn, I think you did a lot of work on the favorites db. Curious if you could
> offer any suggestions on how I could improve the performance of these lookups:
> 
> http://mxr.mozilla.org/mozilla-central/source/browser/components/wintaskbar/WindowsJumpLists.jsm#384
Can we do this work asynchronously (as in, are the consumers of those methods OK with that)?
(In reply to comment #33)
> (In reply to comment #29)
> > Shawn, I think you did a lot of work on the favorites db. Curious if you could
> > offer any suggestions on how I could improve the performance of these lookups:
> > 
> > http://mxr.mozilla.org/mozilla-central/source/browser/components/wintaskbar/WindowsJumpLists.jsm#384
> Can we do this work asynchronously (as in, are the consumers of those methods
> OK with that)?

The code currently expects results in real time now, but I'm sure it could be reworked to accumulate the results and then update.
Filed bug 598229 on improving jump list query performance.
I've installed latest hourly (changeset e4fdb23efa33)  on my desktop (i7@3.5Ghz, 6gb, gtx480) system with a much faster CPU, RAM, and HDD than laptop and I have the same experience with a much slower initial cold start. Takes about 3-4 times longer than 3.6, but after initial launch the next start times are near instantaneous.

The actual "paint" delay after the browser window appears is definitely fixed or improved, therefor I think this is a different bug?
(In reply to comment #26)
> For me the initial cold boot start is still very much delayed compared to 3.6,
> but all starts thereafter are about twice as fast as before. I think there
> still needs to be some improvements to cold starts. Perhaps this is a different
> bug entirely and not related to initial painting?

(In reply to comment #36)
> I've installed latest hourly (changeset e4fdb23efa33)  on my desktop
> (i7@3.5Ghz, 6gb, gtx480) system with a much faster CPU, RAM, and HDD than
> laptop and I have the same experience with a much slower initial cold start.
> Takes about 3-4 times longer than 3.6, but after initial launch the next start
> times are near instantaneous.
> 
> The actual "paint" delay after the browser window appears is definitely fixed
> or improved, therefor I think this is a different bug?

This really doesn't play into what we're working on here. Maybe we need a new bug on regressions related to 4.0 beta cold Ts compared to 3.6?
Sounds like it to me, yes.  Ideally with a regression range...
Depends on: 598572
No longer depends on: 598572
Do extensions load before of after the initial paint?
Blocks: slowui
(In reply to comment #40)
> *** Bug 598871 has been marked as a duplicate of this bug. ***

Great screenshots in ^^^.
Blocks: 598229
Bug 598229 is fixed. Any plans to resolve THIS bug?
Assignee: nobody → jmathies
(In reply to comment #43)
> Bug 598229 is fixed. Any plans to resolve THIS bug?

No, we still have the "white background paints before glass" bug to figure out.
I did a quick timing test on a release, non-opt build - 219 msec between the initial wm_showwindow event and the first wm_paint. During this time the user sees "Example of white window on startup". This is way to long.
Attached patch sync paint on show (obsolete) — Splinter Review
This shaves about 60 msec off the initial paint delay.
Attachment #483848 - Flags: review?(roc)
Comment on attachment 483848 [details] [diff] [review]
sync paint on show

http://hg.mozilla.org/mozilla-central/rev/6714a0c929d4
Attachment #483848 - Attachment description: sync paint on show → [checked in] sync paint on show
Comment on attachment 483848 [details] [diff] [review]
sync paint on show

backed out due to paint assertions during reflow. (bug 605163)
Attachment #483848 - Attachment description: [checked in] sync paint on show → sync paint on show
Also caused some pretty hairy Ts regressions :/
(In reply to comment #49)
> Also caused some pretty hairy Ts regressions :/

All of these tests rely on the load event. It would seem none of our startup timing tests include the initial paint of the window. I'm going to work up a new test based on txul that relies on MozAfterPaint to get some numbers. Maybe we can add that to our test suite.

What concerns me here is that we might be pulling a erfectly viable patche due to onload timing regressions that actually improves the user experience.
(In reply to comment #50)
> All of these tests rely on the load event. It would seem none of our startup
> timing tests include the initial paint of the window. I'm going to work up a
> new test based on txul that relies on MozAfterPaint to get some numbers. Maybe
> we can add that to our test suite.
I've always kinda wondered if this was the case.  When running Ts with standalone talos on windows 7, I only ever see a white window pop-up briefly.

> What concerns me here is that we might be pulling a erfectly viable patche due
> to onload timing regressions that actually improves the user experience.
If the test is wrong, the data is useless.  We can easily make the case to take the regression so we start to measure the right thing.
(In reply to comment #51)
> If the test is wrong, the data is useless.  We can easily make the case to take
> the regression so we start to measure the right thing.

Quite. See also: ew.
If we get a load event then it is probably more likely that painting has _not_ happened than that painting has happened because we fire the load event before we unsuppress painting for pages that load quickly enough to not unsuppress earlier (probably most simple pages loaded from disk).
(In reply to comment #50)
> (In reply to comment #49)
> > Also caused some pretty hairy Ts regressions :/
> 
> All of these tests rely on the load event. It would seem none of our startup
> timing tests include the initial paint of the window. I'm going to work up a
> new test based on txul that relies on MozAfterPaint to get some numbers. Maybe
> we can add that to our test suite.

Don't use MozAfterPaint for performance stuff, it fires when we invalidate, not when we paint.
Some initial paint timing turns up some interesting results.

Intial paint of window:

GDI: 18msec
D2D10: 145msec

Time between Show() and the first full paint completed:

GDI/without forced update: 72msec, short white flash
2D/without forced update: 223msec, long white flash

GDI/forced update: 25msec, window paints before displayed
2D/forced update: 144msec, long white flash

Bas is working on acceleration startup delay, so the problems with 2d should be worked out. (I need to track down the bug and mark this one dependent on it.) In addition to that, adding the update on initial show fixes any remaining initial display problems.

So I would like to propose we take this patch and the Txul hit. User experience trumps internal test numbers. (The talos work to include paint in these tests is being tracked by bug 612190.)

Anyone have any issues with this?
Could we fix Txul to include the first paint? That seems like the best solution.
Roc, that's bug 612190.
I think, anyways - as currently stated it doesn't say that.
(In reply to comment #59)
> I think, anyways - as currently stated it doesn't say that.
It also doesn't look like it's being worked on by anyone.
Well, why don't we fix that instead of working around it?

Fixing MozAfterPaint to fire ... after paint would be the best thing to do. Then it would be easy to integrate into the test harness.
(In reply to comment #60)
> (In reply to comment #59)
> > I think, anyways - as currently stated it doesn't say that.
> It also doesn't look like it's being worked on by anyone.

It was just filed a week or so ago. I was planning on looking at it, but blockers are a higher priority I guess..

(In reply to comment #61)
> Well, why don't we fix that instead of working around it?

I don't see how fixing Txul has anything to do with user experience in Fx 4.0. I'm not sure I understand what we're working around here.

> Fixing MozAfterPaint to fire ... after paint would be the best thing to do.
> Then it would be easy to integrate into the test harness.

We could file a new bug on this and have it block bug 612190. Would we block release on this?
(In reply to comment #62)
> (In reply to comment #61)
> > Well, why don't we fix that instead of working around it?
> 
> I don't see how fixing Txul has anything to do with user experience in Fx 4.0.
> I'm not sure I understand what we're working around here.

We're working around the deficiencies of Txul every time we say "oh, Txul is useless because it doesn't measure painting, let's ignore it".

> > Fixing MozAfterPaint to fire ... after paint would be the best thing to do.
> > Then it would be easy to integrate into the test harness.
> 
> We could file a new bug on this and have it block bug 612190. Would we block
> release on this?

Probably not, but if we care about Txul, making it meaningful should be reasonably high priority, IMHO.
Depends on: 613377
(In reply to comment #63)
> Probably not, but if we care about Txul, making it meaningful should be
> reasonably high priority, IMHO.
Well, we care about Txul, and this is a blocker, and if we have to fix Txul to land this, I think it'd make it a blocker.
We don't have to fix Txul to land this, but I'd like to.
Depends on: 612190
(In reply to comment #48)
> Comment on attachment 483848 [details] [diff] [review]
> sync paint on show
> 
> backed out due to paint assertions during reflow. (bug 605163)

Part 1 in bug 562138 defers the call to widget->Show for popup windows until after reflow. That should fix those assertions.
(In reply to comment #66)
> (In reply to comment #48)
> > Comment on attachment 483848 [details] [diff] [review]
> > sync paint on show
> > 
> > backed out due to paint assertions during reflow. (bug 605163)
> 
> Part 1 in bug 562138 defers the call to widget->Show for popup windows until
> after reflow. That should fix those assertions.

Thanks tn, I'll apply that and confirm.
(In reply to comment #67)
> (In reply to comment #66)
> > (In reply to comment #48)
> > > Comment on attachment 483848 [details] [diff] [review]
> > > sync paint on show
> > > 
> > > backed out due to paint assertions during reflow. (bug 605163)
> > 
> > Part 1 in bug 562138 defers the call to widget->Show for popup windows until
> > after reflow. That should fix those assertions.
> 
> Thanks tn, I'll apply that and confirm.

oops, mstange I mean!
Whiteboard: [hardblocker](?) → [softblocker]
roc, I believe this needs to be a hardblocker. This can be very visible, and startup time is a core piece of Firefox 4. I also think (as I mentioned in the platform meeting today) that we should land the patch here without the Talos changes. jimm is going to explain that proposal to dev.tree-management.
Whiteboard: [softblocker] → [hardblocker]
Some current numbers based on testing latest trunk release build:

widget Show() -> completion of first OnPaint():

numbers are - without invalidate/with forced invalidate

GDI tests: 
launch: 65/21
nth window: 43/16

acceleration:
launch: 101/50
nth window: 54/37

--

Txul / Tpaint numbers from twinopen in bug 612190:

GDI:
w/out: 235 / 259
w/invalidation: 247 / 264

acceleration:
w/out: 240 / 280
w/invalidation: 252 / 286

I'm a little disheartened about Tpaint regressing slightly, but the show -> paint improvements are compelling wins.

The original layout assertion from when this first landed isn't occurring for me locally. I've pushed the patch to try to see if it shows up there.
Whiteboard: [hardblocker] → [hardblocker][has patch]
(In reply to comment #70)
> The original layout assertion from when this first landed isn't occurring for
> me locally. I've pushed the patch to try to see if it shows up there.

I'd expect it to happen when opening a menu, for example. Until part 1 in bug 562138 lands again (which probably won't happen for Firefox 4), a workaround would be to skip the synchronous paint in Show for nsWindows with widget type eWindowType_popup.
(In reply to comment #71)
> (In reply to comment #70)
> > The original layout assertion from when this first landed isn't occurring for
> > me locally. I've pushed the patch to try to see if it shows up there.
> 
> I'd expect it to happen when opening a menu, for example. Until part 1 in bug
> 562138 lands again (which probably won't happen for Firefox 4), a workaround
> would be to skip the synchronous paint in Show for nsWindows with widget type
> eWindowType_popup.

That was it! Updated the patch so it only take effect on top level windows.
Attachment #483848 - Attachment is obsolete: true
Attachment #511080 - Flags: review?(roc)
http://hg.mozilla.org/mozilla-central/rev/fc87245c91c0
Status: NEW → RESOLVED
Closed: 13 years ago
Resolution: --- → FIXED
Component: Layout: View Rendering → Layout: Web Painting
You need to log in before you can comment on or make changes to this bug.