BaselineProfiles are not generated using Firebase Test Lab devices with Gradle Managed Device [285187547]

Fixed

Bug

Status Update

No update yet.

Description

di...@target.com

created issue #1

Jun 1, 2023 01:11PM

We are trying to generate Baseline Profiles for our application using the BaselineProfiles plugin and since we want to generate it on our CI/CD pipelines we are exploring Gradle Managed devices.

As there is an already existing issue where Gradle Managed devices fail to setup on Linux machines, we are exploring the new feature of using Firebase Test Lab devices as Gradle Managed devices.

I am following the performance sample app and included the changes mentioned for running tests on Firebase Test Lab devices as Gradle Managed device. When the task generateBaselineProfile runs locally, Baseline Profiles are generated correctly. However, when run on the FTL configured device, tests are running successfully, but the profiles are not generated and I see this message in the output:

No baseline profile rules were generated for the variant `release`.
This is most likely because there are no instrumentation test for it. If this
is not intentional check that tests for this variant exist in the `baselineProfile`
dependency module.

Comparing the logs from local and FTL, I could see that the profiles are generated in a directory different than the task tries to extract from:

05-26 09:23:41.425: D/Benchmark(9473): Reference profile location: /data/misc/profiles/ref/com.example.macrobenchmark.target/primary.prof
...
05-26 09:23:41.545: D/Benchmark(9473): APK Path: /data/app/~~kpdhuDgDtK4xTg_DWXX1nQ==/com.example.macrobenchmark.target-NvgEVbxIsGXC8BzbuvHGrg==/base.apk
05-26 09:23:41.545: D/Benchmark(9473): Converting to human readable profile format
05-26 09:23:41.545: D/Benchmark(9473): Using profile location: /data/misc/profiles/ref/com.example.macrobenchmark.target/primary.prof
...
05-26 09:23:41.844: D/Benchmark(9473): Using profile location: /data/misc/profiles/cur/0/com.example.macrobenchmark.target/primary.prof
...
05-26 09:23:44.174: D/Benchmark(9473): Pull Baseline Profile with: `adb pull "/storage/emulated/0/Android/media/com.example.benchmark.baselinprofile/ComposeActivityBaselineProfileGenerator_profileGenerator-baseline-prof-2023-05-26-16-23-43.txt" .`
05-26 09:23:44.266: D/Benchmark(9473): Total Run Time Ns: 37069762291
05-26 09:23:44.268: D/Benchmark(9473): Killing process com.example.macrobenchmark.target

When run locally, I can see that it is using the same location from which it is later extracted:

2023-05-27 00:17:09.432  7983-8002  Benchmark               com...mple.benchmark.baselinprofile  D  additionalTestOutputDir=/sdcard/Android/media/com.example.benchmark.baselinprofile/additional_test_output
...
2023-05-27 00:17:09.448  7983-8002  Benchmark               com...mple.benchmark.baselinprofile  D  Usable output directory: /storage/emulated/0/Android/media/com.example.benchmark.baselinprofile
2023-05-27 00:17:09.449  7983-8002  Benchmark               com...mple.benchmark.baselinprofile  D  Output Directory: /sdcard/Android/media/com.example.benchmark.baselinprofile/additional_test_output
2023-05-27 00:17:40.452  7983-8002  Benchmark               com...mple.benchmark.baselinprofile  D  Copying /storage/emulated/0/Android/media/com.example.benchmark.baselinprofile/LoginBaselineProfileGenerator_profileGenerator-baseline-prof.txt to /sdcard/Android/media/com.example.benchmark.baselinprofile/additional_test_output/LoginBaselineProfileGenerator_profileGenerator-baseline-prof.txt
2023-05-27 00:17:40.462  7983-8002  Benchmark               com...mple.benchmark.baselinprofile  D  Pull Baseline Profile with: `adb pull "/storage/emulated/0/Android/media/com.example.benchmark.baselinprofile/LoginBaselineProfileGenerator_profileGenerator-baseline-prof-2023-05-26-18-47-40.txt" .`
2023-05-27 00:17:40.467  7983-8002  Benchmark               com...mple.benchmark.baselinprofile  D  Copying /storage/emulated/0/Android/media/com.example.benchmark.baselinprofile/LoginBaselineProfileGenerator_profileGenerator-baseline-prof-2023-05-26-18-47-40.txt to /sdcard/Android/media/com.example.benchmark.baselinprofile/additional_test_output/LoginBaselineProfileGenerator_profileGenerator-baseline-prof-2023-05-26-18-47-40.txt
2023-05-27 00:17:40.475  7983-8002  Benchmark               com...mple.benchmark.baselinprofile  D  Total Run Time Ns: 10786612088

Setup:

Android Studio Hedgehog | 2023.1.1 Canary 5

Build #AI-231.7864.76.2311.10195651, built on May 25, 2023

Runtime version: 17.0.6+0-17.0.6b829.9-10027231 aarch64

AGP 8.2.0-alpha05

Benchmark 1.2.0-alpha13

Could the copying be an issue?

I have attached the performance sample app code with the changes. Run it in the above configuration with FTL setup and should see a similar output.

performance-samples.zip

7.9 MB

Download

Comments

di...@target.com <di...@target.com> #2Jun 1, 2023 01:15PM

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

commit 3283536a57f7caf087786f6030f6bf246489df85
Author: Chris Craik <ccraik@google.com>
Date: Fri Feb 02 16:27:30 2024

Speculative fix for Failed to stop [ProcessPid(processName=perfetto...

Bug: 323601788
Bug: 307649002
Relnote: "Adjusted data source timeouts to attempt to fix java.lang.IllegalStateException: Failed to stop [ProcessPid(processName=perfetto, pid=...)]"

Test: ./gradlew bench:b-m:cC
Change-Id: I8dc7d5091ea1a8e68cb5effb21363f1c3196cf56

M benchmark/benchmark-common/src/main/java/androidx/benchmark/perfetto/PerfettoConfig.kt
M benchmark/benchmark-common/src/main/java/androidx/benchmark/perfetto/PerfettoHelper.kt

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

ra...@google.com <ra...@google.com> Jun 1, 2023 08:06PM

Reassigned to ma...@google.com.

ma...@google.com <ma...@google.com> #3Jun 1, 2023 10:46PM

This is expected to be fixed with the change above, which made it into 1.3.0-alpha01.

Please let us know if you still see this issue after updating to that version

di...@gmail.com <di...@gmail.com> #4Jun 2, 2023 06:49AM

Comment has been deleted.

Message last modified on Jun 2, 2023 06:49AM

di...@target.com <di...@target.com> #5Jun 2, 2023 06:50AM

@ #comment4 - can you attach logcat of a scenario where this reproduces? If necessary, you can filter it to perfetto/PerfettoCapture/Benchmark tags.

How reproducible is this, and on which devices and OS versions?

ma...@google.com <ma...@google.com> #6Jun 2, 2023 05:23PM

I'm facing the same issue. Device: Pixel 8 Pro Android 15 - Build Number: AP31.240426.023 Stack:

java.lang.IllegalStateException: Failed to stop [ProcessPid(processName=perfetto, pid=11267)]
at androidx.benchmark.Shell.terminateProcessesAndWait(Shell.kt:612)
at androidx.benchmark.Shell.terminateProcessesAndWait(Shell.kt:581)
at androidx.benchmark.perfetto.PerfettoHelper$Companion.stopAllPerfettoProcesses(PerfettoHelper.kt:441)
at androidx.benchmark.perfetto.PerfettoHelper.startCollecting(PerfettoHelper.kt:91)
at androidx.benchmark.perfetto.PerfettoCapture.start(PerfettoCapture.kt:73)
at androidx.benchmark.perfetto.PerfettoCaptureWrapper.start(PerfettoCaptureWrapper.kt:80)
at androidx.benchmark.perfetto.PerfettoCaptureWrapper.record(PerfettoCaptureWrapper.kt:136)
at androidx.benchmark.perfetto.PerfettoCaptureWrapper.record$default(PerfettoCaptureWrapper.kt:101)
at androidx.benchmark.junit4.BenchmarkRule$applyInternal$$inlined$Statement$1.evaluate(BenchmarkRule.kt:442)
at androidx.test.rule.GrantPermissionRule$RequestPermissionStatement.evaluate(GrantPermissionRule.java:136)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
at androidx.test.ext.junit.runners.AndroidJUnit4.run(AndroidJUnit4.java:162)
at org.junit.runners.Suite.runChild(Suite.java:128)
at org.junit.runners.Suite.runChild(Suite.java:27)
at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
at org.junit.runner.JUnitCore.run(JUnitCore.java:115)
at androidx.test.internal.runner.TestExecutor.execute(TestExecutor.java:67)
at androidx.test.internal.runner.TestExecutor.execute(TestExecutor.java:58)
at androidx.test.runner.AndroidJUnitRunner.onStart(AndroidJUnitRunner.java:446)
at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:2594)

Log from Logcat:

2024-06-01 19:08:00.528 10362-10380 Benchmark               com.performance.benchmark.test       D  launching Benchmark IsolationActivity
2024-06-01 19:08:00.554 10362-10422 vulkan                  com.performance.benchmark.test       D  searching for layers in '/data/app/~~BWq1z3HXtczxQa9ZQjpLhA==/com.performance.benchmark.test-PKZxIOqbb6y3ykj-YzNhBA==/lib/arm64'
2024-06-01 19:08:00.554 10362-10422 vulkan                  com.performance.benchmark.test       D  searching for layers in '/data/app/~~BWq1z3HXtczxQa9ZQjpLhA==/com.performance.benchmark.test-PKZxIOqbb6y3ykj-YzNhBA==/base.apk!/lib/arm64-v8a'
2024-06-01 19:08:00.563 10362-10362 LifecycleMonitor        com.performance.benchmark.test       D  Lifecycle status change: androidx.benchmark.IsolationActivity@f8698f1 in: PRE_ON_CREATE
2024-06-01 19:08:00.572 10362-10362 .benchmark.test         com.performance.benchmark.test       E  Invalid resource ID 0x00000000.
2024-06-01 19:08:00.579 10362-10362 CompatChangeReporter    com.performance.benchmark.test       D  Compat change id reported: 309578419; UID 10004; state: DISABLED
2024-06-01 19:08:00.582 10362-10362 CompatChangeReporter    com.performance.benchmark.test       D  Compat change id reported: 210923482; UID 10004; state: ENABLED
2024-06-01 19:08:00.582 10362-10362 CompatChangeReporter    com.performance.benchmark.test       D  Compat change id reported: 63938206; UID 10004; state: DISABLED
2024-06-01 19:08:01.357 10362-10362 Benchmark               com.performance.benchmark.test       D  Clocks not locked: online cores with min freq == min avail freq
2024-06-01 19:08:01.357 10362-10362 Benchmark               com.performance.benchmark.test       D  cpu0 CoreDir(path=/sys/devices/system/cpu/cpu7, online=true, availableFreqs=[402000, 578000, 697000, 712000, 910000, 1065000, 1221000, 1328000, 1418000, 1572000, 1836000, 1945000, 2130000, 2245000, 2367000], setSpeedKhz=402000, maxFreqKhz=2367000)
2024-06-01 19:08:01.357 10362-10362 Benchmark               com.performance.benchmark.test       D  cpu1 CoreDir(path=/sys/devices/system/cpu/cpu5, online=true, availableFreqs=[402000, 578000, 697000, 712000, 910000, 1065000, 1221000, 1328000, 1418000, 1572000, 1836000, 1945000, 2130000, 2245000, 2367000], setSpeedKhz=402000, maxFreqKhz=2367000)
2024-06-01 19:08:01.357 10362-10362 Benchmark               com.performance.benchmark.test       D  cpu2 CoreDir(path=/sys/devices/system/cpu/cpu3, online=true, availableFreqs=[324000, 610000, 820000, 955000, 1098000, 1197000, 1328000, 1425000, 1548000, 1704000], setSpeedKhz=324000, maxFreqKhz=1704000)
2024-06-01 19:08:01.357 10362-10362 Benchmark               com.performance.benchmark.test       D  cpu3 CoreDir(path=/sys/devices/system/cpu/cpu1, online=true, availableFreqs=[324000, 610000, 820000, 955000, 1098000, 1197000, 1328000, 1425000, 1548000, 1704000], setSpeedKhz=324000, maxFreqKhz=1704000)
2024-06-01 19:08:01.357 10362-10362 Benchmark               com.performance.benchmark.test       D  cpu4 CoreDir(path=/sys/devices/system/cpu/cpu8, online=true, availableFreqs=[500000, 880000, 1164000, 1298000, 1557000, 1745000, 1885000, 2049000, 2147000, 2294000, 2363000, 2556000, 2687000, 2850000, 2914000], setSpeedKhz=500000, maxFreqKhz=2914000)
2024-06-01 19:08:01.357 10362-10362 Benchmark               com.performance.benchmark.test       D  cpu5 CoreDir(path=/sys/devices/system/cpu/cpu6, online=true, availableFreqs=[402000, 578000, 697000, 712000, 910000, 1065000, 1221000, 1328000, 1418000, 1572000, 1836000, 1945000, 2130000, 2245000, 2367000], setSpeedKhz=402000, maxFreqKhz=2367000)
2024-06-01 19:08:01.357 10362-10362 Benchmark               com.performance.benchmark.test       D  cpu6 CoreDir(path=/sys/devices/system/cpu/cpu4, online=true, availableFreqs=[402000, 578000, 697000, 712000, 910000, 1065000, 1221000, 1328000, 1418000, 1572000, 1836000, 1945000, 2130000, 2245000, 2367000], setSpeedKhz=402000, maxFreqKhz=2367000)
2024-06-01 19:08:01.357 10362-10362 Benchmark               com.performance.benchmark.test       D  cpu7 CoreDir(path=/sys/devices/system/cpu/cpu2, online=true, availableFreqs=[324000, 610000, 820000, 955000, 1098000, 1197000, 1328000, 1425000, 1548000, 1704000], setSpeedKhz=324000, maxFreqKhz=1704000)
2024-06-01 19:08:01.357 10362-10362 Benchmark               com.performance.benchmark.test       D  cpu8 CoreDir(path=/sys/devices/system/cpu/cpu0, online=true, availableFreqs=[324000, 610000, 820000, 955000, 1098000, 1197000, 1328000, 1425000, 1548000, 1704000], setSpeedKhz=324000, maxFreqKhz=1704000)
2024-06-01 19:08:01.359 10362-10362 LifecycleMonitor        com.performance.benchmark.test       D  Lifecycle status change: androidx.benchmark.IsolationActivity@f8698f1 in: CREATED
2024-06-01 19:08:01.359 10362-10362 LifecycleMonitor        com.performance.benchmark.test       D  Lifecycle status change: androidx.benchmark.IsolationActivity@f8698f1 in: STARTED
2024-06-01 19:08:01.361 10362-10362 LifecycleMonitor        com.performance.benchmark.test       D  Lifecycle status change: androidx.benchmark.IsolationActivity@f8698f1 in: RESUMED
2024-06-01 19:08:01.365 10362-10362 CompatChangeReporter    com.performance.benchmark.test       D  Compat change id reported: 237531167; UID 10004; state: DISABLED
2024-06-01 19:08:01.426 10362-10380 GrantPermissionCallable com.performance.benchmark.test       I  Permission: android.permission.READ_EXTERNAL_STORAGE is already granted!
2024-06-01 19:08:01.426 10362-10380 GrantPermissionCallable com.performance.benchmark.test       I  Permission: android.permission.WRITE_EXTERNAL_STORAGE is already granted!
2024-06-01 19:08:01.426 10362-10380 Benchmark               com.performance.benchmark.test       D  -- Running com.performance.benchmark.ExampleBenchmark#log --
2024-06-01 19:08:01.427 10362-10380 PerfettoCapture         com.performance.benchmark.test       D  Supported ABIs: arm64-v8a
2024-06-01 19:08:01.427 10362-10380 PerfettoCapture         com.performance.benchmark.test       D  Recording perfetto trace
2024-06-01 19:08:01.446 10362-10380 PerfettoCapture         com.performance.benchmark.test       I  Cleanup perfetto before starting.
2024-06-01 19:08:01.558 10362-10380 Benchmark               com.performance.benchmark.test       D  kill -TERM command output - Output(stdout=, stderr=/storage/emulated/0/Android/media/com.performance.benchmark.test/temporaryScript5455895838492548174.tmp[2]: kill: 11267: Operation not permitted
                                                                                                    )
2024-06-01 19:08:01.725 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:01.759 10362-10572 InteractionJankMonitor  com.performance.benchmark.test       W  Initializing without READ_DEVICE_CONFIG permission. enabled=false, interval=1, missedFrameThreshold=3, frameTimeThreshold=64, package=com.performance.benchmark.test
2024-06-01 19:08:01.865 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:02.019 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:02.156 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:02.292 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:02.433 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:02.583 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:02.729 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:02.877 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:03.024 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:03.169 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:03.323 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:03.480 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:03.638 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:03.806 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:03.961 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:04.113 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:04.263 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:04.419 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:04.584 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:04.748 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:04.900 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:05.064 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:05.226 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:05.384 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:05.550 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:05.641 10362-10673 ProfileInstaller        com.performance.benchmark.test       D  Installing profile for com.performance.benchmark.test
2024-06-01 19:08:05.717 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:05.873 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:06.035 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:06.185 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:06.346 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:06.512 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:06.679 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:06.836 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:07.000 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:07.146 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:07.314 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:07.487 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:07.652 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:07.814 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:07.979 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:08.148 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:08.316 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:08.477 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:08.640 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:08.808 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:08.970 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:09.131 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:09.299 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:09.447 10362-10380 Benchmark               com.performance.benchmark.test       D  Waiting 100 ms for [ProcessPid(processName=perfetto, pid=11267)] to die
2024-06-01 19:08:09.496 10362-10380 TestRunner              com.performance.benchmark.test       E  failed: log(com.performance.benchmark.ExampleBenchmark)
2024-06-01 19:08:09.496 10362-10380 TestRunner              com.performance.benchmark.test       E  ----- begin exception -----
2024-06-01 19:08:09.500 10362-10380 TestRunner              com.performance.benchmark.test       E  java.lang.IllegalStateException: Failed to stop [ProcessPid(processName=perfetto, pid=11267)] (Ask Gemini)
                                                                                                    	at androidx.benchmark.Shell.terminateProcessesAndWait(Shell.kt:612)
                                                                                                    	at androidx.benchmark.Shell.terminateProcessesAndWait(Shell.kt:581)
                                                                                                    	at androidx.benchmark.perfetto.PerfettoHelper$Companion.stopAllPerfettoProcesses(PerfettoHelper.kt:441)
                                                                                                    	at androidx.benchmark.perfetto.PerfettoHelper.startCollecting(PerfettoHelper.kt:91)
                                                                                                    	at androidx.benchmark.perfetto.PerfettoCapture.start(PerfettoCapture.kt:73)
                                                                                                    	at androidx.benchmark.perfetto.PerfettoCaptureWrapper.start(PerfettoCaptureWrapper.kt:80)
                                                                                                    	at androidx.benchmark.perfetto.PerfettoCaptureWrapper.record(PerfettoCaptureWrapper.kt:136)
                                                                                                    	at androidx.benchmark.perfetto.PerfettoCaptureWrapper.record$default(PerfettoCaptureWrapper.kt:101)
                                                                                                    	at androidx.benchmark.junit4.BenchmarkRule$applyInternal$$inlined$Statement$1.evaluate(BenchmarkRule.kt:442)
                                                                                                    	at androidx.test.rule.GrantPermissionRule$RequestPermissionStatement.evaluate(GrantPermissionRule.java:136)
                                                                                                    	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
                                                                                                    	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
                                                                                                    	at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
                                                                                                    	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
                                                                                                    	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
                                                                                                    	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
                                                                                                    	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
                                                                                                    	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
                                                                                                    	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
                                                                                                    	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
                                                                                                    	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
                                                                                                    	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
                                                                                                    	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
                                                                                                    	at androidx.test.ext.junit.runners.AndroidJUnit4.run(AndroidJUnit4.java:162)
                                                                                                    	at org.junit.runners.Suite.runChild(Suite.java:128)
                                                                                                    	at org.junit.runners.Suite.runChild(Suite.java:27)
                                                                                                    	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
                                                                                                    	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
                                                                                                    	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
                                                                                                    	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
                                                                                                    	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
                                                                                                    	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
                                                                                                    	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
                                                                                                    	at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
                                                                                                    	at org.junit.runner.JUnitCore.run(JUnitCore.java:115)
                                                                                                    	at androidx.test.internal.runner.TestExecutor.execute(TestExecutor.java:67)
                                                                                                    	at androidx.test.internal.runner.TestExecutor.execute(TestExecutor.java:58)
                                                                                                    	at androidx.test.runner.AndroidJUnitRunner.onStart(AndroidJUnitRunner.java:446)
                                                                                                    	at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:2594)
2024-06-01 19:08:09.500 10362-10380 TestRunner              com.performance.benchmark.test       E  ----- end exception -----
2024-06-01 19:08:09.504 10362-10380 TestRunner              com.performance.benchmark.test       I  finished: log(com.performance.benchmark.ExampleBenchmark)
2024-06-01 19:08:09.514 10362-10362 MonitoringInstr         com.performance.benchmark.test       I  Finishing activity: androidx.benchmark.IsolationActivity@f8698f1
2024-06-01 19:08:09.515 10362-10380 TestRunner              com.performance.benchmark.test       I  run finished: 1 tests, 1 failed, 0 ignored
2024-06-01 19:08:09.519 10362-10362 MonitoringInstr         com.performance.benchmark.test       I  Finishing activity: androidx.benchmark.IsolationActivity@f8698f1

ma...@google.com <ma...@google.com> #7Jun 2, 2023 05:38PM

Same with 1.3.0-beta01
```
java.lang.IllegalStateException: Failed to stop [ProcessPid(processName=perfetto, pid=19422)]
at androidx.benchmark.Shell.terminateProcessesAndWait(Shell.kt:617)
```

I am trying to use a wrapper rule that can do some postprocessing on the macrobenchmark json before it sends to our servers instead of doing this in CI though.
Wrapper rule is pretty trivial:
```

class StatsDtaMacrobenchmarkRule : TestRule {
val macrobenchmarkRule: MacrobenchmarkRule = MacrobenchmarkRule()

override fun apply(
base: Statement,
description: Description,
): Statement = object : Statement() {
@Throws(Throwable::class)
override fun evaluate() {
before()
try {
macrobenchmarkRule.apply(base, description).evaluate()
} finally {
after()
}
}
}

/**
* Forwards to [MacrobenchmarkRule.measureRepeated]
*/
@JvmOverloads
fun measureRepeated(
packageName: String,
metrics: List<Metric>,
compilationMode: CompilationMode = CompilationMode.DEFAULT,
startupMode: StartupMode? = null,
@IntRange(from = 1)
iterations: Int,
setupBlock: MacrobenchmarkScope.() -> Unit = {},
measureBlock: MacrobenchmarkScope.() -> Unit,
) {
macrobenchmarkRule.measureRepeated(
packageName,
metrics,
compilationMode,
startupMode,
iterations,
setupBlock,
measureBlock,
)
}

private fun before() {
// Custom code to run before the nested rules
}

private fun after() {
// Custom code to run after the nested rules
val logcat = captureLogcat()
val regex = Regex(".*/(.+\\.json)")
val matchResult = regex.find(logcat)
val filename = matchResult?.groups?.get(1)?.value
filename?.let {
logV { "Macrobenchmark Filename: $it" }
} ?: logE { "Unable to find macrobenchmark file in logs!" }
}

private fun captureLogcat(): String {
val logcatProcess = Runtime.getRuntime().exec("logcat -d")
val bufferedReader = BufferedReader(InputStreamReader(logcatProcess.inputStream))

val logcatOutput = StringBuilder()
bufferedReader.useLines { lines ->
lines.forEach { line ->
logcatOutput.append(line).append("\n")
}
}

return logcatOutput.toString()
}

private companion object : LogCompanion("StatsDtaMacrobenchmarkRule")
}
```

di...@target.com <di...@target.com> #8Jun 5, 2023 09:38AM

But even using just the MacrobenchmarkRule, it has the same issue w/ perfectto process not being killed...

performance-samples.zip

7.7 MB

Download

di...@target.com <di...@target.com> #9Jun 5, 2023 09:48AM

Running killall in an adb shell doesn't work too:
```
$ killall perfetto
killall: pid 19422: Operation not permitted
killall: perfetto: Operation not permitted
```

ma...@google.com <ma...@google.com> #10Jun 5, 2023 09:49PM

restarting the device also doesn't seem to help

di...@target.com <di...@target.com> #11Jun 6, 2023 10:41AM

Forgot to mention my device: Pixel7 latest Android 15 beta, build API31.240517.031
Device is not rooted.

From the logs, it seems like the test doesn't have permissions needed to kill the perfetto process. It probably should send an IPC call to it to kill it (if perfectto has that capability).

Message last modified on Jun 6, 2023 11:13AM

di...@target.com <di...@target.com> #12Jun 12, 2023 09:26AM

Workaround for me was try a different device. Samsung S23 Ultra w/ Android 14 works w/o that perfetto kill permission error.

ma...@google.com <ma...@google.com> #13Jun 14, 2023 06:19PM

Experiencing the same issue.

Stacktrace:

java.lang.IllegalStateException: Failed to stop [ProcessPid(processName=perfetto, pid=24965)]
at androidx.benchmark.Shell.terminateProcessesAndWait(Shell.kt:617)
at androidx.benchmark.Shell.terminateProcessesAndWait(Shell.kt:587)
at androidx.benchmark.perfetto.PerfettoHelper$Companion.stopAllPerfettoProcesses(PerfettoHelper.kt:470)
at androidx.benchmark.perfetto.PerfettoHelper.startCollecting(PerfettoHelper.kt:85)
at androidx.benchmark.perfetto.PerfettoCapture.start(PerfettoCapture.kt:69)
at androidx.benchmark.perfetto.PerfettoCaptureWrapper.start(PerfettoCaptureWrapper.kt:76)
at androidx.benchmark.perfetto.PerfettoCaptureWrapper.record(PerfettoCaptureWrapper.kt:131)
at androidx.benchmark.perfetto.PerfettoCaptureWrapper.record$default(PerfettoCaptureWrapper.kt:95)
at androidx.benchmark.macro.MacrobenchmarkPhaseKt.runPhase(MacrobenchmarkPhase.kt:105)
at androidx.benchmark.macro.MacrobenchmarkKt$macrobenchmark$4.invoke(Macrobenchmark.kt:258)
at androidx.benchmark.macro.MacrobenchmarkKt$macrobenchmark$4.invoke(Macrobenchmark.kt:255)
at androidx.benchmark.perfetto.PerfettoTraceProcessor$Companion.runServer-VtjQ1oo(PerfettoTraceProcessor.kt:133)
at androidx.benchmark.perfetto.PerfettoTraceProcessor$Companion.runServer(PerfettoTraceProcessor.kt:108)
at androidx.benchmark.macro.MacrobenchmarkKt.macrobenchmark(Macrobenchmark.kt:255)
at androidx.benchmark.macro.MacrobenchmarkKt.macrobenchmarkWithStartupMode(Macrobenchmark.kt:392)
at androidx.benchmark.macro.junit4.MacrobenchmarkRule.measureRepeated(MacrobenchmarkRule.kt:108)
at com.example.baselineprofile.StartupBenchmarks.benchmark(StartupBenchmarks.kt:52)
at com.example.baselineprofile.StartupBenchmarks.startupCompilationNone(StartupBenchmarks.kt:44)

Versions:

androidx.benchmark:benchmark-macro-junit4:1.3.0
AGP: 8.6.0
Android Studio: Android Studio Koala Feature Drop | 2024.1.2

Device:

Google Pixel 6 Pro
Android 15
Android security update: August 5, 2024
Google Play system update: July 1, 2024
Kernel version:
5.10.210-android13-4-03254-g38965378c80a-ab11958173
#1 Wed Jun 12 03:24:21 UTC 2024
Build number: AP41.240726.010
Not rooted

The full logs of two test runs can be found in the attachments of the previous comment.

This section in the logs seems interesting:

09-03 11:09:10.873 10922 10942 D PerfettoCapture: Supported ABIs: arm64-v8a, armeabi-v7a, armeabi
09-03 11:09:10.873 10922 10942 D PerfettoCapture: Recording perfetto trace
09-03 11:09:10.873 27764 10817 I NetworkScheduler.Stats: (REDACTED) Task %s/%s started execution. cause:%s exec_start_elapsed_seconds: %s
09-03 11:09:10.876 27764 10713 I NetworkScheduler.Stats: (REDACTED) Task %s/%s finished executing. cause:%s result: %s elapsed_millis: %s uptime_millis: %s exec_start_elapsed_seconds: %s
09-03 11:09:10.890  4184  5455 W MediaProvider: isAppCloneUserPair for user 0: false
09-03 11:09:10.895 10922 10942 I PerfettoCapture: Cleanup perfetto before starting.
09-03 11:09:10.934 27764 10817 I NetworkScheduler.Stats: (REDACTED) Task %s/%s started execution. cause:%s exec_start_elapsed_seconds: %s
09-03 11:09:10.938 27764 11369 I NetworkScheduler.Stats: (REDACTED) Task %s/%s finished executing. cause:%s result: %s elapsed_millis: %s uptime_millis: %s exec_start_elapsed_seconds: %s
09-03 11:09:10.966  4184 30886 W MediaProvider: isAppCloneUserPair for user 0: false
09-03 11:09:11.003  1109  1109 I WifiHAL : Creating message to get link statistics; iface = 47
09-03 11:09:11.019 27764 10817 I NetworkScheduler.Stats: (REDACTED) Task %s/%s started execution. cause:%s exec_start_elapsed_seconds: %s
09-03 11:09:11.023 27764 10820 I NetworkScheduler.Stats: (REDACTED) Task %s/%s finished executing. cause:%s result: %s elapsed_millis: %s uptime_millis: %s exec_start_elapsed_seconds: %s
09-03 11:09:11.045  4184 30886 W MediaProvider: Ignoring param:deletedata post U for external apps
09-03 11:09:11.048  4184 30886 I MediaProvider: Invalidating LocalCallingIdentity cache for package com.example.baselineprofile. Reason: owned_database_row_deleted:/storage/emulated/0/Android/media/com.example.baselineprofile/temporaryScript3723391827797421641.tmp
09-03 11:09:11.051  4184 30886 I MediaProvider: Deleted 1 0 0 0 0 0 0 items on external_primary due to com.android.shell
09-03 11:09:11.054 10922 10942 D Benchmark: kill -TERM command output - Output(stdout=, stderr=/storage/emulated/0/Android/media/com.example.baselineprofile/temporaryScript3723391827797421641.tmp[2]: kill: 24965: Operation not permitted
09-03 11:09:11.054 10922 10942 D Benchmark: )

It looks like PerfettoCapture is trying to kill an already running instance of perfetto, but it doesn't have the rights to do so (last log line).

Listing running perfetto processes on the device after the test run shows:

adb -d shell ps | grep perfetto
statsd       15678     1   10846896   4480 0                   0 S perfetto
statsd       24965     1   10814128   3208 0                   0 S perfetto

The process ID of the second process matches the ID in the Stacktrace above. So PerfettoCapture tried to stop this one, but didn't have permission to do so.

Trying to kill these process via adb is also not permitted:

$ adb -d shell kill 24965
/system/bin/sh: kill: 24965: Operation not permitted

$ adb -d shell kill 15678
/system/bin/sh: kill: 15678: Operation not permitted

The user that owns the process seems to be statsd. This looks like the Statsd module. It seems to be responsible for running the perfetto process that can't be killed.

This is likely what comment #9 is also pointing at.

I don't have any other hardware devices with me for comparison runs.

When running the test on an Emulator, the log shows this:

09-03 12:06:55.431 10498 10516 D PerfettoCapture: Supported ABIs: arm64-v8a
09-03 12:06:55.431 10498 10516 D PerfettoCapture: Recording perfetto trace
09-03 12:06:55.435  1479  8742 W MediaProvider: isAppCloneUserPair for user 0: false
09-03 12:06:55.436 10498 10516 I PerfettoCapture: Cleanup perfetto before starting.
09-03 12:06:55.445  1285 10327 I NetworkScheduler.Stats: (REDACTED) Task %s/%s started execution. cause:%s exec_start_elapsed_seconds: %s
09-03 12:06:55.446  1285 10578 I NetworkScheduler.Stats: (REDACTED) Task %s/%s finished executing. cause:%s result: %s elapsed_millis: %s uptime_millis: %s exec_start_elapsed_seconds: %s
09-03 12:06:55.453  1479  8742 W MediaProvider: isAppCloneUserPair for user 0: false
09-03 12:06:55.464  1285 10327 I NetworkScheduler.Stats: (REDACTED) Task %s/%s started execution. cause:%s exec_start_elapsed_seconds: %s
09-03 12:06:55.466  1285  3618 I NetworkScheduler.Stats: (REDACTED) Task %s/%s finished executing. cause:%s result: %s elapsed_millis: %s uptime_millis: %s exec_start_elapsed_seconds: %s
09-03 12:06:55.474  1479  2128 I MediaProvider: Invalidating LocalCallingIdentity cache for package com.example.baselineprofile. Reason: owned_database_row_deleted:/storage/emulated/0/Android/media/com.example.baselineprofile/temporaryScript2502516040961053018.tmp
09-03 12:06:55.474  1479  2128 I MediaProvider: Deleted 1 0 0 0 0 0 0 items on external_primary due to com.android.shell
09-03 12:06:55.475 10498 10516 I PerfettoCapture: Starting perfetto tracing with cmd: cat /storage/emulated/0/Android/media/com.example.baselineprofile/trace_config.pb | perfetto --background-wait -c - -o /data/misc/perfetto-traces/trace_output.pb
09-03 12:06:55.478  1479  8742 W MediaProvider: isAppCloneUserPair for user 0: false
09-03 12:06:55.484  1285 10327 I NetworkScheduler.Stats: (REDACTED) Task %s/%s started execution. cause:%s exec_start_elapsed_seconds: %s
09-03 12:06:55.486  1285  3618 I NetworkScheduler.Stats: (REDACTED) Task %s/%s finished executing. cause:%s result: %s elapsed_millis: %s uptime_millis: %s exec_start_elapsed_seconds: %s
09-03 12:06:55.484 11210 11210 W perfetto: type=1400 audit(0.0:455): avc:  denied  { write } for  path="/data/local/tmp/temporaryScript4626443941097950496.tmp_stderr" dev="dm-39" ino=65625 scontext=u:r:perfetto:s0 tcontext=u:object_r:shell_data_file:s0 tclass=file permissive=0
09-03 12:06:55.493 11211 11211 I perfetto:    perfetto_cmd.cc:1053 Connected to the Perfetto traced service, starting tracing
09-03 12:06:55.493   444   444 I perfetto: ng_service_impl.cc:1042 Configured tracing session 22, #sources:9, duration:0 ms, #buffers:2, total buffer size:36864 KB, total sessions:1, uid:2000 session name: ""
09-03 12:06:55.493   432   432 I perfetto:  probes_producer.cc:141 Ftrace setup (target_buf=43)
09-03 12:06:55.492   432   432 W traced_probes: type=1400 audit(0.0:456): avc:  denied  { read } for  name="current_tracer" dev="tracefs" ino=9295 scontext=u:r:traced_probes:s0 tcontext=u:object_r:debugfs_tracing_debug:s0 tclass=file permissive=0
09-03 12:06:55.493   432   432 I perfetto:    ftrace_procfs.cc:445 disabled ftrace in /sys/kernel/tracing/
09-03 12:06:55.708   432   432 W traced_probes: type=1400 audit(0.0:457): avc:  denied  { read } for  name="format" dev="tracefs" ino=8233 scontext=u:r:traced_probes:s0 tcontext=u:object_r:debugfs_tracing_debug:s0 tclass=file permissive=0
09-03 12:06:55.710   432   432 I perfetto:    ftrace_procfs.cc:442 enabled ftrace in /sys/kernel/tracing/
09-03 12:06:55.751  1479  6378 I MediaProvider: Invalidating LocalCallingIdentity cache for package com.example.baselineprofile. Reason: owned_database_row_deleted:/storage/emulated/0/Android/media/com.example.baselineprofile/temporaryScript4626443941097950496.tmp
09-03 12:06:55.753  1479  6378 I MediaProvider: Deleted 1 0 0 0 0 0 0 items on external_primary due to com.android.shell
09-03 12:06:55.754 10498 10516 I PerfettoCapture: Perfetto output - 11211
09-03 12:06:55.754 10498 10516 I PerfettoCapture: EXITCODE=0

Emulator info:

Pixel 6 AVD
Android 14
Android security update: September 5, 2023
Google Play system update: July 1, 2023
Kernel version:
6.1.23-android14-4-00257-g7e35917775b8-ab9964412
#1 Mon Apr 17 20:50:58 UTC 2023
Build number: UE1A.230829.036.A1 dev-keys

It seems like PerfettoCapture doesn't try to kill a perfetto process, and it seems to be able to start a perfetto trace.

Querying for an existing perfetto process on the emulator shows that no perfetto processes are running.

Hypothesis based on information in this thread:

On Pixel (maybe others too) devices with Android 15, the Statsd module is starting a perfetto process. This process can't be killed by PerfettoCapture when running a test, which produces the crash.

Edit 1: Seems like I hit a shortcut that sends the comment and deleted the text 🙈. Now I have to type it all again 😫. Hope I don't hit it again. Well, here we go 🤞.

Edit 2: Comment text got removed when posting the comment — and of course I didn't save it somewhere else. On to try number 3 🏇. Different browser...

di...@target.com <di...@target.com> #14Jun 15, 2023 11:28AM

Checked on a Pixel 6 Pro with Android 14 today. The crash did not occur.

I tried restarting the problematic device running 15, it did not resolve the issue. After a restart, the perfetto processes owned by statsd are also present again.

I also encountered this issue with the problematic Pixel 6 Pro running Android 15: https://issuetracker.google.com/issues/239897826. It also couldn't be resolved with a restart. On the Pixel 6 Pro with Android 14, recording a trace was possible.
Maybe the problem described in that issue could also be triggered by the perfetto process which can't be killed. The logs posted in this issue hint that the cause might also be a failure to run perfetto on the device.

Message last modified on Jun 15, 2023 11:36AM

ma...@google.com <ma...@google.com> #15Jun 15, 2023 04:52PM

I was able to occasionally reproduce this with my Pixel 5 with ToT on ScrollerBenchmark as well as TrivialKotlinBenchmark. Unfortunately I can't seem to reproduce this anymore, but here are some details anyway:

Device:

Google Pixel 5
Android 14

ed...@gmail.com <ed...@gmail.com> #16Jun 17, 2023 09:03PM

Nice work debugging in #13.
I can confirm I have the same issue on a Pixel 6 running Android 15. Same steps...same error. perfetto process can't be killed.
This seems like a bug in macrobenchmark? Or the Pixel 6 perfetto statsd autostartup.

Given this is a pretty popular test device, it should be easily reproducible...

ma...@google.com <ma...@google.com> #17Jun 20, 2023 05:15PM

Reassigned to bu...@google.com.

Experiencing the same issue.

Stacktrace:

----- begin exception -----
01-23 21:15:05.513 938 964 E TestRunner: java.lang.IllegalStateException: Failed to stop [ProcessPid(processName=perfetto, pid=5165)]
Device:
Pixel 9 Pro XL | Android 15

bu...@google.com <bu...@google.com> #18Jun 20, 2023 05:17PM

Accepted by bu...@google.com.

Project: platform/frameworks/support
Branch: androidx-main
Author: Chris Craik <ccraik@google.com>
Link: https://android-review.googlesource.com/3463345

Avoid crashes from external perfetto trace capture

Expand for full commit details

Avoid crashes from external perfetto trace capture 
 
Fixes: 323601788 
Test: ShellTest#killProcessesAndWait_failure 
Relnote: "Speculative fix for crashes: 'Failed to stop [ProcessPid(processName=perfetto, pid=...)]'. Now Benchmark will log a message instead of crashing when a backgroudn Perfetto process isn't able to be stopped before running the benchmark." 
 
From bugreport details, it appears that background perfetto traces are 
often triggered which cannot be terminated by shell. Log an error 
rather than crashing the benchmark. 
 
Change-Id: I37d3e254f7f3e49c53387dae89bb5bed7d2c9bf5

Files:

M benchmark/benchmark-common/src/androidTest/java/androidx/benchmark/PerfettoHelperTest.kt
M benchmark/benchmark-common/src/androidTest/java/androidx/benchmark/ShellTest.kt
M benchmark/benchmark-common/src/main/java/androidx/benchmark/Shell.kt
M benchmark/benchmark-common/src/main/java/androidx/benchmark/perfetto/PerfettoHelper.kt
M benchmark/benchmark-macro/src/androidTest/java/androidx/benchmark/macro/perfetto/AndroidxTracingTraceTest.kt
M benchmark/benchmark-macro/src/androidTest/java/androidx/benchmark/macro/perfetto/PerfettoCaptureSweepTest.kt

Hash: a1d00d7f334608a7d4975b209b4569cfdadb2539
Date: Thu Jan 23 16:10:27 2025

di...@target.com <di...@target.com> #19Jun 21, 2023 02:48PM

The following release(s) address this bug.It is possible this bug has only been partially addressed:

androidx.benchmark:benchmark-common:1.4.0-alpha08
androidx.benchmark:benchmark-macro:1.4.0-alpha08

ma...@google.com <ma...@google.com> #20Jun 21, 2023 05:51PM

That task is internal.

This task can be fixed only when that one is completed.

za...@gmail.com <za...@gmail.com> #21Jan 10, 2024 11:34PM

Could the internal issue be made public? It's not clear from the (sparse) docs I could find on managed devices and baseline profile generation that only GMDs were supported.

be...@google.com <be...@google.com> #22Jan 15, 2024 11:03AM

Thanks for flagging this problem. If you're facing it, use the +1 button.
This issue will be added to the known issues on Baseline Profiles documentation for the time being.

li...@gmail.com <li...@gmail.com> #23Aug 23, 2024 04:38PM

I've come to this issue from the list of known issues of Baseline Profiles plugin. There it says:

Baseline Profile generation isn't supported on Firebase Test Lab devices, including Gradle-managed Test Lab devices

However, comment #5 states that:

When testing the application on a physical device (from FTL) with API 33, the profiles were successfully generated.

So, does it mean that it's actually possible to generate baseline profile using FTL devices?

se...@team.bumble.com <se...@team.bumble.com> #24Aug 27, 2024 11:24AM

FWIW, I can generate baseline profiles using FTL ARM device but without AndroidX Baseline Profile Gradle plugin. The FTL Gradle plugin currently doesn't honour instrumentation runner arguments (see b/328216014). As a workaround, I'm passing them via the instrumentation APK manifest.
It would be great if AndroidX Baseline Profile and FTL plugins could finally work properly together, but I don't get my hopes up as the FTL plugin has seen very little development this year.

Message last modified on Sep 13, 2024 12:48PM

li...@gmail.com <li...@gmail.com> #25Sep 8, 2024 03:55PM

FWIW, I can generate baseline profiles using FTL ARM device but without AndroidX Benchmark Gradle plugin.

Do you mean w/o androidx.baselineprofile plugin? How do you run the benchmarks/fetch the profiles then? It would be awesome if you could share your setup.

Message last modified on Sep 8, 2024 03:56PM

bu...@google.com <bu...@google.com> Sep 12, 2024 11:03PM

Assigned to ma...@google.com.

se...@team.bumble.com <se...@team.bumble.com> #26Sep 13, 2024 01:00PM

#25 indeed, I meant Baseline profile Gradle plugin. What I did basically is follow this guide to configure FTL in a standalone test module (com.android.test), and tell FTL plugin to pull the contents of the package-specific media directory where the generated baseline profiles are saved.

plugins {
    id("com.google.firebase.testlab")
}

testLab {
    managedDevices{
        create("firebaseSmallPhone") {
            device = "SmallPhone.arm"
            apiLevel = 34
        }
    }

    testOptions {
        results {
            directoriesToPull.set(
                listOf("/sdcard/Android/media/${android.namespace}")
            )
        }
    }
}

At the end of the build, I copy the pulled baseline profile to the src directory:

find <path to baseline profile module>/build/outputs -name '*-baseline-prof.txt' \
  -exec cp {} <path to app module>/src/main/baselineProfiles/baseline-prof.txt \;

Message last modified on Sep 13, 2024 01:02PM

li...@gmail.com <li...@gmail.com> #27Sep 13, 2024 03:08PM

https://issuetracker.google.com/issues/285187547#comment26

Thanks!

Could you please specify how you launch a baseline profile generator with this setup? Simply as an instrumentation test?

A little side note. I though that the whole issue is that the folder, where profiles are generated, is always different on an FTL device. With the above setup, what actually prevent you from using the Baseline Profile plugin?

Message last modified on Sep 16, 2024 04:08PM

ma...@google.com <ma...@google.com> #28Sep 17, 2024 11:36PM

With aosp/3267102, the ftl plugin can now be used with the baseline profile gradle plugin as well. This will be added in version 1.3.2.

In order to use, simply add a baseline profile module, for example :baselineprofile and add the following to build.gradle:

plugins {
    ...
    id("androidx.baselineprofile")
    id("com.google.firebase.testlab")
}

...

firebaseTestLab {

    // Credentials for FTL service
    serviceAccountCredentials.set(file("credentials.json"))

    // Creates one or more managed devices to run the tests on.
    managedDevices {
        "ftlDeviceShiba34" {
            device = "shiba"
            apiLevel = 34
        }
    }

    // Ensures the baseline profile are pulled from the device.
    // Note that this will be automated as well later with aosp/3272935.
    testOptions {
        results {
            directoriesToPull.addAll(\"/storage/emulated/0/Android/media/${android.namespace}\")
        }
    }
}

baselineProfile {
    ...
    managedDevices += "ftlDeviceShiba34"
    useConnectedDevices = false
}

Message last modified on Sep 18, 2024 09:18PM

ap...@google.com <ap...@google.com> #29Sep 18, 2024 10:56PM

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

commit 7e25ec644b2fd621b7a96016f9e397dab254540d
Author: Marcello Albano <maralb@google.com>
Date: Tue Sep 17 15:11:56 2024

Added support for FTL to Baseline Profile Gradle Plugin

FTL devices don't use per test artifacts, rather global ones,
so in test-results.pb they need to be found separately.
Note that the ftl plugin still needs to be configured separately.

Relnote: "Added support for FTL to Baseline Profile Gradle Plugin.
To use FTL apply the plugin to the baseline profile module in the
plugin block, with:
```
plugins {
...
id(\"com.google.firebase.testlab\")
}
```

and then configure firebase test lab with:

```
firebaseTestLab {

// Credentials for FTL service
serviceAccountCredentials.set(file(\"credentials.json\"))

// Creates one or more managed devices to run the tests on.
managedDevices {
\"ftlDeviceShiba34\" {
device = \"shiba\"
apiLevel = 34
}
}

// Ensures the baseline profile are pulled from the device.
// Note that this will be automated as well later with aosp/3272935.
testOptions {
results {
directoriesToPull.addAll(\"/storage/emulated/0/Android/media/${android.namespace}\")
}
}
}
```

Also the created ftl device needs to be added to the baseline profile extension:

```
baselineProfile {
managedDevices += \"ftlDeviceShiba34\"
useConnectedDevices = false
}
```"
Test: ./gradlew :benchmark:benchmark-baseline-profile-gradle-plugin:test
Bug: 285187547

Change-Id: I2f6789d81a32d04df976437c2be426cbe04488ac

M benchmark/baseline-profile-gradle-plugin/src/main/kotlin/androidx/baselineprofile/gradle/producer/tasks/CollectBaselineProfileTask.kt
M benchmark/baseline-profile-gradle-plugin/src/test/kotlin/androidx/baselineprofile/gradle/consumer/BaselineProfileConsumerPluginTest.kt
M benchmark/baseline-profile-gradle-plugin/src/test/kotlin/androidx/baselineprofile/gradle/utils/BaselineProfileProjectSetupRule.kt
M benchmark/baseline-profile-gradle-plugin/src/test/kotlin/androidx/baselineprofile/gradle/utils/TestUtils.kt

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

li...@gmail.com <li...@gmail.com> #30Sep 21, 2024 08:25PM

I apologise for posting an offtopic, but attempting to setup Baseline Profiles generation, using the above instructions and FTL Gradle plugin, I've encountered a strange dependency issue: https://issuetracker.google.com/issues/368628050

Firebase section of the issue tracker is not available for me, so posting a reference here with a hope, that somebody with access could check for duplicates and maybe suggest a solution.

ma...@google.com <ma...@google.com> #31Oct 1, 2024 05:18PM

Marked as fixed.

Thanks, the dependency issue is a different one already been tracked. Closing this one.

li...@gmail.com <li...@gmail.com> #32Oct 1, 2024 08:59PM