"Broken pipe" exception when running macrobenchmark tests on 1.2.0-alpha09 [269949822]

Fixed

Bug

Status Update

No update yet.

Description

sc...@gmail.com

created issue #1

Feb 20, 2023 07:02PM

Hi!

For the following setup:

Component used: androidx.benchmark:benchmark-macro-junit4

Version used: 1.2.0-alpha09

Devices/Android versions reproduced on: Zenfone 9 (Android 13) / Pixel 3A (Android 12)

IDE: Android Studio Giraffe + AGP 7.4.1

Gradle 7.6

  private fun startup(
    compilationMode: CompilationMode,
    startupMode: StartupMode
  ) = benchmarkRule.measureRepeated(
    packageName = PROD_PACKAGE_NAME,
    metrics = listOf(
      StartupTimingMetric(),
      FrameTimingMetric()
    ),
    iterations = 5,
    compilationMode = compilationMode,
    startupMode = startupMode,
    setupBlock = {
      startActivityAndWait()
      device.signIn()
      pressHome()
    },
  ) {
    startActivityAndWait()

    device.swipeFeed()

    device.waitForIdle()
  }

I keep getting the following exception randomly during test execution:

java.net.SocketException: Broken pipe
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:116)
at java.net.SocketOutputStream.write(SocketOutputStream.java:156)
at com.android.okhttp.okio.Okio$1.write(Okio.java:78)
at com.android.okhttp.okio.AsyncTimeout$1.write(AsyncTimeout.java:157)
at com.android.okhttp.okio.RealBufferedSink.emitCompleteSegments(RealBufferedSink.java:177)
at com.android.okhttp.okio.RealBufferedSink.write(RealBufferedSink.java:47)
at com.android.okhttp.internal.http.RetryableSink.writeToSocket(RetryableSink.java:80)
at com.android.okhttp.internal.http.Http1xStream.writeRequestBody(Http1xStream.java:234)
at com.android.okhttp.internal.http.HttpEngine.readResponse(HttpEngine.java:618)
at com.android.okhttp.internal.huc.HttpURLConnectionImpl.execute(HttpURLConnectionImpl.java:475)
at com.android.okhttp.internal.huc.HttpURLConnectionImpl.getResponse(HttpURLConnectionImpl.java:411)
at com.android.okhttp.internal.huc.HttpURLConnectionImpl.getInputStream(HttpURLConnectionImpl.java:248)
at androidx.benchmark.macro.perfetto.server.PerfettoHttpServer.httpRequest(PerfettoHttpServer.kt:276)
at androidx.benchmark.macro.perfetto.server.PerfettoHttpServer.httpRequest$default(PerfettoHttpServer.kt:257)
at androidx.benchmark.macro.perfetto.server.PerfettoHttpServer.parse(PerfettoHttpServer.kt:217)
at androidx.benchmark.macro.perfetto.PerfettoTraceProcessor.loadTrace(PerfettoTraceProcessor.kt:111)
at androidx.benchmark.macro.MacrobenchmarkKt$macrobenchmark$measurements$1.invoke(Macrobenchmark.kt:255)
at androidx.benchmark.macro.MacrobenchmarkKt$macrobenchmark$measurements$1.invoke(Macrobenchmark.kt:201)
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:201)
at androidx.benchmark.macro.MacrobenchmarkKt.macrobenchmarkWithStartupMode(Macrobenchmark.kt:367)
at androidx.benchmark.macro.junit4.MacrobenchmarkRule.measureRepeated(MacrobenchmarkRule.kt:107)
at my.company.benchmark.FeedScrollingBenchmark.startup(FeedScrollingBenchmark.kt:65)

Happens on both of my devices. It was also present in 1.2.0-alpha07 which I tested some time ago.

It seems that this occurs at a random time - sometime just at the beginning of a test or in the middle of it. Happens for both builds with and without baseline profile.

Going back to version 1.1.1 resolves the issue.

Comments

ra...@google.com <ra...@google.com> Feb 21, 2023 05:32PM

Reassigned to ma...@google.com.

ma...@google.com <ma...@google.com> #2Feb 21, 2023 05:50PM

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

sc...@gmail.com <sc...@gmail.com> #3Feb 21, 2023 06:10PM

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

ma...@google.com <ma...@google.com> #4Feb 21, 2023 06:11PM

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)

af...@gmail.com <af...@gmail.com> #5Apr 6, 2023 03:01AM

@ #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> #6Apr 19, 2023 10:42AM

Comment has been deleted.

Message last modified on Apr 19, 2023 10:42AM

ma...@google.com <ma...@google.com> #7Apr 19, 2023 10:53PM

Accepted by ma...@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")
}
```

ma...@google.com <ma...@google.com> #8Apr 25, 2023 03:22PM

Marked as fixed.

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

ap...@google.com <ap...@google.com> #9Apr 25, 2023 03:23PM

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

na...@google.com <na...@google.com> #10May 3, 2023 06:24PM

restarting the device also doesn't seem to help