Fixed
Status Update
No update yet.
Comments
mo...@google.com
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
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
cc...@google.com
ap...@google.com
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
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)
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)
au...@google.com
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
cc...@google.com
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")
}
```
```
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")
}
```
cc...@google.com
But even using just the MacrobenchmarkRule, it has the same issue w/ perfectto process not being killed...
ap...@google.com
Running killall in an adb shell doesn't work too:
```
$ killall perfetto
killall: pid 19422: Operation not permitted
killall: perfetto: Operation not permitted
```
```
$ killall perfetto
killall: pid 19422: Operation not permitted
killall: perfetto: Operation not permitted
```
cc...@google.com
ap...@google.com
restarting the device also doesn't seem to help
cc...@google.com
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).
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).
ab...@gmail.com
Workaround for me was try a different device. Samsung S23 Ultra w/ Android 14 works w/o that perfetto kill permission error.
Description
Because the sampling profiler has trouble giving accurate results, the recommendation is to use simpleperf. Documentation on how to set it up would be helpful.
Making it automatic from gradle would be even more helpful, if it is possible.