java.lang.IllegalStateException: Perfetto unexpected exit code, output = 9462 [244621251]

Duplicate

of 282191686

Bug

Status Update

No update yet.

Description

st...@axelspringer.com

created issue #1

Sep 2, 2022 01:21PM

Component used: androidx.benchmark:benchmark-macro-junit4:1.2.0-alpha02 Version used: Devices/Android versions reproduced on: HTC One M9 (Android 6)

If this is a bug in the library, we would appreciate if you could attach:

Sample project to trigger the issue. N/A
A screenrecord or screenshots showing the issue (if UI related). N/A

logs:

2022-09-02 15:16:18.640 9160-9173/de.welt.benchmark D/Benchmark: resetting persist.traced.enable to 
2022-09-02 15:16:18.640 9160-9173/de.welt.benchmark D/Benchmark: Killing process de.cellular.n24hybrid
2022-09-02 15:16:19.696 9160-9173/de.welt.benchmark E/TestRunner: failed: coldStartup(de.welt.benchmark.StartupBenchmark)
2022-09-02 15:16:19.696 9160-9173/de.welt.benchmark E/TestRunner: ----- begin exception -----
2022-09-02 15:16:19.699 9160-9173/de.welt.benchmark E/TestRunner: java.lang.IllegalStateException:             Perfetto unexpected exit code, output = 9462
    EXITCODE=2
                Please report a bug, and include a logcat capture of the test run and failure.
                DeviceInfo(Brand=htc, Model=HTC One M9, SDK=23, BuildFp=htc/himauhl_o2_uk/htc_himauhl:6.0/MRA58K/670363.13:user/release-keys)
        at androidx.benchmark.perfetto.PerfettoHelper.perfettoStartupException(PerfettoHelper.kt:61)
        at androidx.benchmark.perfetto.PerfettoHelper.startCollecting(PerfettoHelper.kt:118)
        at androidx.benchmark.perfetto.PerfettoCapture.start(PerfettoCapture.kt:77)
        at androidx.benchmark.perfetto.PerfettoCaptureWrapper.start(PerfettoCaptureWrapper.kt:46)
        at androidx.benchmark.perfetto.PerfettoCaptureWrapper.record(PerfettoCaptureWrapper.kt:87)
        at androidx.benchmark.macro.MacrobenchmarkKt.macrobenchmark(Macrobenchmark.kt:167)
        at androidx.benchmark.macro.MacrobenchmarkKt.macrobenchmarkWithStartupMode(Macrobenchmark.kt:301)
        at androidx.benchmark.macro.junit4.MacrobenchmarkRule.measureRepeated(MacrobenchmarkRule.kt:106)
        at androidx.benchmark.macro.junit4.MacrobenchmarkRule.measureRepeated$default(MacrobenchmarkRule.kt:96)
        at de.welt.benchmark.StartupBenchmark.coldStartup(StartupBenchmark.kt:29)
        at java.lang.reflect.Method.invoke(Native Method)
        at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
        at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
        at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
        at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
        at androidx.benchmark.macro.junit4.MacrobenchmarkRule$applyInternal$1.evaluate(MacrobenchmarkRule.kt:132)
        at androidx.test.rule.GrantPermissionRule$RequestPermissionStatement.evaluate(GrantPermissionRule.java:134)
        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:56)
        at androidx.test.runner.AndroidJUnitRunner.onStart(AndroidJUnitRunner.java:444)
        at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1996)
2022-09-02 15:16:19.699 9160-9173/de.welt.benchmark E/TestRunner: ----- end exception -----
2022-09-02 15:16:19.704 9160-9173/de.welt.benchmark I/TestRunner: finished: coldStartup(de.welt.benchmark.StartupBenchmark)
2022-09-02 15:16:19.730 9160-9173/de.welt.benchmark I/TestRunner: started: warmStartup(de.welt.benchmark.StartupBenchmark)
2022-09-02 15:16:19.736 9160-9173/de.welt.benchmark I/GrantPermissionCallable: Permission: android.permission.READ_EXTERNAL_STORAGE is already granted!
2022-09-02 15:16:19.736 9160-9173/de.welt.benchmark I/GrantPermissionCallable: Permission: android.permission.WRITE_EXTERNAL_STORAGE is already granted!
2022-09-02 15:16:19.758 9160-9173/de.welt.benchmark D/Benchmark: Killing process de.cellular.n24hybrid
2022-09-02 15:16:20.819 9160-9173/de.welt.benchmark D/Benchmark: Starting activity with command: am start -W "intent:#Intent;action=android.intent.action.MAIN;category=android.intent.category.LAUNCHER;launchFlags=0x10008000;package=de.cellular.n24hybrid;component=de.cellular.n24hybrid/de.weltn24.news.main.view.MainScreenActivity;end"
2022-09-02 15:16:25.501 9160-9173/de.welt.benchmark D/Benchmark: Result: Starting: Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10008000 pkg=de.cellular.n24hybrid cmp=de.cellular.n24hybrid/de.weltn24.news.main.view.MainScreenActivity }
    Status: ok
    Activity: de.cellular.n24hybrid/de.weltn24.news.main.view.MainScreenActivity
    ThisTime: 3537
    TotalTime: 3537
    WaitTime: 3564
    Complete
2022-09-02 15:16:25.582 9160-9173/de.welt.benchmark I/System.out: 0 Flags,IntendedVsync,Vsync,OldestInputEvent,NewestInputEvent,HandleInputStart,AnimationStart,PerformTraversalsStart,DrawStart,SyncQueued,SyncStart,IssueDrawCommandsStart,SwapBuffers,FrameCompleted,
2022-09-02 15:16:25.582 9160-9173/de.welt.benchmark I/System.out: 1 0,271396692896,271863359572,9223372036854775807,0,271868986354,271869014583,271870212968,271872528906,271894617239,271894699166,271896822291,272108287760,272115426875,
2022-09-02 15:16:25.582 9160-9173/de.welt.benchmark I/System.out: 2 0,271881132766,272164466105,9223372036854775807,0,272180462604,272180492812,272189667083,272198765625,272226348489,272226413177,272228232656,272243359791,272244183125,
2022-09-02 15:16:25.582 9160-9173/de.welt.benchmark I/System.out: 0 Flags,IntendedVsync,Vsync,OldestInputEvent,NewestInputEvent,HandleInputStart,AnimationStart,PerformTraversalsStart,DrawStart,SyncQueued,SyncStart,IssueDrawCommandsStart,SwapBuffers,FrameCompleted,
2022-09-02 15:16:25.582 9160-9173/de.welt.benchmark I/System.out: 1 0,271396692896,271863359572,9223372036854775807,0,271868986354,271869014583,271870212968,271872528906,271894617239,271894699166,271896822291,272108287760,272115426875,
2022-09-02 15:16:25.582 9160-9173/de.welt.benchmark I/System.out: 2 0,271881132766,272164466105,9223372036854775807,0,272180462604,272180492812,272189667083,272198765625,272226348489,272226413177,272228232656,272243359791,272244183125,
2022-09-02 15:16:25.583 9160-9173/de.welt.benchmark D/PerfettoCapture: Supported ABIs: arm64-v8a, armeabi-v7a, armeabi
2022-09-02 15:16:25.600 9160-9173/de.welt.benchmark D/Benchmark: setting persist.traced.enable to 1 (was )
2022-09-02 15:16:25.622 9160-9173/de.welt.benchmark D/PerfettoCapture: Recording perfetto trace
2022-09-02 15:16:25.628 9160-9173/de.welt.benchmark I/PerfettoCapture: Cleanup perfetto before starting.
2022-09-02 15:16:25.720 9160-9173/de.welt.benchmark D/Benchmark: kill -TERM command output - 
2022-09-02 15:16:25.742 9160-9173/de.welt.benchmark D/Benchmark: kill -TERM command output - 
2022-09-02 15:16:25.763 9160-9173/de.welt.benchmark D/Benchmark: kill -TERM command output - 
2022-09-02 15:16:25.939 9160-9173/de.welt.benchmark D/Benchmark: Waiting 100 ms for [ProcessPid(processName=tracebox, pid=9462)] to die
2022-09-02 15:16:26.039 9160-9173/de.welt.benchmark I/PerfettoCapture: Perfetto output file cleanup - 
2022-09-02 15:16:26.039 9160-9173/de.welt.benchmark I/PerfettoCapture: Starting perfetto tracing with cmd: /data/local/tmp/tracebox --background-wait -c /data/local/tmp/config.pb -o /data/local/tmp/trace_output.pb
2022-09-02 15:16:56.193 9160-9173/de.welt.benchmark D/Benchmark: resetting persist.traced.enable to 
2022-09-02 15:16:56.193 9160-9173/de.welt.benchmark D/Benchmark: Killing process de.cellular.n24hybrid
2022-09-02 15:16:57.417 9160-9173/de.welt.benchmark E/TestRunner: failed: warmStartup(de.welt.benchmark.StartupBenchmark)
2022-09-02 15:16:57.417 9160-9173/de.welt.benchmark E/TestRunner: ----- begin exception -----
2022-09-02 15:16:57.418 9160-9173/de.welt.benchmark E/TestRunner: java.lang.IllegalStateException:             Perfetto unexpected exit code, output = 9803
    EXITCODE=2
                Please report a bug, and include a logcat capture of the test run and failure.
                DeviceInfo(Brand=htc, Model=HTC One M9, SDK=23, BuildFp=htc/himauhl_o2_uk/htc_himauhl:6.0/MRA58K/670363.13:user/release-keys)
        at androidx.benchmark.perfetto.PerfettoHelper.perfettoStartupException(PerfettoHelper.kt:61)
        at androidx.benchmark.perfetto.PerfettoHelper.startCollecting(PerfettoHelper.kt:118)
        at androidx.benchmark.perfetto.PerfettoCapture.start(PerfettoCapture.kt:77)
        at androidx.benchmark.perfetto.PerfettoCaptureWrapper.start(PerfettoCaptureWrapper.kt:46)
        at androidx.benchmark.perfetto.PerfettoCaptureWrapper.record(PerfettoCaptureWrapper.kt:87)
        at androidx.benchmark.macro.MacrobenchmarkKt.macrobenchmark(Macrobenchmark.kt:167)
        at androidx.benchmark.macro.MacrobenchmarkKt.macrobenchmarkWithStartupMode(Macrobenchmark.kt:301)
        at androidx.benchmark.macro.junit4.MacrobenchmarkRule.measureRepeated(MacrobenchmarkRule.kt:106)
        at androidx.benchmark.macro.junit4.MacrobenchmarkRule.measureRepeated$default(MacrobenchmarkRule.kt:96)
        at de.welt.benchmark.StartupBenchmark.warmStartup(StartupBenchmark.kt:40)
        at java.lang.reflect.Method.invoke(Native Method)
        at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
        at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
        at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
        at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
        at androidx.benchmark.macro.junit4.MacrobenchmarkRule$applyInternal$1.evaluate(MacrobenchmarkRule.kt:132)
        at androidx.test.rule.GrantPermissionRule$RequestPermissionStatement.evaluate(GrantPermissionRule.java:134)
        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:56)
        at androidx.test.runner.AndroidJUnitRunner.onStart(AndroidJUnitRunner.java:444)
        at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1996)
2022-09-02 15:16:57.418 9160-9173/de.welt.benchmark E/TestRunner: ----- end exception -----
2022-09-02 15:16:57.419 9160-9173/de.welt.benchmark I/TestRunner: finished: warmStartup(de.welt.benchmark.StartupBenchmark)
2022-09-02 15:16:57.422 9160-9173/de.welt.benchmark I/TestRunner: run finished: 2 tests, 2 failed, 0 ignored
2022-09-02 15:16:57.429 9160-9173/de.welt.benchmark I/MonitoringInstr: waitForActivitiesToComplete() took: 0ms

Comments

cc...@google.com <cc...@google.com> Sep 2, 2022 07:12PM

Reassigned to ma...@google.com.

ma...@google.com <ma...@google.com> #2Oct 3, 2022 09:17PM

This is logged here. The values are PIDs of the subprocesses:

2022-09-02 15:16:19.699 9160-9173/de.welt.benchmark E/TestRunner: java.lang.IllegalStateException:             Perfetto unexpected exit code, output = 9462
    EXITCODE=2

2022-09-02 15:16:57.418 9160-9173/de.welt.benchmark E/TestRunner: java.lang.IllegalStateException:             Perfetto unexpected exit code, output = 9803
    EXITCODE=2

And the actual error code is 2.

Looking at perfetto code, it seems that not all the data sources are ready (code). Data sources are defined here.

I wonder if some of those data sources are not supported on that device that runs Android 6.

cc...@google.com <cc...@google.com> #3Dec 12, 2022 10:13PM

Agree, likely related to b/259389420. I expect we updated perfetto since alpha02, so it's possible this doesn't reproduce now in alpha08 (see b/259389420#comment4).

cc...@google.com <cc...@google.com> Dec 12, 2022 11:24PM

Reassigned to cc...@google.com.

cc...@google.com <cc...@google.com> #4May 12, 2023 05:57PM

Status: Duplicate of

282191686

Given that we saw a number of emulators not correctly configured for tracing with the same exit code, this is most likely a dupe.

ou...@gmail.com <ou...@gmail.com> #5Sep 4, 2023 08:10AM

I am getting a similar error when running a simple app startup benchmark on Pixel 6 running on Android 14

java.lang.IllegalStateException: Failed to stop [ProcessPid(processName=perfetto, pid=18066)]

lo...@onepeloton.com <lo...@onepeloton.com> #6Sep 5, 2023 09:44PM

Seeing a similar issue while running benchmark tests on Pixel 6 Pro running Android 14.

java.lang.IllegalStateException: Failed to stop [ProcessPid(processName=perfetto, pid=28209)] at androidx.benchmark.Shell.terminateProcessesAndWait(Shell.kt:596) at androidx.benchmark.Shell.terminateProcessesAndWait(Shell.kt:565) at androidx.benchmark.perfetto.PerfettoHelper$Companion.stopAllPerfettoProcesses(PerfettoHelper.kt:443) at androidx.benchmark.perfetto.PerfettoHelper.startCollecting(PerfettoHelper.kt:93) at androidx.benchmark.perfetto.PerfettoCapture.start(PerfettoCapture.kt:72) at androidx.benchmark.perfetto.PerfettoCaptureWrapper.start(PerfettoCaptureWrapper.kt:70) at androidx.benchmark.perfetto.PerfettoCaptureWrapper.record(PerfettoCaptureWrapper.kt:127) at androidx.benchmark.perfetto.PerfettoCaptureWrapper.record$default(PerfettoCaptureWrapper.kt:92) at androidx.benchmark.macro.MacrobenchmarkKt$macrobenchmark$measurements$1.invoke(Macrobenchmark.kt:256) at androidx.benchmark.macro.MacrobenchmarkKt$macrobenchmark$measurements$1.invoke(Macrobenchmark.kt:241) at androidx.benchmark.perfetto.PerfettoTraceProcessor$Companion.runServer(PerfettoTraceProcessor.kt:105) at androidx.benchmark.macro.MacrobenchmarkKt.macrobenchmark(Macrobenchmark.kt:241) at androidx.benchmark.macro.MacrobenchmarkKt.macrobenchmarkWithStartupMode(Macrobenchmark.kt:415) at androidx.benchmark.macro.junit4.MacrobenchmarkRule.measureRepeated(MacrobenchmarkRule.kt:107)

sa...@gmail.com <sa...@gmail.com> #7Sep 18, 2023 10:05PM

On the running macrobenchmark test on the emulator working fine, but failing on Pixel 6a Android 14 (Physical device) 🧐

Facing the same error

java.lang.IllegalStateException: Failed to stop [ProcessPid(processName=perfetto, pid=26338)]
at androidx.benchmark.Shell.terminateProcessesAndWait(Shell.kt:596)
at androidx.benchmark.Shell.terminateProcessesAndWait(Shell.kt:565)
at androidx.benchmark.perfetto.PerfettoHelper$Companion.stopAllPerfettoProcesses(PerfettoHelper.kt:441)
at androidx.benchmark.perfetto.PerfettoHelper.startCollecting(PerfettoHelper.kt:92)
at androidx.benchmark.perfetto.PerfettoCapture.start(PerfettoCapture.kt:72)
at androidx.benchmark.perfetto.PerfettoCaptureWrapper.start(PerfettoCaptureWrapper.kt:68)
at androidx.benchmark.perfetto.PerfettoCaptureWrapper.record(PerfettoCaptureWrapper.kt:124)
at androidx.benchmark.perfetto.PerfettoCaptureWrapper.record$default(PerfettoCaptureWrapper.kt:90)
at androidx.benchmark.macro.MacrobenchmarkKt$macrobenchmark$measurements$1.invoke(Macrobenchmark.kt:243)
at androidx.benchmark.macro.MacrobenchmarkKt$macrobenchmark$measurements$1.invoke(Macrobenchmark.kt:228)
at androidx.benchmark.perfetto.PerfettoTraceProcessor$Companion.runServer(PerfettoTraceProcessor.kt:105)
at androidx.benchmark.macro.MacrobenchmarkKt.macrobenchmark(Macrobenchmark.kt:228)
at androidx.benchmark.macro.MacrobenchmarkKt.macrobenchmarkWithStartupMode(Macrobenchmark.kt:405)
at androidx.benchmark.macro.junit4.MacrobenchmarkRule.measureRepeated(MacrobenchmarkRule.kt:107)
at androidx.benchmark.macro.junit4.MacrobenchmarkRule.measureRepeated$default(MacrobenchmarkRule.kt:97)

Message last modified on Sep 18, 2023 10:08PM

sa...@gmail.com <sa...@gmail.com> #8Sep 18, 2023 10:26PM

Updating the dependency from androidx.benchmark:benchmark-macro-junit4:1.2.0-beta01 to androidx.benchmark:benchmark-macro-junit4:1.2.0-beta05 solved it :)

sa...@gmail.com <sa...@gmail.com> #9Sep 19, 2023 12:12PM

getting the error again 😭 I've updated my Android 14 version to a newest patch, I think that's the suspect

cc...@google.com <cc...@google.com> #10Feb 2, 2024 11:58PM

These Failed to stop issues on Android 14 are separate from the exception in this bug #comment1, splitting off new bug for those: b/323601788