dropShaderCache test crash on 1.2.0-alpha07 [API 30] [259508183]

Fixed

Bug

Status Update

No update yet.

Description

la...@team.bumble.com

created issue #1

Nov 17, 2022 05:35PM

Component used: Macrobenchmark, profileinstaller

Version used: 1.2.0-alpha07 (Macrobenchmark), 1.3.0-alpha02 (profileinstaller)

Devices/Android versions reproduced on: Samsung SM-A415F/SM-A217F (API 30) [not-rooted]

Hi!

I'm trying to update to macrobenchmark 1.2.0-alpha06 to 1.2.0-alpha07, and unfortunately due to the latest change relating to the dropShaderCache (or perhaps 'safe shell commands' - https://android-review.googlesource.com/c/platform/frameworks/support/+/2267992) macrobenchmark is failing on the first iteration of the test run.

java.lang.IllegalStateException: Expected no stderr from echo 3 > /proc/sys/vm/drop_caches && echo Success || echo Failure, saw /storage/emulated/0/Android/media/com.badoo.mobile.macrobenchmark/temporaryScript7432334656308310021.tmp[2]: can't create /proc/sys/vm/drop_caches: Permission denied
	at androidx.benchmark.Shell.executeScriptCaptureStdout(Shell.kt:217)
	at androidx.benchmark.Shell.executeScriptCaptureStdout$default(Shell.kt:215)
	at androidx.benchmark.macro.MacrobenchmarkScope.dropKernelPageCache(MacrobenchmarkScope.kt:297)
	at androidx.benchmark.macro.MacrobenchmarkKt$macrobenchmarkWithStartupMode$1.invoke(Macrobenchmark.kt:389)
	at androidx.benchmark.macro.MacrobenchmarkKt$macrobenchmarkWithStartupMode$1.invoke(Macrobenchmark.kt:365)
	at androidx.benchmark.macro.MacrobenchmarkKt$macrobenchmark$measurements$1.invoke(Macrobenchmark.kt:208)
	at androidx.benchmark.macro.MacrobenchmarkKt$macrobenchmark$measurements$1.invoke(Macrobenchmark.kt:199)
	at androidx.benchmark.macro.perfetto.PerfettoTraceProcessor$Companion.runServer(PerfettoTraceProcessor.kt:70)
	at androidx.benchmark.macro.perfetto.PerfettoTraceProcessor$Companion.runServer$default(PerfettoTraceProcessor.kt:53)
	at androidx.benchmark.macro.MacrobenchmarkKt.macrobenchmark(Macrobenchmark.kt:199)
	at androidx.benchmark.macro.MacrobenchmarkKt.macrobenchmarkWithStartupMode(Macrobenchmark.kt:365)
	at androidx.benchmark.macro.junit4.MacrobenchmarkRule.measureRepeated(MacrobenchmarkRule.kt:106)
	at com.badoo.mobile.macrobenchmark.BadooStartupBenchmark.measureAppStartup(BadooStartupBenchmark.kt:21)

Any tips to avoid this crash? Or is it possibly a bug with the latest version?

Comments

cc...@google.com <cc...@google.com> #2Nov 17, 2022 06:23PM

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

la...@team.bumble.com <la...@team.bumble.com> #3Nov 17, 2022 06:27PM

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

ap...@google.com <ap...@google.com> #4Nov 19, 2022 05:28AM

Marked as fixed.

Hey I'm still seeing this issue with 1.3.0-alpha01, this is the stack:

java.lang.IllegalStateException: Failed to stop [ProcessPid(processName=perfetto, pid=2784)]
at androidx.benchmark.Shell.terminateProcessesAndWait(Shell.kt:596)
at androidx.benchmark.perfetto.PerfettoHelper.stopPerfetto(PerfettoHelper.kt:258)
at androidx.benchmark.perfetto.PerfettoHelper.stopCollecting(PerfettoHelper.kt:236)
at androidx.benchmark.perfetto.PerfettoCapture.stop(PerfettoCapture.kt:87)
at androidx.benchmark.perfetto.PerfettoCaptureWrapper$stop$1.invoke(PerfettoCaptureWrapper.kt:91)
at androidx.benchmark.perfetto.PerfettoCaptureWrapper$stop$1.invoke(PerfettoCaptureWrapper.kt:88)
at androidx.benchmark.Outputs.writeFile(Outputs.kt:136)
at androidx.benchmark.Outputs.writeFile$default(Outputs.kt:125)
at androidx.benchmark.perfetto.PerfettoCaptureWrapper.stop(PerfettoCaptureWrapper.kt:88)
at androidx.benchmark.perfetto.PerfettoCaptureWrapper.record(PerfettoCaptureWrapper.kt:145)
at androidx.benchmark.perfetto.PerfettoCaptureWrapper.record$default(PerfettoCaptureWrapper.kt:101)
at androidx.benchmark.macro.MacrobenchmarkKt$macrobenchmark$measurements$1.invoke(Macrobenchmark.kt:271)
at androidx.benchmark.macro.MacrobenchmarkKt$macrobenchmark$measurements$1.invoke(Macrobenchmark.kt:255)
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:438)
at androidx.benchmark.macro.junit4.MacrobenchmarkRule.measureRepeated(MacrobenchmarkRule.kt:107)
at com.meta.compose.macrobenchmark.scroll.HomeFeedScrollBenchmark.scroll(HomeFeedScrollBenchmark.kt:43)
at com.meta.compose.macrobenchmark.scroll.HomeFeedScrollBenchmark.noCompilation(HomeFeedScrollBenchmark.kt:35)

ju...@google.com <ju...@google.com> #5Dec 7, 2022 06:36PM

@ #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?

la...@team.bumble.com <la...@team.bumble.com> #6Dec 8, 2022 12:30PM

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

Issue 259508183