Macrobench startup traces cutting off too early, failing to capture metric [193827052]

Duplicate

of 194105203

Bug

Status Update

No update yet.

Description

cc...@google.com

created issue #1

Jul 15, 2021 10:14PM

Seeing traces cutting off too early, before e.g. startActivityAndWait have fully completed, which results in an exception like the following:

java.lang.IllegalStateException: Error, different metrics observed in different iterations.

Iteration 1 missing keys [startupMs]Please report a bug, and include a logcat capture, and all traces captured by this test run:
/storage/emulated/0/Android/media/androidx.benchmark.integration.macrobenchmark.test/TrivialStartupBenchmark_startup[startup=COLD,compilation=SpeedProfile[iterations=3]]_iter000_2021-07-15-22-21-37.trace
/storage/emulated/0/Android/media/androidx.benchmark.integration.macrobenchmark.test/TrivialStartupBenchmark_startup[startup=COLD,compilation=SpeedProfile[iterations=3]]_iter001_2021-07-15-22-21-41.trace
/storage/emulated/0/Android/media/androidx.benchmark.integration.macrobenchmark.test/TrivialStartupBenchmark_startup[startup=COLD,compilation=SpeedProfile[iterations=3]]_iter002_2021-07-15-22-21-44.trace
DeviceInfo(Brand=google, Model=Pixel 4a (5G), SDK=30, BuildFp=google/bramble/bramble:11/RQ3A.210605.003/7295351:userdebug/dev-keys)
...

See attached trace.

Seeing this in CI frequently with androidx.benchmark.integration.macrobenchmark.SmallListStartupBenchmark, e.g. https://android-build.googleplex.com/builds/tests/view?invocationId=I51900009972024845&redirect=http%3A%2F%2Fab%2FI51900009972024845&testClass=SmallListStartupBenchmark&testMethod=startup%5Bstartup%3DHOT%2Ccompilation%3DNone%5D&testPackage=androidx.benchmark.integration.macrobenchmark

This is likely due to switch either to am start (http://aosp/1751627), or reduction of sleep before killing the trace (http://aosp/1751631).

nometric.trace

3 MB

Download

Comments

ap...@google.com <ap...@google.com> #2Jul 16, 2021 05:36PM

Marked as fixed.

Yigit, do you have time to fix it?

reemission of the same liveData is racy

cc...@google.com <cc...@google.com> Jul 20, 2021 05:58PM

Status: Assigned (reopened)

ap...@google.com <ap...@google.com> #3Jul 28, 2021 01:21AM

yea i'll take it.

ap...@google.com <ap...@google.com> #4Oct 13, 2021 12:08AM

Thanks for the detailed analysis. This may not be an issue anymore since we've started using Main.immediate there but I' not sure; I'll try to create a test case.

cc...@google.com <cc...@google.com> Nov 3, 2021 06:15PM

Status: Duplicate of

194105203

Issue 193827052