Optimize Chrome startup based on data from UMA Sampling Profiler |
|||
Issue descriptionOptimize Chrome startup based on data from UMA Sampling Profiler. While looking at the data from a regression, I noticed a few low hanging fruits we can optimize that will improve start up time. Will use this bug to track these small improvements. Planning to land a few for M55.
,
Sep 30 2016
And another one: https://codereview.chromium.org/2382023003/
,
Sep 30 2016
And one more: https://codereview.chromium.org/2379033004/
,
Sep 30 2016
Planning to land the set of CLs all together early next week, just to see how much they move the needle. (Each one individually is a pretty small gain, but together it should be a reasonable improvement.)
,
Oct 3 2016
And one more: https://codereview.chromium.org/2383893002/ Will land them all on the same day (hopefully today if I can get all the lgtms) so we can see the combined effect in canary. :)
,
Oct 3 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/b62d7d9eec9d9d49d7d2d50bc3fb08f1a4d1880e commit b62d7d9eec9d9d49d7d2d50bc3fb08f1a4d1880e Author: asvitkine <asvitkine@chromium.org> Date: Mon Oct 03 21:15:03 2016 Optimize ShouldLaunchIncognito() since its on the startup path. Sampling profiler data shows this takes 10ms on the startup path, mainly due to querying parental controls. Since we only need to check parental controls if the incognito flag was specified on the command line, the code is refactored to only query them in that case. BUG= 651848 Review-Url: https://codereview.chromium.org/2382023003 Cr-Commit-Position: refs/heads/master@{#422532} [modify] https://crrev.com/b62d7d9eec9d9d49d7d2d50bc3fb08f1a4d1880e/chrome/browser/prefs/incognito_mode_prefs.cc [modify] https://crrev.com/b62d7d9eec9d9d49d7d2d50bc3fb08f1a4d1880e/chrome/browser/prefs/incognito_mode_prefs.h
,
Oct 3 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/5424cce0cb1592d7e5c025417861a1a540bd7569 commit 5424cce0cb1592d7e5c025417861a1a540bd7569 Author: asvitkine <asvitkine@chromium.org> Date: Mon Oct 03 21:54:41 2016 Optimize startup time of notification code by removing unused code. Generating the icon via GetAvatarIcon() can be expensive - according to UMA sampling profiler it takes ~35ms mean time from a recent Windows dev release. Turns out, it's not even used - so this CL simply removes it. Additionally, removes a unit test that stayed around after the code it was testing was removed because it wasn't referenced in any BUILD file: ui/message_center/cocoa/settings_controller_unittest.mm BUG= 651848 Review-Url: https://codereview.chromium.org/2383893002 Cr-Commit-Position: refs/heads/master@{#422550} [modify] https://crrev.com/5424cce0cb1592d7e5c025417861a1a540bd7569/chrome/browser/notifications/message_center_settings_controller.cc [delete] https://crrev.com/6971ec6d658d06cace0a6d873608127a99367aee/ui/message_center/cocoa/settings_controller_unittest.mm [modify] https://crrev.com/5424cce0cb1592d7e5c025417861a1a540bd7569/ui/message_center/fake_notifier_settings_provider.cc [modify] https://crrev.com/5424cce0cb1592d7e5c025417861a1a540bd7569/ui/message_center/notifier_settings.cc [modify] https://crrev.com/5424cce0cb1592d7e5c025417861a1a540bd7569/ui/message_center/notifier_settings.h
,
Oct 3 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/49cf5df2724445f3160b4fdf13a187295abe14fb commit 49cf5df2724445f3160b4fdf13a187295abe14fb Author: asvitkine <asvitkine@chromium.org> Date: Mon Oct 03 22:25:05 2016 Optimize some code in RenderTextHarfbuzz. This was showing up in the UMA callstacks profiler as taking significant time on start up. Turns out, creating and Init'ing the BreakIterator does some icu initialization which is expensive, e.g. ~50ms at the mean from dev UMA users. However, we only ever need the BreakIterator if there's a grapheme run of over 2 characters - which might be uncommon for many users. So this change makes that initialization lazy - only done when we actually need it. BUG= 651848 Review-Url: https://codereview.chromium.org/2379033004 Cr-Commit-Position: refs/heads/master@{#422564} [modify] https://crrev.com/49cf5df2724445f3160b4fdf13a187295abe14fb/ui/gfx/render_text_harfbuzz.cc [modify] https://crrev.com/49cf5df2724445f3160b4fdf13a187295abe14fb/ui/gfx/render_text_harfbuzz.h [modify] https://crrev.com/49cf5df2724445f3160b4fdf13a187295abe14fb/ui/gfx/render_text_unittest.cc
,
Oct 3 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/4417714b419462d698d03a790293818c6cecd81f commit 4417714b419462d698d03a790293818c6cecd81f Author: asvitkine <asvitkine@chromium.org> Date: Mon Oct 03 22:52:08 2016 Move GetNewTabCSS() caching off the startup path. This function appears to take about a mean of 35ms during startup according to UMA sampling profiler data. Also, the current NTP doesn't need this CSS - since this is related to the old local NTP, which currently only powers chrome://apps. This also saves memory used by the generated CSS until the first time it's used. The downside is there will be a delay when loading this css - but given this codepath is only used by chrome://apps page, this seems like a reasonable trade-off. Note: The CSS will still be cached after the first request, since NTPResourceCache caches it and we fetch it from there. No intended functional changes. Expecting to see a 35ms startup improvement in UMA when this lands. BUG= 651848 Review-Url: https://codereview.chromium.org/2381093002 Cr-Commit-Position: refs/heads/master@{#422578} [modify] https://crrev.com/4417714b419462d698d03a790293818c6cecd81f/chrome/browser/ui/webui/theme_source.cc [modify] https://crrev.com/4417714b419462d698d03a790293818c6cecd81f/chrome/browser/ui/webui/theme_source.h [modify] https://crrev.com/4417714b419462d698d03a790293818c6cecd81f/chrome/browser/ui/webui/theme_source_unittest.cc
,
Oct 6 2016
We now have data for 2880 which has the fixes. Results: https://codereview.chromium.org/2383893002 -> GetAvatarIcon goes from 35ms to essentially 0 https://codereview.chromium.org/2379033004 -> BreakIterator::Init goes from 52ms to 18ms https://codereview.chromium.org/2382023003 -> ShouldLaunchIncognito goes from ~8ms to essentially 0 https://codereview.chromium.org/2381093002 -> ThemeSource goes from ~35ms to essentially 0 All of the above were inspected by comparing 55.0.2877.0 canary and 55.0.2880.4 canaries on callstacks dashboard.
,
Oct 6 2016
(And specifically, by typing the above function names into the search field and seeing aggregated time used by time from the very bottom.)
,
Oct 6 2016
I tried to look at UMA histograms to see if the effect is clear there and I didn't see a lot of effect in NonEmptyPaint2 - possibly the metric is too noisy? So I tried to get something more precise - e.g. Startup.BrowserMainRunnerImplInitializeLongTime. In this case, no real effect at 50th percentile, but see clear wins at 75th and 95th percentiles: https://uma.googleplex.com/p/chrome/timeline_v2/?sid=cd79d5974014960b90e03568122d8541 This is just looking at first day of a canary, since we don't have the data yet. So for first day, 75% goes from 2.3s to 2.175s and 95% goes from 11s to 10.5s. Still very limited data though, so I'd like to keep monitoring this to see if this trend continues after a few days.
,
Nov 15 2016
I wanted to go back to see if I can tease out the effect of my optimizations. I looked at 55.0.2877.0 canary and 55.0.2880.4 canaries to match my analysis in comment 10. To focus on one specific change, I picked the ThemeSource optimization and I filtered both callstacks by ComponentLoader::LoadAll - of which ThemeSource was a large chunk before my optimization. SamplingProfiler shows that in 2877 this took 79.4ms mean and in 2880 it became 40.2ms: https://uma.googleplex.com/callstacks?sid=a9deab27efa68621b1ca51286ccb7dae https://uma.googleplex.com/callstacks?sid=442344082c15172e348bf483d8a78cc5 Looks great! But - I picked ComponentLoader::LoadAll for a reason - because there's a histogram (Extensions.LoadAllComponentTime) track this same interval - so this lets us compare sampling profiler data vs. what we see via histograms. And we do see an effect there: https://uma.googleplex.com/timeline_v2/?sid=38b8c4dba64bfdeae64c530c99a8cbcb Looks like a 10ms saving at the 50th percentile and a 200ms (!) saving at the 95th percentile. Actually, more impressive than I expected! (Since this was just one of the four optimizations I landed.) Also, demonstrates that we really want to have percentiles in sampling profiler data. Otherwise, hard to see the effect of optimizations without also having such histograms.
,
Nov 15 2016
Re: the above, we also see the effect in 50th and 75th percentiles of Extensions.ExtensionServiceInitTime: https://uma.googleplex.com/timeline_v2/?sid=6863ea0ad735853b3f53cdb693d8e79d (95th percentile is unfortunately noisy)
,
Nov 15 2016
Cool :), also appears to be visible in Profile.OnLocaleReadyTime and Profile.ProfileImplDoFinalInit which are part of the same stack, but it's lost in noise in Startup.BrowserMessageLoopStartTime.
,
Nov 16 2016
Great, glad to see this help move the needle on startup performance. I've seen other cases of slowness due to high-percentile clients (e.g. issue 632126 ), so adding percentile support to the tool will definitely be useful.
,
Feb 25 2018
Closing per the optimizations done earlier. We can file new bugs for any additional work. |
|||
►
Sign in to add a comment |
|||
Comment 1 by asvitk...@chromium.org
, Sep 30 2016