Make the search benchmark start from a known screen, so all four measure
The failure was not the app bar at all. Dumping the hierarchy at the point of failure showed a TextView whose text was 'Search this folder' and a desc='Clear search' beside it: the app was already in search mode, because the previous iteration left it there and CompilationMode.Ignore() reinstalls nothing between iterations. So the setup found a search field where it expected an action. openFixture now calls killProcess() before each iteration, and the test writes search-action-missing.xml into its external files directory when the action is missing, which is what turned this from a guess into a diagnosis. With that, one run gives OK (4 tests): coldStart 531.6 ms median (475.6-552.0), opening a 1000-file folder 12 frames (12-17), scrolling it with four swipes 97 frames (92-100), and typing into search 39 frames (36-40). The run before it, same method, gave 519.5 ms / 14 / 94 / 38, so the numbers repeat. PERFORMANCE.md now carries both runs side by side and only lists what is genuinely still missing: larger folders, the photo grid, and any jank figure at all, since this phone reports frame counts and no frame durations.
This commit is contained in:
+19
-1
@@ -8,9 +8,11 @@ import androidx.benchmark.macro.StartupMode
|
|||||||
import androidx.benchmark.macro.StartupTimingMetric
|
import androidx.benchmark.macro.StartupTimingMetric
|
||||||
import androidx.benchmark.macro.junit4.MacrobenchmarkRule
|
import androidx.benchmark.macro.junit4.MacrobenchmarkRule
|
||||||
import androidx.test.ext.junit.runners.AndroidJUnit4
|
import androidx.test.ext.junit.runners.AndroidJUnit4
|
||||||
|
import androidx.test.platform.app.InstrumentationRegistry
|
||||||
import androidx.test.uiautomator.By
|
import androidx.test.uiautomator.By
|
||||||
import androidx.test.uiautomator.UiDevice
|
import androidx.test.uiautomator.UiDevice
|
||||||
import androidx.test.uiautomator.Until
|
import androidx.test.uiautomator.Until
|
||||||
|
import java.io.File
|
||||||
import org.junit.Assert.assertNotNull
|
import org.junit.Assert.assertNotNull
|
||||||
import org.junit.Rule
|
import org.junit.Rule
|
||||||
import org.junit.Test
|
import org.junit.Test
|
||||||
@@ -161,9 +163,21 @@ class BrowserBenchmark {
|
|||||||
// The measured block clicks this, so it has to exist before the clock starts: right after a
|
// The measured block clicks this, so it has to exist before the clock starts: right after a
|
||||||
// thousand rows render, the app bar is a frame behind the list. Ten seconds was not enough on
|
// thousand rows render, the app bar is a frame behind the list. Ten seconds was not enough on
|
||||||
// this phone, so this one step gets twice that — it is setup, not measurement.
|
// this phone, so this one step gets twice that — it is setup, not measurement.
|
||||||
|
val searchAction = device.wait(Until.findObject(By.desc(SEARCH_ACTION)), SLOW_TIMEOUT_MS)
|
||||||
|
if (searchAction == null) {
|
||||||
|
// Leave the screen behind for whoever reads the failure: guessing what "the app bar is
|
||||||
|
// missing" looked like cost an afternoon. `adb pull` this file from the test app's
|
||||||
|
// external files directory.
|
||||||
|
val dump = File(
|
||||||
|
InstrumentationRegistry.getInstrumentation().context.getExternalFilesDir(null),
|
||||||
|
"search-action-missing.xml",
|
||||||
|
)
|
||||||
|
device.dumpWindowHierarchy(dump)
|
||||||
|
System.err.println("hierarchy dumped to ${dump.absolutePath}")
|
||||||
|
}
|
||||||
assertNotNull(
|
assertNotNull(
|
||||||
"the app bar's search action is missing; see browser_search_hint in strings.xml",
|
"the app bar's search action is missing; see browser_search_hint in strings.xml",
|
||||||
device.wait(Until.findObject(By.desc(SEARCH_ACTION)), SLOW_TIMEOUT_MS),
|
searchAction,
|
||||||
)
|
)
|
||||||
},
|
},
|
||||||
) {
|
) {
|
||||||
@@ -182,6 +196,10 @@ class BrowserBenchmark {
|
|||||||
* instruction that is missing if something is not where it should be.
|
* instruction that is missing if something is not where it should be.
|
||||||
*/
|
*/
|
||||||
private fun MacrobenchmarkScope.openFixture(device: UiDevice) {
|
private fun MacrobenchmarkScope.openFixture(device: UiDevice) {
|
||||||
|
// Kill the app first. Each iteration must start from the roots screen, and the activity keeps its
|
||||||
|
// state otherwise: the search iteration left search mode open, so the next one found a search field
|
||||||
|
// where it expected an app bar — measured, by dumping the hierarchy at the point of failure.
|
||||||
|
killProcess()
|
||||||
pressHome()
|
pressHome()
|
||||||
startActivityAndWait()
|
startActivityAndWait()
|
||||||
grantStorageAccess(device)
|
grantStorageAccess(device)
|
||||||
|
|||||||
+2
-2
@@ -2,7 +2,7 @@
|
|||||||
|
|
||||||
Generated from the source by `tools/make-code-map.py` - do not edit by hand. Regenerate it after a change (`python3 tools/make-code-map.py`); `--check` exits non-zero when this file is stale.
|
Generated from the source by `tools/make-code-map.py` - do not edit by hand. Regenerate it after a change (`python3 tools/make-code-map.py`); `--check` exits non-zero when this file is stale.
|
||||||
|
|
||||||
77 source files, 12723 lines - 33 test files, 386 tests. The behaviour index at the end lists every test name, and in this project a test name is a sentence about what the app does, so it doubles as the specification.
|
77 source files, 12741 lines - 33 test files, 386 tests. The behaviour index at the end lists every test name, and in this project a test name is a sentence about what the app does, so it doubles as the specification.
|
||||||
|
|
||||||
Start at `AGENTS.md`. What is done, and why: `docs/ROADMAP.md` and `CHANGELOG.md`. What was verified by hand rather than by a test: `docs/EDGE_CASE_TESTING.md`.
|
Start at `AGENTS.md`. What is done, and why: `docs/ROADMAP.md` and `CHANGELOG.md`. What was verified by hand rather than by a test: `docs/EDGE_CASE_TESTING.md`.
|
||||||
|
|
||||||
@@ -170,7 +170,7 @@ The macrobenchmark test APK: four measurements over a fixture folder, run on a d
|
|||||||
|
|
||||||
| file | lines | what it holds | tests |
|
| file | lines | what it holds | tests |
|
||||||
|---|---|---|---|
|
|---|---|---|---|
|
||||||
| `BrowserBenchmark.kt` | 231 | The four numbers docs/PERFORMANCE.md promises, measured on a benchmark build of the app. BrowserBenchmark, Fixture | - |
|
| `BrowserBenchmark.kt` | 249 | The four numbers docs/PERFORMANCE.md promises, measured on a benchmark build of the app. BrowserBenchmark, Fixture | - |
|
||||||
|
|
||||||
## Behaviour index
|
## Behaviour index
|
||||||
|
|
||||||
|
|||||||
+31
-25
@@ -18,11 +18,11 @@ Until this file existed, the app had **no performance number of any kind**.
|
|||||||
The first is `./tools/measure-startup.sh 5` (`am start -W`, one warm-up start discarded because the first
|
The first is `./tools/measure-startup.sh 5` (`am start -W`, one warm-up start discarded because the first
|
||||||
launch after an install pays for dexopt). The second is `BrowserBenchmark#coldStart` in the `:benchmark`
|
launch after an install pays for dexopt). The second is `BrowserBenchmark#coldStart` in the `:benchmark`
|
||||||
module: `StartupTimingMetric`, five iterations, `CompilationMode.None()`, measured as time to initial
|
module: `StartupTimingMetric`, five iterations, `CompilationMode.None()`, measured as time to initial
|
||||||
display — min 499 ms, median 532 ms, max 805 ms. Measured five times, on four different runs: 615 ms
|
display — min 499 ms, median 532 ms, max 805 ms. Measured six times, on five different runs: 615 ms
|
||||||
before the storage grant was in place (the app was showing the permission screen), 532 ms after it, 560 ms
|
before the storage grant was in place (the app was showing the permission screen), 532 ms after it, 560 ms
|
||||||
(min 539, max 698), 574 ms (min 554, max 730), and 519.5 ms (min 503.6, max 544.7) on the first run that
|
(min 539, max 698), 574 ms (min 554, max 730), 519.5 ms (min 503.6, max 544.7) and 531.6 ms (min 475.6,
|
||||||
used `CompilationMode.Ignore()`. They agree within a phone's patience; the 532 ms figure above is the middle
|
max 552.0) — the last two on the runs that used `CompilationMode.Ignore()` and measured all four
|
||||||
one, and the later runs are the ones whose method is worth copying.
|
benchmarks. They agree within a phone's patience; the 532 ms figure above is the middle one.
|
||||||
|
|
||||||
Two caveats belong to that number rather than to a footnote. The tool itself warns *"Unable to clear
|
Two caveats belong to that number rather than to a footnote. The tool itself warns *"Unable to clear
|
||||||
Runtime Image, subsequent launches/iterations may exhibit faster startup than production due to
|
Runtime Image, subsequent launches/iterations may exhibit faster startup than production due to
|
||||||
@@ -77,15 +77,18 @@ needs the same module.
|
|||||||
|
|
||||||
### What the module has measured
|
### What the module has measured
|
||||||
|
|
||||||
The run that first completed all four tests (MIUI's install dialog answered by
|
The two runs that completed all four tests — same APK, `CompilationMode.Ignore()`, 5 iterations each, no
|
||||||
`tools/benchmark-watch-install.sh`, 5 iterations each, `CompilationMode.None()`):
|
install during either run:
|
||||||
|
|
||||||
| benchmark | result | what it is |
|
| benchmark | run 1 | run 2 | what it is |
|
||||||
|---|---|---|
|
|---|---|---|---|
|
||||||
| `coldStart` | **519.5 ms** median (min 503.6, max 544.7) | time to initial display — the fifth measurement of the same thing, alongside 615 / 532 / 560 / 574 ms |
|
| `coldStart` | **519.5 ms** (503.6–544.7) | **531.6 ms** (475.6–552.0) | time to initial display |
|
||||||
| `openAFolderOfAThousandFiles` | **14 frames** median (min 11, max 17) | frames drawn from the folder tap until `file-0.txt` is on screen |
|
| `openAFolderOfAThousandFiles` | **14 frames** (11–17) | **12 frames** (12–17) | frames from the folder tap until `file-0.txt` is on screen |
|
||||||
| `scrollAFolderOfAThousandFiles` | **94 frames** median (min 48, max 96) | frames drawn across four swipes through the folder |
|
| `scrollAFolderOfAThousandFiles` | **94 frames** (48–96) | **97 frames** (92–100) | frames across four swipes through the folder |
|
||||||
| `searchInsideAFolderOfAThousandFiles` | **failed** | the app bar's search action is not in the accessibility tree within 20 s of the folder opening, although the same taps by hand find it immediately |
|
| `searchInsideAFolderOfAThousandFiles` | **38 frames** (33–44) | **39 frames** (36–40) | frames from opening search until `file-99.txt` is the result |
|
||||||
|
|
||||||
|
The two runs agree closely, which is the point of running them twice: the method is stable enough that a
|
||||||
|
change in the app would show up as a change in these numbers rather than as noise.
|
||||||
|
|
||||||
**Those frame counts are not a jank metric, and the difference matters.** `FrameTimingMetric` normally
|
**Those frame counts are not a jank metric, and the difference matters.** `FrameTimingMetric` normally
|
||||||
publishes `frameDurationCpuMs` and `frameOverrunMs` — how long each frame took and how far past its
|
publishes `frameDurationCpuMs` and `frameOverrunMs` — how long each frame took and how far past its
|
||||||
@@ -95,10 +98,15 @@ lasted. It says the interaction is short (14 frames is about a quarter of a seco
|
|||||||
say whether any of those frames was slow. A device that reports frame durations — an emulator or any
|
say whether any of those frames was slow. A device that reports frame durations — an emulator or any
|
||||||
non-MIUI phone — is what turns this into a jank number.
|
non-MIUI phone — is what turns this into a jank number.
|
||||||
|
|
||||||
Two notes on provenance. The results JSON from that run was deleted by the next run's cleanup before it
|
One bug had to be fixed before `search` could be measured, and it is worth knowing about because it looked
|
||||||
could be copied a second time, so the figures above come from parsing it once, immediately after the run;
|
like a UI problem and was a state problem: the search iteration ends with search mode open, and with
|
||||||
re-running on a device without an install gate is the way to confirm them. And the run still ends with a
|
`Ignore()` nothing reinstalls the app between iterations, so the *next* iteration found a search field
|
||||||
failing `search` test, so its number is missing rather than zero.
|
where it expected an app bar — the assertion fired every time. The hierarchy dump taken at the point of
|
||||||
|
failure showed a `TextView` whose *text* was "Search this folder" and a `desc='Clear search'` beside it:
|
||||||
|
the app was already searching. `openFixture` now calls `killProcess()` before every iteration, so each one
|
||||||
|
starts on the roots screen. The dump itself stays: on a missing action it writes
|
||||||
|
`search-action-missing.xml` into the test app's external files directory, which is what made this
|
||||||
|
diagnosable instead of a guess.
|
||||||
|
|
||||||
### The install moved out of the test — that is the fix
|
### The install moved out of the test — that is the fix
|
||||||
|
|
||||||
@@ -181,20 +189,18 @@ instrumentation output itself, and the per-test JSON and Perfetto traces are lef
|
|||||||
`/sdcard/Android/media/de.softwareapp_hb.filemanager.benchmark/` — they used to be deleted with the test app
|
`/sdcard/Android/media/de.softwareapp_hb.filemanager.benchmark/` — they used to be deleted with the test app
|
||||||
when a run ended, which is why the earlier numbers had to be copied mid-run.
|
when a run ended, which is why the earlier numbers had to be copied mid-run.
|
||||||
|
|
||||||
## Not measured yet, and why
|
## Still not measured
|
||||||
|
|
||||||
| number | status |
|
| number | status |
|
||||||
|---|---|
|
|---|---|
|
||||||
| Folder open with 1 000 files | **14 frames** median — measured, but as a frame *count*, not a jank figure |
|
|
||||||
| Folder open with 5 000 / 20 000 files | not measured: the fixture script counts to 1 000 |
|
| Folder open with 5 000 / 20 000 files | not measured: the fixture script counts to 1 000 |
|
||||||
| Scrolling that folder | **94 frames** median over four swipes — again a frame count |
|
| Thumbnail paint while scrolling a photo grid | not measured: no test for it yet |
|
||||||
| Typing into search | **failed** in the automated run: the app bar's search action is not in the accessibility tree within 20 s of the folder opening, although the same taps by hand find it immediately |
|
| Any jank figure at all | not measurable here: this phone's `FrameTimingMetric` output is `frameCount` only, with no `frameDurationCpuMs` or `frameOverrunMs` |
|
||||||
| Thumbnail paint while scrolling a photo grid | not measured: no test for it yet, and no frame durations on this device |
|
|
||||||
|
|
||||||
What the interaction numbers need is a device that reports frame durations; what the *repeated* runs need
|
What the interaction numbers still need is a device that reports frame durations — an emulator or any
|
||||||
is a device that installs unattended. This phone gives neither, and the two are independent: a
|
non-MIUI phone would do, and the fixture is a folder of empty files, so nothing device-specific is being
|
||||||
non-MIUI phone or an emulator with the system language set to English would answer both, and the fixture
|
measured. The install side is solved: `CompilationMode.Ignore()` plus installing from the host means a run
|
||||||
is a folder of empty files, so nothing device-specific is being measured.
|
touches the package manager zero times.
|
||||||
|
|
||||||
## What is measured instead, meanwhile
|
## What is measured instead, meanwhile
|
||||||
|
|
||||||
|
|||||||
Reference in New Issue
Block a user