Add histograms for WebView startup performance |
|||||||||||
Issue descriptionWe'll want this to measure the impact of adding Finch to WebView, which is going to add some work on the critical path.
,
Jun 26 2017
Oh, neat. Where does that data come from? Our internal testing, or out in the wild? If internal, is it only on our devices? As was mentioned in today's meeting, we're interested in the performance of cheap devices with slow flash.
,
Jun 27 2017
Yes, that's internal data from perf bots. I think adding a UMA histogram for this might make a certain amount of sense, if it's possible to log the required information early enough. However I also suspect that there will be a large number of confounding factors and it will be difficult to assess the effect of an individual change of this nature because of the variability associated with real world measurements.
,
Jun 27 2017
> if it's possible to log the required information early enough. All we need is for SystemClock.elapsedRealtime() to work, yes? Then we just save the values until after native initialization. And it looks like the UMA macros do initialization on first use: https://cs.chromium.org/chromium/src/base/metrics/histogram_macros.h?q=UMA_HISTOGRAM%5Cw*TIMES https://cs.chromium.org/chromium/src/base/metrics/histogram.cc?type=cs&q=Histogram::Factory::Build Alexei please correct if I'm wrong. > I also suspect that there will be a large number of confounding factors Granularity might help with the variability; we could time individual startup steps separately.
,
Jun 27 2017
I measured all the functions called from WebViewChromiumFactoryProvider.startChromiumLocked which took more than a few milliseconds (on Nexus 6):
setUpResources - 11 ms
initPlatSupportLibrary - 113 ms
doNetworkInitializations - 31 ms
AwBrowserProcess.start - 169 ms
AwBrowserProcess.handleMinidumpsAndSetMetricsConsent - 20 ms
setWebContentsDebuggingEnabled - 45 ms
new WebStorageAdapter + AwQuotaManagerBridge.getInstance - 46 ms
In WebViewChromiumFactoryProvider.initialize, the only expensive call was AwBrowserProcess.loadLibrary - 1498 ms. (System.loadLibrary("webviewchromium_plat_support") was only 2 ms.)
Given this, I'd put one timer around AwBrowserProcess.loadLibrary; I'd put one around any synchronous file I/O which we introduce for Finch; and I'd put one around WebViewChromiumFactoryProvider.startChromiumLocked (since no single step of startChromiumLocked or AwBrowserProcess.start seems to be way more expensive/interesting than the others).
Am I missing anything?
,
Jun 27 2017
....AwBrowserProcess.loadLibrary is taking 1500ms, ever? What configuration is that? That seems immensely slow and way worse than should ever happen...
,
Jun 27 2017
Paul mentioned (on Nexus 6) in comment #6. Shamu I guess? Paul please share your methodology too.
,
Jun 27 2017
Seems to be caused by is_component_build=true. With is_component_build=false, startChromiumLocked is ~10 ms and AwBrowserProcess.loadLibrary is ~100 ms. I'm surprised how big a difference that makes, and I wouldn't have thought startChromiumLocked would have been affected. Here's how I'm measuring them: https://codereview.chromium.org/2960923002
,
Jun 28 2017
Ah yeah, component builds have immensely slower startup times - that's one of the main reasons we build a single giant library for the shipping config in the first place :) There's orders of magnitude more work to do in a component build: there are tens of thousands of symbols to look up and fix up between the libraries instead of just the ~100 or so symbols from libc/other system libraries in a static build. There's also a lot more random disk IO, because the file isn't mapped in as a single chunk and so prefetching/caching is less effective. On some OS versions and configurations the process of searching for each library to be loaded is also quite slow when there are a lot of libraries, which becomes a quadratic cost, and will also affect loading the platform support library even though it's not part of the APK. Component builds are also slower to actually execute (though by a much less dramatic factor), because the extra PLT indirections to call between components aren't free. So, yeah, don't ever test performance of anything on component builds, but especially not startup where all of these things compound the maximum possible amount :)
,
Jun 28 2017
Does that mean the single libmonochrome.so in a non-component build doesn't require relocation?
,
Jun 28 2017
This is related to, but not the same thing as, applying relocations. There's a certain number of relocation entries in the binary that are references to things in the binary itself: there are the same number of these regardless of whether you use a component build or not, they're just distributed between the binaries in a component build instead of all being in one place. (these are things like vtables and function pointers). There's then a bunch of *extra* entries of a different type which are part of the dynamic symbol resolution process and apply to the PLT and GOT - these are used to reference between libraries. The single library in the non-component build only has a few of these, for the symbols in libc and other system libraries that it imports, and so processing them doesn't take very long. The component build has a huge number in each component for all the symbols it uses that are defined in other components, so this takes way longer.
,
Sep 27 2017
,
Oct 5 2017
Assigning to owner. Please triage as appropriate.
,
May 8 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/38fd382af0d193193f5a3bc7f64eb1e09bd05017 commit 38fd382af0d193193f5a3bc7f64eb1e09bd05017 Author: Changwan Ryu <changwan@google.com> Date: Tue May 08 19:55:17 2018 Add UMAs for webview creation time Android's WebView constructor calls ensureProviderCreated() and then mProvider.init(). In Chromium WebView, this corresponds to WebViewChromiumFactoryProvider constructor and startChromiumLocked(), so we capture the time taken there. And, as noted in WebViewChromium#init(), the real initialization (startYourEngines and thus startChromiumLocked) may be delayed until the first View method is called and View thread can be determined, so skip it when it hasn't started yet. The sum of the two creation times is roughly the creation time contributed by Chromium WebView, but with the following caveats: 1) ensureProviderCreated() may be called earlier in the constructor as View methods can be called in the constructor. 2) This does not capture the time taken in View constructor and View inflation, so this is only a portion of webview creation time. Also, the factory initialization (the first portion) occurs only once, while the provider initialization (the second portion) occurs every time the app creates a webview instance. Since the second portion takes much longer only for the first time, I'm splitting it into 'First' and 'NonFirst'. BUG= 736545 Change-Id: I16ece2c4a1277a2489f5e8f44d157fd5cc35124d Reviewed-on: https://chromium-review.googlesource.com/1041152 Commit-Queue: Changwan Ryu <changwan@chromium.org> Reviewed-by: Bo <boliu@chromium.org> Reviewed-by: Paul Miller <paulmiller@chromium.org> Reviewed-by: Tobias Sargeant <tobiasjs@chromium.org> Reviewed-by: Ilya Sherman <isherman@chromium.org> Reviewed-by: Richard Coles <torne@chromium.org> Cr-Commit-Position: refs/heads/master@{#556937} [modify] https://crrev.com/38fd382af0d193193f5a3bc7f64eb1e09bd05017/android_webview/glue/java/src/com/android/webview/chromium/WebViewChromium.java [modify] https://crrev.com/38fd382af0d193193f5a3bc7f64eb1e09bd05017/android_webview/glue/java/src/com/android/webview/chromium/WebViewChromiumFactoryProvider.java [modify] https://crrev.com/38fd382af0d193193f5a3bc7f64eb1e09bd05017/tools/metrics/histograms/histograms.xml
,
May 8 2018
requesting merge of #15 to M67 - it will help understand finch impact better. There should be almost no production impact of the merge.
,
May 8 2018
The bug is marked as P3 or Feature. It should not be merged as M67 is in beta. Please contact the approriate milestone owner if you have questions. Owners: cmasso@(Android), cmasso@(iOS), kbleicher@(ChromeOS), govind@(Desktop) For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
,
May 8 2018
This bug requires manual review: M67 has already been promoted to the beta branch, so this requires manual review Please contact the milestone owner if you have questions. Owners: cmasso@(Android), cmasso@(iOS), kbleicher@(ChromeOS), govind@(Desktop) For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
,
May 8 2018
,
May 9 2018
Merged as https://chromium-review.googlesource.com/c/chromium/src/+/1050960 (not updated here due to the chromium maintenance)
,
May 14 2018
This issue has been approved for a merge. Please merge the fix to any appropriate branches as soon as possible! If all merges have been completed, please remove any remaining Merge-Approved labels from this issue. Thanks for your time! To disable nags, add the Disable-Nags label. For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
,
May 14 2018
,
May 14 2018
Talked to paulmiller, histogram has data proves it's working - hence marking verified |
|||||||||||
►
Sign in to add a comment |
|||||||||||
Comment 1 by tobiasjs@chromium.org
, Jun 26 2017