Skip to content
This repository has been archived by the owner on Jan 12, 2023. It is now read-only.

MainDispatcherLoader.<clinit> unexpectedly takes 209ms to run on COLD MAIN start up #5102

Closed
mcomella opened this issue Aug 11, 2021 · 12 comments
Assignees
Labels
performance Performance related issues

Comments

@mcomella
Copy link
Contributor

I took a profile of COLD MAIN start up on my Moto G5: https://share.firefox.dev/3iFn6LU

The main thing that appears unnecessarily slow is the PromptMiddleware.<init> call: let's investigate!

@mcomella mcomella added the performance Performance related issues label Aug 11, 2021
@mcomella
Copy link
Contributor Author

mcomella commented Aug 12, 2021

We see a similar issue in fenix: https://share.firefox.dev/3CPxBEH It also does a long, java.net.URL.openStream thing as a child of kotlinx.coroutines.internal.MainDispatcherLoader.<clinit>. I tried upgrading to the latest stable versions of coroutines and kotlin that jetpack compose would let me do but still no fix.

@mcomella
Copy link
Contributor Author

mcomella commented Aug 12, 2021

I looked into the MainDispatcherLoader.<clinit> part. Here's the source: https://github.com/Kotlin/kotlinx.coroutines/blob/8c98180f177bbe4b26f1ed9685a9280fea648b9c/kotlinx-coroutines-core/jvm/src/internal/MainDispatchers.kt#L26-L36

It seems like the coroutines library is calling a slow method, ServiceLoader.load, which is expected to be optimized by R8. However, if we don't have a recent enough version of R8, I'm guessing this might not be optimized. The version of R8 is provided by the Android Gradle Plugin.

We recently upgraded AGP, kotlin, coroutines, etc. so maybe that's why we saw this regression.

@mcomella
Copy link
Contributor Author

It looks like we have the latest version of the Android Gradle Plugin, v7.0.0 so it seems we can't modify the versions to fix this issue.

Looking at blame of the code I linked above, this coroutine code was written 2 years ago: that implies that maybe the later releases of AGP may have broken this optimization. They also allude to a need for us to manually disable the fast service loader in the commit that added the code so maybe there's a configuration issue.

@mcomella
Copy link
Contributor Author

I downgraded AGP to 4.2.0 (and removed compose during a previous debugging attempt) and no longer see the issue: https://share.firefox.dev/3fVvG7H Let's:

  • can we just downgrade to AGP 4.2.0 without removing compose and still get the fix?
  • does this also fix fenix?
  • file an upstream bug against R8
  • perhaps document this more broadly (moz perf blog?) so the android community can workaround this issue

@mcomella mcomella changed the title PromptMiddleware.<init> unexpectedly takes 209ms to run on COLD MAIN start up MainDispatcherLoader.<cinit> unexpectedly takes 209ms to run on COLD MAIN start up Aug 12, 2021
@mcomella
Copy link
Contributor Author

mcomella commented Aug 12, 2021

I confirmed this is a regression from AGP v7.0.0 by creating a minimally reproducible test case: https://github.com/mcomella/AGP7Slowdown

I filed an upstream bug with the R8 team: https://issuetracker.google.com/issues/196302685

Since this affects fenix, I filed: mozilla-mobile/fenix#20824

As for what we can do about this, we should probably just downgrade to AGP v4.2.0 until this is addressed upstream. An alternative would be to use the fast ServiceLoader via systemProp (see the code for details) but it's unclear how much more performant that'd be, if any.

@mcomella mcomella self-assigned this Aug 12, 2021
@mcomella
Copy link
Contributor Author

mcomella commented Aug 12, 2021

When I downgrade to AGP v4.2.0, I get the following error:

error: this version (1.0.0) of the Compose Compiler requires Kotlin version 1.5.10 but you appear to be using Kotlin version 1.4.31 which is not known to be compatible.  Please fix your configuration (or `suppressKotlinVersionCompatibilityCheck` but don't say I didn't warn you!).

> Task :app:compileFocusNightlyKotlin FAILED

FAILURE: Build failed with an exception.

Which is weird because we explicitly declare kotlin 1.5.10 – I guess our dependencies are pulling in an older version that somehow gets upgraded with AGP v7.0.0. We could either:

@mcomella
Copy link
Contributor Author

This regressed in 6caa946. As far as I can tell, this is not in the v91.1.1 release:

$ git log --ancestry-path 6caa9468a4906675378a4bef9f9ad12bbb7c6bca..v91.1.1
$

I do not see tags for beta releases so I'm not sure how those work for Focus. Presumably, we just need to fix this before the v92 release, which probably follows the same train as Fenix: that's in 24 days.

@mcomella mcomella changed the title MainDispatcherLoader.<cinit> unexpectedly takes 209ms to run on COLD MAIN start up MainDispatcherLoader.<clinit> unexpectedly takes 209ms to run on COLD MAIN start up Aug 12, 2021
@mcomella
Copy link
Contributor Author

In my local benchmark, this improved start up by 97ms. I filed #5121 as a follow-up to remove the hack.

mcomella added a commit to mcomella/focus-android that referenced this issue Aug 12, 2021
For the root cause, see the comments added in the commit.

This improves COLD MAIN time to first frame by 97ms across 10
iterations (medians):
- before: 616.5ms
- after: 519.5ms
@mcomella
Copy link
Contributor Author

In my local benchmark, this improved start up by 97ms. I filed #5121 as a follow-up to remove the hack.

Actually, if our proguard code fails, it'll fall back on the r8 optimization anyway: it doesn't seem worth the churn to keep track of the upstream fix and remove it, especially for two products.

I wanted to verify that the perf of the fast service loader and the r8 optimization are comparable so I took benchmarks: the fast service loader made start up 45ms faster but I realized this isn't a fair comparison as we downgraded our version of R8 and may be missing other optimizations. I could take a benchmark of just main scope but I think I spent enough time on this. We don't see a major perf hit in the profile so I think we can deal with it. If we later see a perf hit in the profile, then we can worry about it again.

mcomella added a commit to mcomella/focus-android that referenced this issue Aug 13, 2021
mergify bot pushed a commit that referenced this issue Aug 16, 2021
For the root cause, see the comments added in the commit.

This improves COLD MAIN time to first frame by 97ms across 10
iterations (medians):
- before: 616.5ms
- after: 519.5ms
mergify bot pushed a commit that referenced this issue Aug 17, 2021
For the root cause, see the comments added in the commit.

This improves COLD MAIN time to first frame by 97ms across 10
iterations (medians):
- before: 616.5ms
- after: 519.5ms

(cherry picked from commit 162e5bf)
mergify bot pushed a commit that referenced this issue Aug 17, 2021
@mcomella
Copy link
Contributor Author

Here's my PR in which I also requested a backport to v92: #5122

@mcomella
Copy link
Contributor Author

Backport PR: #5158 The original PR is closed.

mergify bot pushed a commit that referenced this issue Aug 18, 2021
For the root cause, see the comments added in the commit.

This improves COLD MAIN time to first frame by 97ms across 10
iterations (medians):
- before: 616.5ms
- after: 519.5ms

(cherry picked from commit 162e5bf)
mergify bot pushed a commit that referenced this issue Aug 18, 2021
@mcomella
Copy link
Contributor Author

Both main branch and releases branch is updated: closing as fixed.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
performance Performance related issues
Projects
None yet
Development

No branches or pull requests

1 participant