Macrobenchmark app launch extremely slow to start [192009149]

Fixed

Bug

Status Update

No update yet.

Description

cc...@google.com

created issue #1

Jun 24, 2021 10:03PM

Trivial hot startup test (TrivialStartupBenchmark#startup[startup=WARM,compilation=None])

Launch itself takes approx 45ms.

waitOnPackageLaunch() takes > 5.5 seconds. Of that, more than 4.5 seconds is spent waiting for the app to actually launch (that is, time elapsed before the launching: <packagename> trace section).

It looks like the wait finishes several hundred millis later, due to UiAutomator polling every 1 second. The gap at the end of the trace is an intentional sleep, to ensure trace content isn't lost (400ms).

TrivialStartupBenchmark_startup[startup=WARM,compilation=None]_iter000_2021-06-24-22-16-51.trace

6.1 MB

Download

Comments

cc...@google.com <cc...@google.com> #2Jun 24, 2021 10:16PM

Project: platform/frameworks/support
Branch: androidx-master-dev

commit c60f33e229e31ab328ef6b59dab63b264954831c
Author: Alexandre Elias <aelias@google.com>
Date: Fri Jul 10 16:23:09 2020

Semantics no-op cleanups

Partly in response to lmr's broad code review, I did a pass of
superficial API/implementation cleanup. The main changes are:

- I changed each Boolean SemanticsProperty where false is equivalent to
not being present to take "Unit" instead. This is conceptually
clearer: it avoids questions like "can I cancel out a semantics from a
merged child by setting it to false?" Because "property = Unit" looks
weird, I also changed the style of these to "property()".

- I moved the Semantics id generator closer to where it's used, in
SemanticsModifierCore. I made it internal and an AtomicInt.
(Note that integer ids are heavily used in the Android
AccessibilityNodeInfo APIs so I can't simply remove them entirely.)

- I deleted dead code. Some examples include SemanticsHintOverrides,
a public API not connected to anything, and SemanticsPropertyKey
merge() open method which is never called. (In both cases I have
a different plan in mind for accessibility.)

Fixes: 145951226
Fixes: 145955412
Test: existing tests
Relnote: "Single-value semantics properties now use a calling style.
For example, 'semantics { hidden = true }' is now written as:
'semantics { hidden() }'."

Change-Id: Ic1afd12ea22c926babc9662f1804d80b33aa0cfc

M ui/integration-tests/benchmark/src/androidTest/java/androidx/ui/benchmark/test/LayoutNodeModifierBenchmark.kt
M ui/ui-core/api/0.1.0-dev15.txt
M ui/ui-core/api/current.txt
M ui/ui-core/api/public_plus_experimental_0.1.0-dev15.txt
M ui/ui-core/api/public_plus_experimental_current.txt
M ui/ui-core/api/restricted_0.1.0-dev15.txt
M ui/ui-core/api/restricted_current.txt
M ui/ui-core/src/androidAndroidTest/kotlin/androidx/ui/graphics/vector/VectorTest.kt
M ui/ui-core/src/androidAndroidTest/kotlin/androidx/ui/semantics/SemanticsTests.kt
M ui/ui-core/src/androidMain/kotlin/androidx/ui/core/AndroidActuals.kt
M ui/ui-core/src/androidMain/kotlin/androidx/ui/core/AndroidComposeView.kt
M ui/ui-core/src/androidMain/kotlin/androidx/ui/core/AndroidComposeViewAccessibilityDelegateCompat.kt
M ui/ui-core/src/androidMain/kotlin/androidx/ui/core/AndroidPopup.kt
M ui/ui-core/src/commonMain/kotlin/androidx/ui/core/Expect.kt
M ui/ui-core/src/commonMain/kotlin/androidx/ui/core/semantics/SemanticsConfiguration.kt
D ui/ui-core/src/commonMain/kotlin/androidx/ui/core/semantics/SemanticsHintOverrides.kt
M ui/ui-core/src/commonMain/kotlin/androidx/ui/core/semantics/SemanticsModifier.kt
M ui/ui-core/src/commonMain/kotlin/androidx/ui/core/semantics/SemanticsNode.kt
M ui/ui-core/src/commonMain/kotlin/androidx/ui/core/semantics/SemanticsOwner.kt
M ui/ui-core/src/commonMain/kotlin/androidx/ui/core/semantics/SemanticsWrapper.kt
M ui/ui-core/src/commonMain/kotlin/androidx/ui/semantics/SemanticsProperties.kt
M ui/ui-foundation/api/0.1.0-dev15.txt
M ui/ui-foundation/api/current.txt
M ui/ui-foundation/api/public_plus_experimental_0.1.0-dev15.txt
M ui/ui-foundation/api/public_plus_experimental_current.txt
M ui/ui-foundation/api/restricted_0.1.0-dev15.txt
M ui/ui-foundation/api/restricted_current.txt
M ui/ui-foundation/src/main/java/androidx/ui/foundation/Clickable.kt
M ui/ui-foundation/src/main/java/androidx/ui/foundation/Dialog.kt
M ui/ui-foundation/src/main/java/androidx/ui/foundation/Scroller.kt
M ui/ui-foundation/src/main/java/androidx/ui/foundation/selection/Selectable.kt
M ui/ui-foundation/src/main/java/androidx/ui/foundation/selection/Toggleable.kt
M ui/ui-foundation/src/main/java/androidx/ui/foundation/semantics/FoundationSemanticsProperties.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/ButtonTest.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/CardTest.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/CheckboxScreenshotTest.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/RadioButtonScreenshotTest.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/ScaffoldTest.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/SnackbarTest.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/SurfaceTest.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/ripple/RippleIndicationTest.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/textfield/TextFieldScreenshotTest.kt
M ui/ui-material/src/main/java/androidx/ui/material/AppBar.kt
M ui/ui-material/src/main/java/androidx/ui/material/TextFieldImpl.kt
M ui/ui-test/src/androidTest/java/androidx/ui/test/AssertsTest.kt
M ui/ui-test/src/androidTest/java/androidx/ui/test/CallSemanticsActionTest.kt
M ui/ui-test/src/androidTest/java/androidx/ui/test/ErrorMessagesTest.kt
M ui/ui-test/src/androidTest/java/androidx/ui/test/FindersTest.kt
M ui/ui-test/src/androidTest/java/androidx/ui/test/PrintToStringTest.kt
M ui/ui-test/src/androidTest/java/androidx/ui/test/ScrollToTest.kt
M ui/ui-test/src/androidTest/java/androidx/ui/test/TextActionsTest.kt
M ui/ui-test/src/main/java/androidx/ui/test/Actions.kt
M ui/ui-test/src/main/java/androidx/ui/test/Filters.kt
M ui/ui-text/api/0.1.0-dev15.txt
M ui/ui-text/api/current.txt
M ui/ui-text/api/public_plus_experimental_0.1.0-dev15.txt
M ui/ui-text/api/public_plus_experimental_current.txt
M ui/ui-text/api/restricted_0.1.0-dev15.txt
M ui/ui-text/api/restricted_current.txt
M ui/ui-text/src/commonMain/kotlin/androidx/ui/text/CoreTextField.kt
M ui/ui-text/src/commonMain/kotlin/androidx/ui/text/TextSemanticsProperties.kt

https://android-review.googlesource.com/1360099

TrivialStartupBenchmark_startup[startup=WARM,compilation=None]_iter000_2021-06-24-22-26-57.trace

6 MB

Download

cc...@google.com <cc...@google.com> #3Jun 24, 2021 10:27PM

Relevant logcat - the activity start request is apparently slowed down for 5 seconds intentionally. Public bug about this behavior: https://b.corp.google.com/issues/36910222

06-24 22:40:10.835  1462  2016 I ActivityTaskManager: START u0 {act=androidx.benchmark.integration.macrobenchmark.target.TRIVIAL_STARTUP_ACTIVITY flg=0x10008000 pkg=androidx.benchmark.integration.macrobenchmark.target cmp=androidx.benchmark.integration.macrobenchmark.target/.TrivialStartupActivity} from uid 10315
06-24 22:40:10.836  1462  2016 W ActivityTaskManager: Activity start request from 10315 stopped
06-24 22:40:14.538  1462  1555 D CompatibilityChangeReporter: Compat change id reported: 135634846; UID 10314; state: DISABLED
06-24 22:40:14.538  1462  1555 D CompatibilityChangeReporter: Compat change id reported: 135754954; UID 10314; state: ENABLED
06-24 22:40:14.538  1462  1578 D CompatibilityChangeReporter: Compat change id reported: 143937733; UID 10314; state: ENABLED
06-24 22:40:14.545   763   763 D Zygote  : Forked child process 24588
06-24 22:40:14.548  1462  1578 I ActivityManager: Start proc 24588:androidx.benchmark.integration.macrobenchmark.target/u0a314 for pre-top-activity {androidx.benchmark.integration.macrobenchmark.target/androidx.benchmark.integration.macrobenchmark.target.TrivialStartupActivity}

cc...@google.com <cc...@google.com> #4Jun 26, 2021 12:12AM

Tried to invoke the intent differently via androidx.test - via ActivityScenario, and via InstrumentationActivityInvoker more directly, both of which didn't solve the latency issue, and had other problems.

Found a way that works pretty nicely - am start-activity \"${intent.toUri(...)}\". We were originally interested in swapping to that to avoid needing UiAutomator to detect launch completion (also a bonus!) - the toUri was the bit I was missing before. Problem is that we need to rewrite things to pipe errors through, since some start-activity errors come out in stdout, and some in stderr.

WIP cl cuts the time per launch iteration down from 16 seconds -> 8s. (I'm sure there's still more to optimize there - several other conservative waits that we can potentially improve.)

ap...@google.com <ap...@google.com> #5Jun 29, 2021 11:54PM

Marked as fixed.

Project: platform/frameworks/support
Branch: androidx-main

commit 4e10e6b81ffd6ad29a1947aa675abaa3bc0d1208
Author: Chris Craik <ccraik@google.com>
Date: Thu Jun 24 15:53:33 2021

Switch to am start-activity for startActivityAndWait

Test: MacrobenchmarkScopeTest
Test: ShellUtilsTest
Fixes: 192009149
Bug: 181810492
Relnote:"""Switched startActivityAndWait to invoke `am start`, which reduces
waiting by approximately 5 seconds, at the cost of no longer supporting
intent parcelables."""

This avoids a 5 second wait in context.startActivity() after every
home button press. Speeds up TrivialStartupBenchmark from 5m38s->8m1s,
a 46% reduction in runtime (bramble on R).

Reworked shell utils to enable capturing stderr, since am start prints
some errors to stdout, and some to stderr.

Additionally:
- adds tracing to startActivityAndWait
- re-enables MacrobenchScopeTest in CI, adding clear error if package missing

Change-Id: I5a6f55819fe095da1317b55405a6a5a9fe3cb758

M benchmark/macro/build.gradle
M benchmark/macro/src/androidTest/java/androidx/benchmark/macro/MacrobenchmarkScopeTest.kt
M benchmark/macro/src/androidTest/java/androidx/benchmark/macro/perfetto/ShellUtilsTest.kt
M benchmark/macro/src/main/java/androidx/benchmark/macro/MacrobenchmarkScope.kt
M benchmark/macro/src/main/java/androidx/benchmark/macro/perfetto/ShellUtils.kt
M testutils/testutils-macrobenchmark/src/main/java/androidx/testutils/MacrobenchUtils.kt

https://android-review.googlesource.com/1751627

Issue 192009149

Description

Issue summary

Comments

cc...@google.com <cc...@google.com> #2Jun 24, 2021 10:16PM

cc...@google.com <cc...@google.com> #3Jun 24, 2021 10:27PM

cc...@google.com <cc...@google.com> #4Jun 26, 2021 12:12AM

ap...@google.com <ap...@google.com> #5Jun 29, 2021 11:54PM

Add comment

Issue metadata