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

Issue 838702 link

Starred by 3 users

Issue metadata

Status: Verified
Owner:
Closed: Jul 3
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Android
Pri: 2
Type: Bug

Blocked on:
issue 849907

Blocking:
issue 817644



Sign in to add a comment

8 ms block unaccounted for during webviewchromium.init

Project Member Reported by ntfschr@chromium.org, May 1 2018

Issue description

See crbug.com/817644#c17.

It's possible that support library callbacks impact startup time, even when the support library is not in use. We should investigate if this is indeed true, or if something else is responsible for the ~8 ms block Changwan observed.

If support library is the culprit, we switch this to lazy initialization, and pay the cost during the first support-lib callback. Specifically, the cost would be paid during the first call to isFeatureAvailable().
 

Comment 1 Deleted

Most reflection work happens during setWebViewClient [1]. My local experiments show this is ~0.5 ms long, which is not as much as the suspicious 8 ms block. We call the method twice overall, but that still only totals 1 ms--it's not obvious that this is the culprit.

Per crbug.com/817644#c16, the 8 ms block isn't visible in local runs. So, I'll add a trace event to gather data from the bot.

[1] https://cs.chromium.org/chromium/src/android_webview/support_library/callback/java/src/org/chromium/support_lib_callback_glue/SupportLibWebViewContentsClientAdapter.java?l=42&rcl=e64312366bcee51fdcee5704c41bc091242cea1e
Project Member

Comment 3 by bugdroid1@chromium.org, May 2 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/e85948284c319555f981a15b6038b73a159446a8

commit e85948284c319555f981a15b6038b73a159446a8
Author: Nate Fischer <ntfschr@chromium.org>
Date: Wed May 02 19:11:37 2018

AW: add a systrace for support library startup

No change to logic, this only adds a systrace event to log startup
performance in the support library. This doesn't appear to be an issue
in local benchmarks, but the bot may perform differently.

Bug:  838702 
Test: N/A
Change-Id: Idde301b3e620e7ca13e779ac35f08338c58910df
Reviewed-on: https://chromium-review.googlesource.com/1039154
Reviewed-by: Changwan Ryu <changwan@chromium.org>
Commit-Queue: Nate Fischer <ntfschr@chromium.org>
Cr-Commit-Position: refs/heads/master@{#555498}
[modify] https://crrev.com/e85948284c319555f981a15b6038b73a159446a8/android_webview/support_library/callback/java/src/org/chromium/support_lib_callback_glue/SupportLibWebViewContentsClientAdapter.java

Summary: 8 ms block unaccounted for during webviewchromium.init (was: Investigate support library callbacks startup time)
I took a look at this on the bot [1]. The support lib (and the entire WebViewContentsClientAdapter constructor) seems insignificant (~0.204 ms for Point ID 555771). Given that support lib isn't to blame for the majority of the 8 ms block, I'm changing the issue title.

Some more ideas for what this could be:

 - is privateBrowsing on? If so, we do some extra work [2]
 - maybe checkThread is surprisingly expensive? [3]
 - ??? (if not any of the above, then I'm really confused why this happens)

[1] https://chromeperf.appspot.com/report?sid=5ae87c41efb3d436419396e0551577a6e5bb1dc9544c55bf0e2881db28ed54be
[2] https://cs.chromium.org/chromium/src/android_webview/glue/java/src/com/android/webview/chromium/WebViewChromium.java?l=153&rcl=d8de8d344e4ae611abcf5178b4bef8d84f4911fb
[3] https://cs.chromium.org/chromium/src/android_webview/glue/java/src/com/android/webview/chromium/WebViewChromium.java?rcl=d8de8d344e4ae611abcf5178b4bef8d84f4911fb&l=173

Comment 5 by torne@chromium.org, May 4 2018

privateBrowsing is never on - this feature was removed in K, nobody uses it.

Comment 6 by torne@chromium.org, May 4 2018

Is startYourEngines already covered by other tracing? because that's going to be the expensive thing here..
This particular block sits between startYourEngines (pink block, labeled in the attached screenshot) & createWebViewContentsClientAdapter (tiny green block before WebViewChromium.ContentSettingsAdapter).

Ruling out private browsing leaves a few (unlikely) suspects:

1. checkThread: Looking carefully at the screenshot, one can see a tiny pink line next to the "m" in "7.329 ms", which indicates obtaining a lock. This almost certainly happens during checkThread (it's this lock [1]). So, checkThread starts near the beginning of the block, but perhaps it takes longer than expected to finish.

2. targetSdkVersion comparisons [2]: mAppTargetSdkVersion is a final int, so I can't believe these comparisons are expensive.

3. Stuff between invoking createWebViewContentsClientAdapter and when we reach this line [3]: this comprises a method call, an instantiation (& class load), and setting a few member variables.

All 3 suspects seem pretty unlikely, but checkThread and createWebViewContentsClientAdapter are probably good places to start investigation.

[1] https://cs.chromium.org/chromium/src/base/android/java/src/org/chromium/base/ThreadUtils.java?l=55&rcl=dc62670454cc8c1d7ada88138a72e569ddd898cb
[2] https://cs.chromium.org/chromium/src/android_webview/glue/java/src/com/android/webview/chromium/WebViewChromium.java?l=180-191&rcl=d8de8d344e4ae611abcf5178b4bef8d84f4911fb
[3] https://cs.chromium.org/chromium/src/android_webview/glue/java/src/com/android/webview/chromium/WebViewContentsClientAdapter.java?l=146&rcl=273cdb49969d456395639b98a05dfae3061a247b
Screenshot from 2018-05-04 14-07-18.png
96.0 KB View Download
Project Member

Comment 8 by bugdroid1@chromium.org, May 8 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/860cf328b47554f5c004b909ec1176b2004aee4a

commit 860cf328b47554f5c004b909ec1176b2004aee4a
Author: Nate Fischer <ntfschr@chromium.org>
Date: Tue May 08 17:38:31 2018

AW: add more startup traces within WebViewChromium.init

This adds more startup traces inside WebViewChromium.init, with the goal
of identifying what is responsible for the 8 ms chunk of unaccounted
work.

Because there is no obvious suspect for such a long duration of time,
this adds a couple different logs:

 * Invoking createWebViewContentsClientAdapter (intentionally logged
   outside the body of the method, to measure Class loading)
 * checkThread

Bug:  838702 
Test: N/A
Change-Id: Ic3029d897f66ddad09cf0c41d49689fdf7833d5a
Reviewed-on: https://chromium-review.googlesource.com/1048485
Commit-Queue: Nate Fischer <ntfschr@chromium.org>
Reviewed-by: Changwan Ryu <changwan@chromium.org>
Cr-Commit-Position: refs/heads/master@{#556857}
[modify] https://crrev.com/860cf328b47554f5c004b909ec1176b2004aee4a/android_webview/glue/java/src/com/android/webview/chromium/WebViewChromium.java

According to the latest trace, invoking WebViewChromiumFactoryProvider.createWebViewContentsClientAdapter takes 7.6 ms, and only the final 1.97 ms is for the "WebViewContentsClientAdapter.constructor" trace (note: this is not the entirety of the constructor).

So, we need to dive deeper into this block:

 * is it expensive to invoke createWebViewContentsClientAdapter?
 * is it expensive to load the WebViewContentsClientAdapter class? To invoke its constructor?
 * are the beginning lines [1] of the constructor surprisingly expensive?

[1] https://cs.chromium.org/chromium/src/android_webview/glue/java/src/com/android/webview/chromium/WebViewContentsClientAdapter.java?l=135-145&rcl=f57e1c35076dedd3a90ab55adae20772404b6702
Project Member

Comment 10 by bugdroid1@chromium.org, May 10 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/998efe38db19486bb8d4b89c520020ba6ddf96bf

commit 998efe38db19486bb8d4b89c520020ba6ddf96bf
Author: Nate Fischer <ntfschr@chromium.org>
Date: Thu May 10 23:08:48 2018

AW: add even more startup traces for 8ms gap

This CL adds even more startup traces to diagnose what causes the 8 ms
gap. My main suspicion is that this is caused by class-loading
WebViewContentsClientAdapter (locally, I see a 0.5 ms gap between the
start of insideCreateWebViewContentsClientAdapter &
beginningOfConstructor).

The goal is to land these on trunk and view the bot to see what takes
the majority of the time. Then we can look into optimizing this.

Bug:  838702 
Test: run benchmark locally, observe the events are logged.
Change-Id: Id1976e80e69dbb1073ed2197b60ca0652ad15356
Reviewed-on: https://chromium-review.googlesource.com/1054637
Reviewed-by: Changwan Ryu <changwan@chromium.org>
Commit-Queue: Nate Fischer <ntfschr@chromium.org>
Cr-Commit-Position: refs/heads/master@{#557720}
[modify] https://crrev.com/998efe38db19486bb8d4b89c520020ba6ddf96bf/android_webview/glue/java/src/com/android/webview/chromium/WebViewChromiumFactoryProvider.java
[modify] https://crrev.com/998efe38db19486bb8d4b89c520020ba6ddf96bf/android_webview/glue/java/src/com/android/webview/chromium/WebViewContentsClientAdapter.java

Cc: torne@chromium.org
Update: the vast majority of this time is taken up between "WebViewChromiumFactoryProvider.insideCreateWebViewContentsClientAdapter" and "WebViewContentsClientAdapter.beginningOfConstructor". That means that it's extremely expensive to invoke the WebViewContentsClientAdapter constructor.

Interesting observations:

 1. There's a ~4ms chunk before a section called "Lock contention on ClassLinker classes lock." Torne, do you know what this means?
 2. There's a ~7ms chunk after the lock contention. I assume this is the actual class loading work.

The exact trace I'm looking at is here [1].

[1] https://00e9e64bac86f881e5a179aed06c1f44d756e03ed6e23bd39f-apidata.googleusercontent.com/download/storage/v1/b/chrome-telemetry-output/o/load_chrome_blank_2018-05-16_14-07-04_54309.html?qk=AD5uMEtxjNqnKeheKDhl-vnnti54MpjiX-6-15OJaJ6zTyNnLp8-ZGUBM-HYJZzwxpcSRNT3DJTllE9pJypJJpyUwgfQAmGTL3rkeoT-ZZLE6SLKiSjx37sSqmhO5-F1p-AcFgd29dsbzX2-V9rgtG-EA0sDzX9CrV4ji8LGPJkI4JUeWVp1AiHS1W45_EdQwBer4IOYbnuHud74Q8ihkzeehlMdDptdw2w3JIIPyG02CO0peSTiz9fV5fAl-H1JwCFpoMAQnMnDLoNxjO4BMguTfeo2NGn4eDF6WsPeuefONV2LEKzu89DI-ytJQLKxU18IKkXsUZjfLT6VooLV7C6iA5hJXtg1yU7X6dulpEIJSiMpir5ioOXXmbDobwXXT69ZZUSWjjXHQRZLqcDmVgogfehMl4fS3hY6FmQ1vrnVGN5kqPqW0xhJbQ-B1mHEIUWLS_q_o9uvi-Y7mCUIeF35aatFonjaNwN6Yu0bXvHDZToi61tp3fKr-qCNlflOrmbx9-1siUW_8Sn4XH9T6SfhJLc8QYJyFKGdLq7mk6F0sEuZH1eGZC3OolcDdfZJjtR4rKtA_5kEw3LzLDwevlRU31OQuIWuuFgYK1Pyw6ROQqOEtceGGmbO-h4MKR9GCqbjc7LHvwwOfNgy6n4C-dm3F6IjhERGHJTwaMSYzGMWM-GpO9v46A7CR1htRO7_IoUiYWrzZN1sQQGu8v4kFULGdNUKF5AcGKWU-FNJvY81pJ--IzxhwZ9JHnCxGzolIvT8tj1cyhzPr5iGEg7CsEmzjD0pPcwcAv4Vv0hEofAKdwoFCaNu55U
Some theories I have:

1) Since WebViewContentsClientAdapter is derived from AwContentsClient, and WebViewContentsClientAdapter's constructor never calls super constructor, AwContentsClient's no-arg constructor gets called.
2) Looper.getLooper() gets called.
3) AwContentsClientCallbackHelper is created and calls "new MyHandler".

Still not clear why these should take a long time,

but would it help if we add more trace events?
Project Member

Comment 13 by bugdroid1@chromium.org, May 25 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/31eb8c6cbe0306d6df5af1f3afa155681459f221

commit 31eb8c6cbe0306d6df5af1f3afa155681459f221
Author: Nate Fischer <ntfschr@chromium.org>
Date: Fri May 25 22:32:26 2018

AW: startup traces for AwContentsClient and Helper

No change to logic.

This adds startup traces to track how long it takes to invoke the
constructors of AwContentsClient and AwContentsClientCallbackHelper.

These are both called as part of the work for instantiating the
WebViewContentsClientAdapter.

Bug:  838702 
Test: N/A
Change-Id: Id04cde3f65d18522893c1bc82621a0740242962b
Reviewed-on: https://chromium-review.googlesource.com/1073915
Commit-Queue: Nate Fischer <ntfschr@chromium.org>
Reviewed-by: Changwan Ryu <changwan@chromium.org>
Cr-Commit-Position: refs/heads/master@{#562039}
[modify] https://crrev.com/31eb8c6cbe0306d6df5af1f3afa155681459f221/android_webview/java/src/org/chromium/android_webview/AwContentsClient.java
[modify] https://crrev.com/31eb8c6cbe0306d6df5af1f3afa155681459f221/android_webview/java/src/org/chromium/android_webview/AwContentsClientCallbackHelper.java

Everything is outside of (before) the AwContentsClient constructor. This could indicate that the expensive operation is classloading either WebViewContentsClientAdapter or AwContentsClient.

I will double check that this cannot repro locally (in an AOSP build). If that's the case, then I'll chalk this up to ART weirdness.

We might also want to measure this time chunk with UMA--do real users see ~8ms or do real-world results reflect what we see locally?

Comment 15 by torne@chromium.org, May 29 2018

We should probably talk with the ART folks a bit again about what the current state of how this is all expected to behave is (especially wrt. AOT optimisation because if that's not reliably happening in all our test cases then a lot of our measurements are unrealistic)
Re #14 - sounds like a good plan. Also, you could try some random changes on Pinpoint to understand this better.
I can't get useful benchmark results on AOSP P. I'll flash to AOSP Oreo and try again tomorrow.
I got a local run on AOSP O, and it says the region is taken up by "Verify class". This runs for 12 ms in this local run, so I think that's the culprit.

If this involves verifying WebViewContentsClientAdapter, issue 791099 (logspam from class verifier work) may be a partial explanation (due to the verification work, not the logspam itself).

I tested this theory by removing the bodies of shouldOverrideUrlLoading, onSafeBrowsingHit, onRenderProcessGone. I saw a huge improvement (14 ms -> 1 ms).
load_chrome_blank_2018-05-30_12-26-59_75690.html
5.5 MB View Download

Comment 19 by torne@chromium.org, May 30 2018

Well we should have been working on fixing issue 791099 already anyhow.. I guess we fix that and see waht changes.
Cc: jamwalla@chromium.org
This is a great finding!
The trace from comment #18 only shows 1 VerifyClass TraceEvent. However, I took a trace on N_MR2 (see attachment), and I consistently see 6 VerifyClass events:

 1. WebViewFactory.getProvider > providerClass.newInstance > VerifyClass (0.774 ms)
 2. createWebViewContentsClientAdapter > insideCreateWebViewContentsClientAdapter > VerifyClass (7.278 ms)
 3. initForReal > AwContents.constructor > ... (there are actually 3 VerifyClass events under this event)
    a. 1st VerifyClass (1.524 ms)
    b. 2nd VerifyClass (0.547 ms)
    c. 3rd VerifyClass (0.964 ms)
 4. AwBrowserProcess.start > startBrowserProcessesSync > VerifyClass (0.398 ms)

#2 is the subject of this bug. I think we should also investigate at least 1, 3a, and 3c. I did 5 runs, and the values I listed above are representative.

---

I have not had success running the benchmark on L, so I don't have data from that. I haven't tried running on M yet.
load_chrome_blank_2018-05-31_18-32-22_60865.html
5.1 MB View Download
crrev/c/1081081 fixes this block of time on Oreo. Testing locally, I found that removing class verification from onSafeBrowsingHit removes the VerifyClass trace event in the benchmark, and brings down the wall time of insideCreateWebViewContentsClientAdapter from ~10ms to ~1ms.

That's just for O, but the same approach should work for classes that affect N and below.
Blockedon: 849907
Project Member

Comment 24 by bugdroid1@chromium.org, Jun 7 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/dfa36b754ac04a837a06d54924e6f63cb6b91686

commit dfa36b754ac04a837a06d54924e6f63cb6b91686
Author: James Wallace-Lee <jamwalla@chromium.org>
Date: Thu Jun 07 23:05:47 2018

Avoid class verification for RenderProcessGoneDetail in WebViewContentsClientAdapter

This adds the Utility class ApiHelperForO. It moves references to
RenderProcessGoneDetail, which was added in O, into a separate class. On
pre-O devices, this reduces log spam caused by a NoClassDefFoundError.
It also improves startup time.

Bug: 791099,  838702 
Test: adb logcat | grep 'Failed resolution of'
Test: run_webview_instrumentation_test_apk -f org.chromium.android_webview.test.AwContentsClientOnRenderProcessGoneTest#*
Change-Id: Iee47d5d5553b6eb339123fbea238dcbf9969de49
Reviewed-on: https://chromium-review.googlesource.com/1089477
Commit-Queue: James Wallace-Lee <jamwalla@chromium.org>
Reviewed-by: Nate Fischer <ntfschr@chromium.org>
Reviewed-by: Bo <boliu@chromium.org>
Cr-Commit-Position: refs/heads/master@{#565451}
[modify] https://crrev.com/dfa36b754ac04a837a06d54924e6f63cb6b91686/android_webview/glue/BUILD.gn
[add] https://crrev.com/dfa36b754ac04a837a06d54924e6f63cb6b91686/android_webview/glue/java/src/com/android/webview/chromium/ApiHelperForO.java
[modify] https://crrev.com/dfa36b754ac04a837a06d54924e6f63cb6b91686/android_webview/glue/java/src/com/android/webview/chromium/WebViewContentsClientAdapter.java

The latest bot runs still have the 8 ms block, so I think we have more class verification work left. I think the last thing to clean-up is WebResourceError (added in API 23).
I was mistaken in comment#25. I need to move N-specific bits of shouldOverrideUrlLoading into ApiHelperForN.java in order to fix the startup delay.

However, we still need to move WebResourceError eventually. This almost certainly causes the startup delay on L (but I'm still blocked by issue 849907, so I can't be 100% certain the class verifier causes a delay).
Project Member

Comment 27 by bugdroid1@chromium.org, Jun 13 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/2ad7180f4915ce69643a9db7a358334320318ba5

commit 2ad7180f4915ce69643a9db7a358334320318ba5
Author: James Wallace-Lee <jamwalla@chromium.org>
Date: Wed Jun 13 20:11:47 2018

Avoid class verification on WebView startup for M and below

This add the utility class ApiHelperForN. It moves references to
ServiceWorkerControllerAdapter and TokenBindingManagerAdapter, which
were added in N, into the separate class. On pre-N devices, this reduces
log spam caused by a NoClassDefFoundError. It also improves startup
time.

org.chromium.android_webview.test.AwServiceWorkerClientTest#.

Bug: 791099,  838702 
Test: adb logcat | grep 'Failed resolution of'
Test: run_webview_instrumentation_test_apk -f
Change-Id: I519075e03bee8c04a3f03a3ff3d316e1473dcc31
Reviewed-on: https://chromium-review.googlesource.com/1098225
Reviewed-by: Bo <boliu@chromium.org>
Reviewed-by: Nate Fischer <ntfschr@chromium.org>
Commit-Queue: James Wallace-Lee <jamwalla@chromium.org>
Cr-Commit-Position: refs/heads/master@{#566966}
[modify] https://crrev.com/2ad7180f4915ce69643a9db7a358334320318ba5/android_webview/glue/BUILD.gn
[add] https://crrev.com/2ad7180f4915ce69643a9db7a358334320318ba5/android_webview/glue/java/src/com/android/webview/chromium/ApiHelperForN.java
[modify] https://crrev.com/2ad7180f4915ce69643a9db7a358334320318ba5/android_webview/glue/java/src/com/android/webview/chromium/WebViewChromiumAwInit.java
[modify] https://crrev.com/2ad7180f4915ce69643a9db7a358334320318ba5/android_webview/glue/java/src/com/android/webview/chromium/WebViewChromiumFactoryProvider.java
[modify] https://crrev.com/2ad7180f4915ce69643a9db7a358334320318ba5/android_webview/glue/java/src/com/android/webview/chromium/WebViewContentsClientAdapter.java

Project Member

Comment 28 by bugdroid1@chromium.org, Jun 15 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/85f76de769d5687512592f95733eedd7e6f55b8a

commit 85f76de769d5687512592f95733eedd7e6f55b8a
Author: James Wallace-Lee <jamwalla@chromium.org>
Date: Fri Jun 15 19:52:24 2018

Avoid class verification on WebView startup for Lollipop

This adds utility classes ApiHelperForM in android_webview/glue and
content/browser/selection. It moves references to
WebResourceErrorAdapter and FloatingActionModeCallback into these
utility classes. On L devices, this reduces logspam caused by class
verification on startup.

Bug: 791099,  838702 
Test: adb logcat | grep 'Rejecting re-init on previously-failed class'
Change-Id: I3c5f096d58fbe710c6429f48b8cc11268683af0d
Reviewed-on: https://chromium-review.googlesource.com/1100048
Commit-Queue: James Wallace-Lee <jamwalla@chromium.org>
Reviewed-by: Bo <boliu@chromium.org>
Reviewed-by: Nate Fischer <ntfschr@chromium.org>
Cr-Commit-Position: refs/heads/master@{#567771}
[modify] https://crrev.com/85f76de769d5687512592f95733eedd7e6f55b8a/android_webview/glue/BUILD.gn
[add] https://crrev.com/85f76de769d5687512592f95733eedd7e6f55b8a/android_webview/glue/java/src/com/android/webview/chromium/ApiHelperForM.java
[modify] https://crrev.com/85f76de769d5687512592f95733eedd7e6f55b8a/android_webview/glue/java/src/com/android/webview/chromium/WebViewContentsClientAdapter.java
[modify] https://crrev.com/85f76de769d5687512592f95733eedd7e6f55b8a/content/public/android/BUILD.gn
[add] https://crrev.com/85f76de769d5687512592f95733eedd7e6f55b8a/content/public/android/java/src/org/chromium/content/browser/ApiHelperForM.java
[modify] https://crrev.com/85f76de769d5687512592f95733eedd7e6f55b8a/content/public/android/java/src/org/chromium/content/browser/selection/FloatingActionModeCallback.java
[modify] https://crrev.com/85f76de769d5687512592f95733eedd7e6f55b8a/content/public/android/java/src/org/chromium/content/browser/selection/SelectionPopupControllerImpl.java

Hmm this doesn't seem to yet be fixed on the dashboard: https://goo.gl/9aapn9. I'll try the latest canary on my M device locally.
Project Member

Comment 30 by bugdroid1@chromium.org, Jun 23 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/428de580e17420d12298e3b482011a5b77fad71b

commit 428de580e17420d12298e3b482011a5b77fad71b
Author: Nate Fischer <ntfschr@chromium.org>
Date: Sat Jun 23 00:03:36 2018

AW: do not allow proguard to optimize ApiHelper classes

We recently introduced a series of ApiHelperFor* classes to help us
ensure the WebView APK's classes pass compile-time verification in order
to avoid runtime verification (which causes logspam and startup
penalties). However, proguard was inlining these classes in our release
builds, which re-introduced the class verification issues.

This adds an annotation to prevent inlining. The @DoNotInline
annotation is used to configure Proguard.

R=torne@chromium.org

      (tested on L,M,NMR1 with standalone webview and monochrome)
      android-webview-google -v --pageset-repeat=1
      (no startup penalty on L device)
      "StatusRetryVerificationAtRuntime" (ensure the fixed classes no
      longer show up)

Bug: 791099
Bug:  838702 
Test: adb logcat | grep 'Failed resolution of'
Test: tools/perf/run_benchmark system_health.webview_startup --browser \
Test: use oatdump after installing APK. Then, grep for
Change-Id: I7e85718916313f03287e5f2d5fe8f51a02661f11
Reviewed-on: https://chromium-review.googlesource.com/1109464
Reviewed-by: Richard Coles <torne@chromium.org>
Reviewed-by: Bo <boliu@chromium.org>
Reviewed-by: agrieve <agrieve@chromium.org>
Commit-Queue: Nate Fischer <ntfschr@chromium.org>
Cr-Commit-Position: refs/heads/master@{#569848}
[modify] https://crrev.com/428de580e17420d12298e3b482011a5b77fad71b/android_webview/glue/java/src/com/android/webview/chromium/ApiHelperForM.java
[modify] https://crrev.com/428de580e17420d12298e3b482011a5b77fad71b/android_webview/glue/java/src/com/android/webview/chromium/ApiHelperForN.java
[modify] https://crrev.com/428de580e17420d12298e3b482011a5b77fad71b/android_webview/glue/java/src/com/android/webview/chromium/ApiHelperForO.java
[modify] https://crrev.com/428de580e17420d12298e3b482011a5b77fad71b/android_webview/glue/java/src/com/android/webview/chromium/ApiHelperForOMR1.java
[modify] https://crrev.com/428de580e17420d12298e3b482011a5b77fad71b/base/BUILD.gn
[add] https://crrev.com/428de580e17420d12298e3b482011a5b77fad71b/base/android/java/src/org/chromium/base/annotations/DoNotInline.java
[modify] https://crrev.com/428de580e17420d12298e3b482011a5b77fad71b/base/android/proguard/chromium_code.flags
[modify] https://crrev.com/428de580e17420d12298e3b482011a5b77fad71b/content/public/android/java/src/org/chromium/content/browser/ApiHelperForM.java

I believe this is fixed (and perf dashboard results should soon reflect this).

I'm going to keep this bug open to track removing some of the systraces I originally added. I added *lots* of events to get a finer-grained view of the 8 ms "mystery block". This block is no longer a mystery (it's class verification), and so we can remove some of these traces.

I'll leave some traces, so that we don't lose all visibility.
Cc: cricke@chromium.org klo...@chromium.org
The results are in. This alone had a huge impact on startup time:

On N5X: 162 --> 150 ms (7.4%)

https://chromeperf.appspot.com/report?sid=5ae87c41efb3d436419396e0551577a6e5bb1dc9544c55bf0e2881db28ed54be

I don't think we have the results on Gobo devices yet.

Great job, everyone! (cc'ing cricke@ and klobag@)

As a follow-up, I'd still like to see some future-proof mechanism to prevent this.

Cc: -jamwalla@chromium.org
Full investigation, including future-proof mechanisms, will be tracked in issue 855796.
Project Member

Comment 35 by bugdroid1@chromium.org, Jul 3

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/5ef15c7b5a09e5a1707ab6a63086d69329b10d23

commit 5ef15c7b5a09e5a1707ab6a63086d69329b10d23
Author: Nate Fischer <ntfschr@chromium.org>
Date: Tue Jul 03 20:43:55 2018

AW: remove unnecessary trace events

No change to logic.

These trace events were added to help investigate the 8 ms block which
wound up caused by class verification. This CL removes these events,
because other trace events (which we intentionally leave in the code)
are more helpful at diagnosing the issue.

R=torne@chromium.org

Bug:  838702 
Test: N/A
Change-Id: Ib0e405fb78df12b159e3bbbf242820650648ebfd
Reviewed-on: https://chromium-review.googlesource.com/1123464
Reviewed-by: Richard Coles <torne@chromium.org>
Commit-Queue: Nate Fischer <ntfschr@chromium.org>
Cr-Commit-Position: refs/heads/master@{#572343}
[modify] https://crrev.com/5ef15c7b5a09e5a1707ab6a63086d69329b10d23/android_webview/glue/java/src/com/android/webview/chromium/WebViewChromium.java
[modify] https://crrev.com/5ef15c7b5a09e5a1707ab6a63086d69329b10d23/android_webview/glue/java/src/com/android/webview/chromium/WebViewContentsClientAdapter.java
[modify] https://crrev.com/5ef15c7b5a09e5a1707ab6a63086d69329b10d23/android_webview/java/src/org/chromium/android_webview/AwContentsClientCallbackHelper.java

Status: Fixed (was: Assigned)
I think this is sufficiently cleaned up. Future class verification work is tracked in issue 855796.
Project Member

Comment 37 by bugdroid1@chromium.org, Aug 2

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/5b9c975efcddf805e9bc1b9c89798e2d1d1beabf

commit 5b9c975efcddf805e9bc1b9c89798e2d1d1beabf
Author: Changwan Ryu <changwan@google.com>
Date: Thu Aug 02 21:56:08 2018

Fix startup regression and avoid logspam

TracingController is a new API in P, and VerifyClass issue in
http://crbug.com/791099,  http://crbug.com/838702  got resurfaced when
we rolled P SDK in
https://chromium-review.googlesource.com/c/chromium/src/+/1112729

Note that the issue might have been there in the downstream, which will
also be fixed with this CL.

Bug: 868250, 791099,  838702 
Test: I no longer see logcat message 'Rejecting re-init on ... TracingControllerAdapter'
Change-Id: Ia7a967d9dfa206f64b0ec7ae284af120ac449534
Reviewed-on: https://chromium-review.googlesource.com/1161003
Commit-Queue: Changwan Ryu <changwan@chromium.org>
Reviewed-by: Nate Fischer <ntfschr@chromium.org>
Cr-Commit-Position: refs/heads/master@{#580339}
[modify] https://crrev.com/5b9c975efcddf805e9bc1b9c89798e2d1d1beabf/android_webview/glue/BUILD.gn
[add] https://crrev.com/5b9c975efcddf805e9bc1b9c89798e2d1d1beabf/android_webview/glue/java/src/com/android/webview/chromium/ApiHelperForP.java
[modify] https://crrev.com/5b9c975efcddf805e9bc1b9c89798e2d1d1beabf/android_webview/glue/java/src/com/android/webview/chromium/WebViewChromiumFactoryProvider.java

Status: Verified (was: Fixed)
Bulk edit: marking stale 'fixed' bugs as 'verified' since they don't need verification at this point.

Sign in to add a comment