java.io.FileNotFoundException: http://localhost:9001/status - PerfettoHttpServer [329145808]

Fixed

Bug

Status Update

No update yet.

Description

en...@meta.com

created issue #1

Mar 12, 2024 09:25AM

Component used: Version used: Benchmark-Macro v1.2.3 Devices/Android versions reproduced on: Android emulator (API 30)

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

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

Using v1.2.3 of the benchmark-macro library on an emulator is yielding the below error which hangs my test.

I have attempted to add android:usesCleartextTraffic="true" to my instrumentation apk and confirmed that it was present in the merged manifest for the instrumentation apk. I also did a get request to the same url via adb shell which yielded a http status code 200 via "nc localhost 9001" with a "GET /status HTTP/1.1" request which yielded the following response for the perfetto server:

HTTP/1.1 200 OK
Cache-Control: no-cache
Content-Type: application/x-protobuf
Transfer-Encoding: identity
Content-Length: 73
Connection: keep-alive

I do notice that the perfetto log for starting the server successfully happens after the failure so I'm wondering if there's a race between the 2 processes.

Error stack trace:

03-11 23:23:12.827  6794  6816 E TestRunner: java.io.FileNotFoundException: http://localhost:9001/status
03-11 23:23:12.827  6794  6816 E TestRunner:    at com.android.okhttp.internal.huc.HttpURLConnectionImpl.getInputStream(HttpURLConnectionImpl.java:255)
03-11 23:23:12.827  6794  6816 E TestRunner:    at androidx.benchmark.macro.perfetto.server.PerfettoHttpServer.httpRequest(PerfettoHttpServer.kt:289)
03-11 23:23:12.827  6794  6816 E TestRunner:    at androidx.benchmark.macro.perfetto.server.PerfettoHttpServer.httpRequest$default(PerfettoHttpServer.kt:270)
03-11 23:23:12.827  6794  6816 E TestRunner:    at androidx.benchmark.macro.perfetto.server.PerfettoHttpServer.status(PerfettoHttpServer.kt:263)
03-11 23:23:12.827  6794  6816 E TestRunner:    at androidx.benchmark.macro.perfetto.server.PerfettoHttpServer.isRunning(PerfettoHttpServer.kt:185)
03-11 23:23:12.827  6794  6816 E TestRunner:    at androidx.benchmark.macro.perfetto.server.PerfettoHttpServer.startServer(PerfettoHttpServer.kt:135)
03-11 23:23:12.827  6794  6816 E TestRunner:    at androidx.benchmark.perfetto.PerfettoTraceProcessor.startServer(PerfettoTraceProcessor.kt:289)
03-11 23:23:12.827  6794  6816 E TestRunner:    at androidx.benchmark.perfetto.PerfettoTraceProcessor.access$startServer(PerfettoTraceProcessor.kt:74)
03-11 23:23:12.827  6794  6816 E TestRunner:    at androidx.benchmark.perfetto.PerfettoTraceProcessor$Companion.runServer(PerfettoTraceProcessor.kt:101)
03-11 23:23:12.827  6794  6816 E TestRunner:    at androidx.benchmark.macro.MacrobenchmarkKt.macrobenchmark(Macrobenchmark.kt:241)
03-11 23:23:12.827  6794  6816 E TestRunner:    at androidx.benchmark.macro.MacrobenchmarkKt.macrobenchmarkWithStartupMode(Macrobenchmark.kt:422)
03-11 23:23:12.827  6794  6816 E TestRunner:    at androidx.benchmark.macro.junit4.MacrobenchmarkRule.measureRepeated(MacrobenchmarkRule.kt:107)
03-11 23:23:12.827  6794  6816 E TestRunner:    at androidx.benchmark.macro.junit4.MacrobenchmarkRule.measureRepeated$default(MacrobenchmarkRule.kt:97)
03-11 23:23:12.827  6794  6816 E TestRunner:    at XXXXXXX.ColdStartNoneTest.coldStart(ColdStartNoneTest.kt:23)
03-11 23:23:12.827  6794  6816 E TestRunner:    at java.lang.reflect.Method.invoke(Native Method)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
03-11 23:23:12.827  6794  6816 E TestRunner:    at com.facebook.testing.jetpackbenchmark.JetpackBenchmarkRunner$2.evaluate(JetpackBenchmarkRunner.java:82)
03-11 23:23:12.827  6794  6816 E TestRunner:    at androidx.benchmark.macro.junit4.MacrobenchmarkRule$applyInternal$1.evaluate(MacrobenchmarkRule.kt:133)
03-11 23:23:12.827  6794  6816 E TestRunner:    at androidx.test.rule.GrantPermissionRule$RequestPermissionStatement.evaluate(GrantPermissionRule.java:136)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.rules.RunRules.evaluate(RunRules.java:20)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.Suite.runChild(Suite.java:128)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.Suite.runChild(Suite.java:27)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
03-11 23:23:12.827  6794  6816 E TestRunner:    at org.junit.runner.JUnitCore.run(JUnitCore.java:115)
03-11 23:23:12.827  6794  6816 E TestRunner:    at androidx.test.internal.runner.TestExecutor.execute(TestExecutor.java:67)
03-11 23:23:12.827  6794  6816 E TestRunner:    at androidx.test.internal.runner.TestExecutor.execute(TestExecutor.java:58)
03-11 23:23:12.827  6794  6816 E TestRunner:    at com.facebook.testing.instrumentation.AndroidJUnitRunner.onStart(AndroidJUnitRunner.java:497)
03-11 23:23:12.827  6794  6816 E TestRunner:    at com.facebook.testing.instrumentation.FbInstrumentationTestRunner.onStart(FbInstrumentationTestRunner.java:198)
03-11 23:23:12.827  6794  6816 E TestRunner:    at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:2211)
03-11 23:23:12.830  6953  6953 W perfetto:             httpd.cc:99 [HTTP] Starting RPC server on localhost:9001
03-11 23:23:12.831  6953  6953 I perfetto:            httpd.cc:104 [HTTP] This server can be used by reloading https://ui.perfetto.dev and clicking on YES on the "Trace Processor native acceleration" dialog or through the Python API (see https://perfetto.dev/docs/analysis/trace-processor#python-api).

Comments

cc...@google.com <cc...@google.com> Apr 1, 2024 05:40PM

Reassigned to ma...@google.com.

en...@meta.com <en...@meta.com> #2Apr 8, 2024 03:21AM

Project: platform/frameworks/support
Branch: androidx-master-dev

commit c60f33e229e31ab328ef6b59dab63b264954831c
Author: Alexandre Elias <aelias@google.com>
Date: Fri Jul 10 16:23:09 2020

Semantics no-op cleanups

Partly in response to lmr's broad code review, I did a pass of
superficial API/implementation cleanup. The main changes are:

- I changed each Boolean SemanticsProperty where false is equivalent to
not being present to take "Unit" instead. This is conceptually
clearer: it avoids questions like "can I cancel out a semantics from a
merged child by setting it to false?" Because "property = Unit" looks
weird, I also changed the style of these to "property()".

- I moved the Semantics id generator closer to where it's used, in
SemanticsModifierCore. I made it internal and an AtomicInt.
(Note that integer ids are heavily used in the Android
AccessibilityNodeInfo APIs so I can't simply remove them entirely.)

- I deleted dead code. Some examples include SemanticsHintOverrides,
a public API not connected to anything, and SemanticsPropertyKey
merge() open method which is never called. (In both cases I have
a different plan in mind for accessibility.)

Fixes: 145951226
Fixes: 145955412
Test: existing tests
Relnote: "Single-value semantics properties now use a calling style.
For example, 'semantics { hidden = true }' is now written as:
'semantics { hidden() }'."

Change-Id: Ic1afd12ea22c926babc9662f1804d80b33aa0cfc

M ui/integration-tests/benchmark/src/androidTest/java/androidx/ui/benchmark/test/LayoutNodeModifierBenchmark.kt
M ui/ui-core/api/0.1.0-dev15.txt
M ui/ui-core/api/current.txt
M ui/ui-core/api/public_plus_experimental_0.1.0-dev15.txt
M ui/ui-core/api/public_plus_experimental_current.txt
M ui/ui-core/api/restricted_0.1.0-dev15.txt
M ui/ui-core/api/restricted_current.txt
M ui/ui-core/src/androidAndroidTest/kotlin/androidx/ui/graphics/vector/VectorTest.kt
M ui/ui-core/src/androidAndroidTest/kotlin/androidx/ui/semantics/SemanticsTests.kt
M ui/ui-core/src/androidMain/kotlin/androidx/ui/core/AndroidActuals.kt
M ui/ui-core/src/androidMain/kotlin/androidx/ui/core/AndroidComposeView.kt
M ui/ui-core/src/androidMain/kotlin/androidx/ui/core/AndroidComposeViewAccessibilityDelegateCompat.kt
M ui/ui-core/src/androidMain/kotlin/androidx/ui/core/AndroidPopup.kt
M ui/ui-core/src/commonMain/kotlin/androidx/ui/core/Expect.kt
M ui/ui-core/src/commonMain/kotlin/androidx/ui/core/semantics/SemanticsConfiguration.kt
D ui/ui-core/src/commonMain/kotlin/androidx/ui/core/semantics/SemanticsHintOverrides.kt
M ui/ui-core/src/commonMain/kotlin/androidx/ui/core/semantics/SemanticsModifier.kt
M ui/ui-core/src/commonMain/kotlin/androidx/ui/core/semantics/SemanticsNode.kt
M ui/ui-core/src/commonMain/kotlin/androidx/ui/core/semantics/SemanticsOwner.kt
M ui/ui-core/src/commonMain/kotlin/androidx/ui/core/semantics/SemanticsWrapper.kt
M ui/ui-core/src/commonMain/kotlin/androidx/ui/semantics/SemanticsProperties.kt
M ui/ui-foundation/api/0.1.0-dev15.txt
M ui/ui-foundation/api/current.txt
M ui/ui-foundation/api/public_plus_experimental_0.1.0-dev15.txt
M ui/ui-foundation/api/public_plus_experimental_current.txt
M ui/ui-foundation/api/restricted_0.1.0-dev15.txt
M ui/ui-foundation/api/restricted_current.txt
M ui/ui-foundation/src/main/java/androidx/ui/foundation/Clickable.kt
M ui/ui-foundation/src/main/java/androidx/ui/foundation/Dialog.kt
M ui/ui-foundation/src/main/java/androidx/ui/foundation/Scroller.kt
M ui/ui-foundation/src/main/java/androidx/ui/foundation/selection/Selectable.kt
M ui/ui-foundation/src/main/java/androidx/ui/foundation/selection/Toggleable.kt
M ui/ui-foundation/src/main/java/androidx/ui/foundation/semantics/FoundationSemanticsProperties.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/ButtonTest.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/CardTest.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/CheckboxScreenshotTest.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/RadioButtonScreenshotTest.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/ScaffoldTest.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/SnackbarTest.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/SurfaceTest.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/ripple/RippleIndicationTest.kt
M ui/ui-material/src/androidTest/java/androidx/ui/material/textfield/TextFieldScreenshotTest.kt
M ui/ui-material/src/main/java/androidx/ui/material/AppBar.kt
M ui/ui-material/src/main/java/androidx/ui/material/TextFieldImpl.kt
M ui/ui-test/src/androidTest/java/androidx/ui/test/AssertsTest.kt
M ui/ui-test/src/androidTest/java/androidx/ui/test/CallSemanticsActionTest.kt
M ui/ui-test/src/androidTest/java/androidx/ui/test/ErrorMessagesTest.kt
M ui/ui-test/src/androidTest/java/androidx/ui/test/FindersTest.kt
M ui/ui-test/src/androidTest/java/androidx/ui/test/PrintToStringTest.kt
M ui/ui-test/src/androidTest/java/androidx/ui/test/ScrollToTest.kt
M ui/ui-test/src/androidTest/java/androidx/ui/test/TextActionsTest.kt
M ui/ui-test/src/main/java/androidx/ui/test/Actions.kt
M ui/ui-test/src/main/java/androidx/ui/test/Filters.kt
M ui/ui-text/api/0.1.0-dev15.txt
M ui/ui-text/api/current.txt
M ui/ui-text/api/public_plus_experimental_0.1.0-dev15.txt
M ui/ui-text/api/public_plus_experimental_current.txt
M ui/ui-text/api/restricted_0.1.0-dev15.txt
M ui/ui-text/api/restricted_current.txt
M ui/ui-text/src/commonMain/kotlin/androidx/ui/text/CoreTextField.kt
M ui/ui-text/src/commonMain/kotlin/androidx/ui/text/TextSemanticsProperties.kt

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

ma...@google.com <ma...@google.com> #3Apr 22, 2024 11:16PM

Accepted by ma...@google.com.

Looking at the source code for (HttpURLConnectionImpl), it seems that the FileNotFoundException is fired when the url does not exist.

This should never happen unless there is another server running on the same port but in that case the process should not be alive (and we'd fire an IllegalStateException).

My best guess it that the perfetto http server hadn't fully started. Did you try your adding the catch exception alone and see if it still crashes?

Also, was this reproducible with any device or just one? We made some changes to perfetto http server so it should be possible to pass the timeout externally now (link).

Adding the catch for that exception sounds reasonable so I'm going ahead and adding that.

Message last modified on Apr 22, 2024 11:26PM

ap...@google.com <ap...@google.com> #4Apr 23, 2024 12:17AM

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

commit 032bde26a7352064404c6738eee29747c49be043
Author: Marcello Albano <maralb@google.com>
Date: Mon Apr 22 16:21:02 2024

Avoid crashing when perfetto trace processor is slow to start

In

b/329145808

it seems that perfetto can sometimes be slow to start
and, while the process is running, query an end point might return an
error, in which case a `FileNotFoundException` is thrown. Since we
already check for the process to be running, it's ok to "catch" this
state of the perfetto trace processor and wait for it for the timeout
duration.

Bug: 329145808
Test: ./gradlew benchmark:benchmark-macro:test
Relnote: Avoid crashing when perfetto trace processor is slow to start
Change-Id: I988418daa69ec33343364f7ad7c5fca26a39a5fa

M benchmark/benchmark-macro/src/main/java/androidx/benchmark/macro/perfetto/server/PerfettoHttpServer.kt

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

ma...@google.com <ma...@google.com> Apr 23, 2024 03:32PM

Marked as fixed.

en...@meta.com <en...@meta.com> #5Apr 28, 2024 09:30PM

The emulator we're using seems to be slower than CF_ARM64 so the 5 second timeout for perfetto http server start doesn't appear to be sufficient. Can this be raised from 5s to 60s in

https://cs.android.com/androidx/platform/frameworks/support/+/androidx-main:benchmark/benchmark-macro/src/main/java/androidx/benchmark/perfetto/PerfettoTraceProcessor.kt;l=84?q=PerfettoTraceProcessor ? This would fully resolve the hang that we're seeing (built and tested on top of the latest commits of benchmark-macro).

ma...@google.com <ma...@google.com> #6Apr 29, 2024 04:03PM

I don't think there is an issue in raising the timeout but you should be able to achieve the same using this function? If you can achieve the same I suggest doing that instead, to avoid a release cycle.

en...@meta.com <en...@meta.com> #7Apr 30, 2024 03:04AM

I believe the call to that function come from the Macrobenchmark library here. I don't think that I have access to this function externally and the default timeout is used :/

ma...@google.com <ma...@google.com> #8Apr 30, 2024 04:41PM

Oh sorry, I forgot that used also in Macrobenchmark. It sounds reasonable to me. Will open a PR. Thanks!

ap...@google.com <ap...@google.com> #9Apr 30, 2024 05:28PM

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

commit 8c32f5e6f64a40fc30c85da98646f814ef2fdb0e
Author: Marcello Albano <maralb@google.com>
Date: Tue Apr 30 09:46:58 2024

Increased default start timeout for perfetto trace processor

Test: n/a
Bug: 329145808
Change-Id: I87e8c9ec3472db0aafb908b590a9a91f6e9e5ed8

M benchmark/benchmark-macro/src/main/java/androidx/benchmark/perfetto/PerfettoTraceProcessor.kt

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

en...@meta.com <en...@meta.com> #10Apr 30, 2024 07:15PM

Thank you!

pr...@google.com <pr...@google.com> #11May 14, 2024 05:21PM

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

androidx.benchmark:benchmark-macro:1.3.0-alpha05