New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 736545 link

Starred by 1 user

Issue metadata

Status: Verified
Owner:
Closed: May 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Android
Pri: 2
Type: Task

Blocking:
issue 678288
issue 817644



Sign in to add a comment

Add histograms for WebView startup performance

Project Member Reported by paulmiller@chromium.org, Jun 23 2017

Issue description

We'll want this to measure the impact of adding Finch to WebView, which is going to add some work on the critical path.
 
Cc: tobiasjs@chromium.org
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.
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.

Comment 4 Deleted

> 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.
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?

Comment 7 by torne@chromium.org, Jun 27 2017

....AwBrowserProcess.loadLibrary is taking 1500ms, ever? What configuration is that? That seems immensely slow and way worse than should ever happen...

Comment 8 by sgu...@chromium.org, Jun 27 2017

Paul mentioned (on Nexus 6) in comment #6. Shamu I guess? Paul please share your methodology too.
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

Comment 10 by torne@chromium.org, 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 :)
Does that mean the single libmonochrome.so in a non-component build doesn't require relocation?

Comment 12 by torne@chromium.org, 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.
Cc: -sgu...@chromium.org
Status: Assigned (was: Untriaged)
Assigning to owner. Please triage as appropriate.
Project Member

Comment 15 by bugdroid1@chromium.org, 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

Cc: cma...@chromium.org
Components: Mobile>WebView>Perf
Labels: -Pri-3 Merge-Request-67 M-68 Pri-2
Owner: changwan@chromium.org
Status: Started (was: Assigned)
requesting merge of #15 to M67 - it will help understand finch impact better. There should be almost no production impact of the merge.
Project Member

Comment 17 by sheriffbot@chromium.org, May 8 2018

Labels: -Merge-Request-67 Merge-Reject-67 Hotlist-Merge-Reject
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
Blocking: 678288 817644
Labels: -Type-Feature -Hotlist-Merge-Reject -Merge-Reject-67 Merge-Request-67 Type-Task
Feature is a big name for UMA. Changing to task and trying again.
Project Member

Comment 19 by sheriffbot@chromium.org, May 8 2018

Labels: -Merge-Request-67 Merge-Review-67 Hotlist-Merge-Review
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
Labels: -Hotlist-Merge-Review -Merge-Review-67 Merge-Approved-67 M-67
Labels: Merge-Merged
Status: Fixed (was: Started)
Merged as https://chromium-review.googlesource.com/c/chromium/src/+/1050960 (not updated here due to the chromium maintenance)
Project Member

Comment 22 by sheriffbot@chromium.org, 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
Labels: -Merge-Approved-67
Status: Verified (was: Fixed)
Talked to paulmiller, histogram has data proves it's working - hence marking verified

Sign in to add a comment