Compare commits

...
Author SHA1 Message Date
Jason Ross 64d5cbf738 Merge pull request #272 from JMR-dev/fix/102-picker-back-press-overshoot
Stop the picker dismissal destroying MainActivity, and census what actually turns legs red (#102)
2026-09-07 17:47:18 -05:00
JMR-devandClaude Opus 5 842965a479 Say who closed the picker, because it was us and the KDoc denied it
The commit below describes "a back press aimed at a picker that had closed five seconds
earlier". The timing is right and the agency is wrong, and the agency is the interesting
half. Re-read out of the same logcat:

  20:59:35.686  UiDevice: Retrieving node ... [RES='android:id/button1'].
  20:59:35.689  UiObject2: Clicking on (927, 2274).
  20:59:36.033  MainActivity RESUMED
  20:59:36.350  VRI[PickActivity]: visibilityChanged ... newVisibility=false

`aerr_wait` and `aerr_close` both missed on that iteration and `dismissASystemErrorDialog`
fell through to `android:id/button1` -- the framework's generic AlertDialog positive button,
which is on every AlertDialog on the device. It hit one inside DocumentsUI, and that is what
closed the picker. The picker did not close on its own; this class closed it.

So the destroyed Activity and #271 are one incident rather than two findings that happened
to share a trace, and the loop's shape is three iterations rather than two: iteration 2
closes the picker through `button1` and then presses back into an app that is already in
front, iteration 3 dismisses the launcher's ANR dialog and presses again, and that press
finishes MainActivity.

It also sharpens what the fix does. With the re-read, iteration 2 returns -- the app is
focused within a second of the `button1` click -- so neither of the two presses that
followed it happens at all. The previous message implied the fix caught only the last one.

`requireAReadableScreen` now drops a Boolean return value, which this codebase treats as a
smell. It is correct there -- the `device.wait` on the next line is the re-probe -- and the
call site says so rather than leaving a reader to work out whether it was an oversight.

No behaviour change beyond the comment: the fix itself is unchanged and the sweep is re-run
because `app/src` is touched.

Refs #102, #271

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-09-07 17:18:23 -05:00
JMR-devandClaude Opus 5 89832563e6 Stop the picker dismissal destroying MainActivity, and census what turns legs red
`dismissThePicker` guarded its back presses on `Activity.hasWindowFocus`, which a system
app-error dialog makes false as well -- it is a fullscreen `system_server` window, which is
why `dismissASystemErrorDialog` exists at all. So the guard could not tell "the picker is
still up" from "a dialog is on top of an app that is already in front", and the loop
dismissed the dialog and then pressed back on the reading it had taken before doing so.

Measured on the API 35 gating leg of run 34161043035 attempt 1, whose head is #269's own
commit: the save picker returns at 20:59:36.033, the launcher's ANR dialog is dismissed at
20:59:41.169, a back press goes out at 20:59:41.713, the launcher is moved to the front 41 ms
later, and MainActivity is DESTROYED at 20:59:42.278. Everything after that in the test throws
`NullPointerException: Cannot run onActivity since Activity has been destroyed already`.

The fix re-reads the focus after a dialog is actually dismissed, and only then -- so it
removes a back press sent on a stale reading rather than retrying one. A picker genuinely in
front still leaves the app unfocused and still gets the press, so nothing about what this
class can catch changes; and on the ordinary path, with no dialog, nothing is re-read and
nothing is waited on. `requireAReadableScreen` twenty lines away has always re-probed after
dismissing a dialog; this is the same rule in the one place that did not follow it.

It cannot be demonstrated by re-running and the KDoc says so: the launcher ANR is ambient on
these runners and is not reproducible on demand, so a green sweep is not evidence for this.
The trace is.

`docs/ci-failure-modes.md` is the rest of it -- a census of every gating E2E leg-attempt in
the repo's history, 129 failures in 1489, classified by mode with a disposition each. It
closes out #102, whose own mode turns out to be the emulator's Codec2 HAL segfaulting: a null
dereference in `getClientUsage` inside `libcodec2_goldfish_common.so` kills
`c2.goldfish.h264.decoder`, and Media3's 25 s export watchdog then aborts the export. Six
occurrences, six carrying that crash in the same job's log, 0.5% of API 33-36 leg-attempts,
and the same vendor HAL `@FailsOnEmulatorApi37` already names.

Three counting rules are in the document and in CLAUDE.md because each was learned by getting
it wrong: count per leg-attempt rather than per run, since a re-run to green replaces the
conclusion; give every mode its own denominator, since the API 37 row filters seven tests out
and some tests are younger than the window; and capture the log before retrying, since
`gh run view --job <id> --log` resolves by run and serves the latest attempt.

Refs #102

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-09-07 17:14:57 -05:00
Jason Ross ef9d35ed40 Merge pull request #269 from JMR-dev/fix/268-saf-picker-determinism
Synchronise SafPickerRoundTripTest on state, not on timing (#268)
2026-09-07 16:21:34 -05:00
JMR-devandClaude Opus 5 b0b8b66d31 Name reattach's third outcome, which this KDoc denied existed
The determinism argument said no coroutine had a `_state` write left in
flight, because `reattach` "has either returned on its `_state.value !is Idle`
guard or found nothing". There is a third outcome: `pruneWork()` is async, so
`reattach` can find an unpruned job, pass that guard, and start an `observe()`
that is a live coroutine with writes ahead of it.

The conclusion survives, by a mechanism the paragraph did not mention.
`reattach` reads `ownership.current` before its query and hands that token to
`observe`, while `onInputPicked` calls `ownership.claim()` synchronously on the
pick -- so once a detail row exists that observation is superseded and every
emission returns at `stillHeldBy` before it writes. The claim is therefore
"every write in flight is landed or superseded", not "no other coroutine
started".

This is the KDoc a future reader opens to learn why the test cannot flake, and
CLAUDE.md records the same failure mode twice already -- E1/E3, and #226's KDoc
that described a draft rather than the code. A correct test with an incomplete
explanation is its own defect.

Comment only; no test logic changed. Committed with --no-verify on the repo
owner's explicit say-so: the gate's cache is keyed on the `app/src` tree hash,
so a comment costs a full 33-36 sweep, and CI is already green on the parent
commit. ktlintCheck, detekt and compileDebugAndroidTestKotlin were run by hand
first and pass -- those are what a comment edit can actually break.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-09-07 16:19:24 -05:00
JMR-devandClaude Opus 5 9fd96d08fd Synchronise SafPickerRoundTripTest on state, not on timing (#268)
Its two picker tests failed on roughly half of gating runs, by two measured
mechanisms. Both are removed here rather than re-tuned; the fix is in the test.

**A -- the Convert tap was lost in the post-probe relayout.**
`ConversionViewModel.onInputPicked` writes `_state` twice: name and size first,
then the probe. The second write grows the file card and moves the Convert
button. Compose computes the tap's coordinate from the semantics node and
dispatches afterwards, so a relayout in that gap hit-tests a stationary
coordinate against the new layout and the touch lands on whatever moved into
the button's place -- silently. Measured as the gap between the pick's FFprobe
closing and the tap: 319 ms and 421 ms passed; 46 ms, 98 ms and 124 ms did not.

`convertToTheDefaultFormat` now waits for the `Container` detail row before
tapping. That row is composed only under `input.probe != null`, so its presence
means both of `onInputPicked`'s writes have landed and been laid out -- and
nothing else in the ViewModel has a `_state` write in flight at that moment
(`reattach` returned on its non-Idle guard, `observe` starts inside `convert()`).
The card cannot change height again before the tap. That is a different claim
from waiting longer.

**B -- the app was not the focused window when Compose was queried.**
One failure had a 416 ms gap, so it was not A: the tap landed,
`GrantPermissionsActivity` started, back was pressed, and nothing was ever
enqueued. A back press goes to whichever window holds *input* focus, while
`Until.hasObject` answers about the accessibility tree -- which can carry the
dialog's nodes first -- so a back that arrives one window early lands on
`MainActivity` and finishes it.

`POST_NOTIFICATIONS` is now held before the tap instead of the dialog being
dismissed after it. `RequestPermission.getSynchronousResult` returns without
starting anything when the permission is already granted, so there is no
foreign window, no back press, and nothing the test injects can finish the
Activity. `@Before` asserts the grant rather than assuming it.

The class KDoc claimed granting "was tried first and did not take". Re-measured
at API 34, six consecutive runs: zero `REQUEST_PERMISSIONS` starts, zero
`GrantPermissionsActivity`, and exactly two `Scheduling work ID` lines per run
-- one per converting test, so neither tap was lost.

Also adds a fail-fast that says the Convert tap started nothing, instead of
spending the 300 s conversion budget and then naming `action.saveFile`. It is a
diagnostic, explicitly not the synchronisation.

Not fixed in production. The double write is deliberate, documented progressive
disclosure -- blocking the screen on an FFprobe process spawn reads as the app
ignoring the tap -- and a layout fix (pinning the button, reserving the card's
height) would make A less likely for one widget where waiting on the probe makes
it impossible for every tap. The ticket's argument that each added `OutputFormat`
widens A does not hold either: the format `FlowRow`'s height is fixed for a given
entry list and does not change when the probe lands. What displaces Convert is
the card growing, independent of chip count.

Mutation, run not predicted: deleting `publish`'s `if (destinationWasEmpty)
deletePartialOutput(...)` arm reddens `aFailedSaveDeletesTheDocumentItCouldNotWrite`
with "publish did not delete the document it could not write", and reddens
nothing else -- its sibling stays green, since the success path never enters
that catch.

Counts re-derived and unchanged: 72 androidTest tests, 7 markers, 65 gating,
FAILS_ON_EMULATOR_API37_BASELINE = 7. Both tests keep @FailsOnEmulatorApi37.

`NotificationCancelActionTest`'s KDoc said the suite grants no runtime
permissions; that is no longer true and it now says so.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-09-07 15:44:20 -05:00
Jason Ross fa22bf3b13 Merge pull request #261 from JMR-dev/feat/ogg-vorbis-libvorbis
Rebuild the FFmpeg AAR with libvorbis, and make Ogg Vorbis reachable (#254)
2026-09-07 13:25:37 -05:00
4 changed files with 440 additions and 42 deletions
+11
View File
@@ -148,6 +148,17 @@ Still true, and the reason the advisory job is not simply deleted: **API 37 need
the Pixel 10 Pro XL before each release.** Those seven tests are the one thing CI cannot answer
for.
**When a gating leg goes red on a diff that cannot explain it, read `docs/ci-failure-modes.md`
before anything else.** It is the census of all 129 gating failures in the repo's history against
1489 leg-attempts, with a per-mode disposition, and it is what closed #102. Three things from it
that are easy to get wrong and expensive: **count per leg-attempt, never per run** — a re-run to
green replaces the conclusion, so counting runs sees about 40% of the failures; **every mode has
its own denominator**, because the API 37 row filters seven tests out and some tests are younger
than the window; and **a re-run destroys the log** — `gh run view --job <id> --log` resolves by run
and serves the latest attempt, so capture evidence before retrying, or read the attempt through
`gh api /repos/.../actions/jobs/{job_id}/logs`. The artifacts do survive, one per attempt under the
same name; `gh run download` takes the newest, which is the wrong one.
On a device or emulator, build only the ABI it can execute:
```bash
@@ -1,7 +1,9 @@
package org.libremediaconverter.saf
import android.Manifest
import android.app.UiAutomation
import android.content.Context
import android.content.pm.PackageManager
import android.net.Uri
import android.provider.DocumentsContract
import android.provider.OpenableColumns
@@ -33,6 +35,7 @@ import org.junit.Assert.assertFalse
import org.junit.Assert.assertNotEquals
import org.junit.Assert.assertNotNull
import org.junit.Assert.assertTrue
import org.junit.Before
import org.junit.Rule
import org.junit.Test
import org.junit.runner.RunWith
@@ -361,6 +364,71 @@ class SafPickerRoundTripTest {
/** Counts [MainActivity] creations from the moment [watchForRecreation] is called. */
private val recreations = AtomicInteger()
/**
* Holds `POST_NOTIFICATIONS`, so tapping Convert cannot open a window this test has to fight.
*
* ## What this replaces, and why the replacement is not a smaller wait
*
* Until #268 the tap was followed by `dismissThePermissionDialog`, which waited for
* `com.google.android.permissioncontroller` to appear and pressed back on it. That is a
* *foreign, focused window* in the middle of the one step this class most needs to be
* deterministic, and it is what mechanism B of #268 was: on the API 35 leg of run 34146936252
* the tap landed — `START u0 {act=android.content.pm.action.REQUEST_PERMISSIONS ...
* GrantPermissionsActivity}` at 17:38:30.516 — back was pressed at 17:38:32.479, and no
* `ConversionWorker` was ever enqueued in the five minutes that followed. A back press goes to
* whichever window holds *input* focus, and `Until.hasObject` answers about the accessibility
* tree, which can carry the dialog's nodes before it has the focus; a back that arrives one
* window early lands on `MainActivity` and finishes it, which is a screen no `waitUntil` can
* wait for the return of.
*
* ## Why holding the permission removes the window rather than making it less likely
*
* `ConverterScreen` wires Convert to `requestNotifications.launch(POST_NOTIFICATIONS)`, and
* `ActivityResultContracts.RequestPermission.getSynchronousResult` returns
* `SynchronousResult(true)` — *without starting anything* — when
* `checkSelfPermission` already answers `PERMISSION_GRANTED`. So with the permission held there
* is no `GrantPermissionsActivity`, no foreign window, no back press, and nothing this test
* injects can finish the Activity. That is the whole chain, and [holdTheNotificationPermission]
* asserts its one premise rather than assuming it.
*
* ## The KDoc this contradicts, and the measurement that settles it
*
* `convertToTheDefaultFormat` used to say granting "was tried first and did not take —
* `GrantPermissionsActivity` appeared anyway". Re-measured on 2026-09-07, API 34 on this host,
* six consecutive runs of this class: logcat carries **zero**
* `act=android.content.pm.action.REQUEST_PERMISSIONS` starts and zero `GrantPermissionsActivity`
* across all six, and exactly two `WM-SystemJobScheduler: Scheduling work ID` lines per run —
* one for each test that converts, so neither Convert tap was lost. Whatever the earlier
* attempt did, a `pm grant` issued before the tap does take. The assertion below is what keeps
* that from going quietly stale.
*
* ## Two consequences, both deliberate
*
* The grant is **not** undone in teardown: revoking a runtime permission restarts the app's
* process, which would take the rest of the instrumentation run with it. The suite runs without
* Orchestrator, so every class that converts *after* this one now does so with notifications
* permitted. That is benign — `ConversionNotifications` builds its channel at
* `IMPORTANCE_LOW`, so nothing heads-up over the screen — but it is a real change to the
* device state the rest of the run sees, and `NotificationCancelActionTest`'s KDoc is updated
* with it.
*
* And this class no longer takes the denial path. It never asserted anything about it — the
* permission is setup for a test whose subject is SAF — and nothing is lost by it: the
* callback `ConverterScreen` registers is `{ viewModel.convert() }`, which **ignores its
* boolean**, so "converts whichever way the answer goes" is the shape of the code rather than a
* branch a test has to choose. `StaleLauncherResultTest` is what pins that callback path.
*/
@Before
fun holdTheNotificationPermission() {
device.executeShellCommand("pm grant $appPackage ${Manifest.permission.POST_NOTIFICATIONS}")
assertEquals(
"POST_NOTIFICATIONS is not held, so tapping Convert would open a permission dialog " +
"and this class's determinism argument does not hold -- see the KDoc above",
PackageManager.PERMISSION_GRANTED,
context.checkSelfPermission(Manifest.permission.POST_NOTIFICATIONS),
)
}
/**
* Counts a rotation's recreation without asking the Activity anything.
*
@@ -721,13 +789,10 @@ class SafPickerRoundTripTest {
* showed LMC R38 fixtures"*. The default `MP4_H265` produces `video/mp4` and the root is
* offered.
*
* **The notification dialog is dismissed rather than pre-granted, and that is the honest
* version.** Convert never calls `convert()` directly — it launches `RequestPermission` for
* `POST_NOTIFICATIONS` and converts from the callback **whichever way the answer goes**. So the
* dialog only has to be got out of the way; denying it is a real user's path and the conversion
* still runs. Granting it programmatically was tried first and did not take —
* `GrantPermissionsActivity` appeared anyway, the click that followed went to it rather than to
* the app, and the screen sat in `Ready` with nothing enqueued.
* **The notification permission is held rather than dismissed**, which is #268's mechanism B
* and is argued in [holdTheNotificationPermission]. The short version: `RequestPermission`
* starts no Activity at all when the permission is already granted, so the tap below is
* followed by no foreign window.
*
* **Both taps scroll first.** On `Ready` the screen carries a file card, five pickers and then
* the button, so Convert is below the fold on a phone. `performClick` on an off-screen node
@@ -735,38 +800,94 @@ class SafPickerRoundTripTest {
* either way — the first version of this sat waiting for a `Converted` that could never come.
*/
private fun convertToTheDefaultFormat() {
awaitTheProbeHavingLanded()
composeRule.onNodeWithTag(TestTags.Converter.CONVERT)
.performScrollTo()
.assertIsEnabled()
.performClick()
dismissThePermissionDialog()
requireTheTapToHaveStartedTheJob()
awaitNode(TestTags.SAVE_FILE, CONVERSION_TIMEOUT_MS)
}
/**
* Gets the `POST_NOTIFICATIONS` dialog out of the way, if this device shows one.
* Blocks until the pick's probe has been rendered, so no relayout can straddle the next tap.
*
* Backing out of it is a denial, and a denial is fine here: the conversion starts either way,
* and what that costs the user is a progress notification confined to the Task Manager. Waiting
* only briefly, because on a device where the permission is already held no dialog appears at
* all and the conversion is already under way.
* **This is #268's mechanism A, and the argument is that it becomes impossible rather than
* unlikely.** `ConversionViewModel.onInputPicked` writes `_state` exactly twice: once with the
* name and size as soon as the metadata query returns, and once more with the probe filled in.
* The second write is what grows the file card, which moves everything below it — including the
* Convert button. Compose's injection computes the target's centre from the semantics node and
* dispatches the touch afterwards; a relayout in that gap hit-tests the stationary coordinate
* against the *new* layout, so the down and the up land on whatever moved into the button's old
* place. Nothing throws. Measured on the two failing gating legs as the gap between the pick's
* FFprobe closing and the tap: 319 ms and 421 ms passed, 46 ms, 98 ms and 124 ms did not.
*
* A detail row can only be composed from that second write, because `FileCard` renders the rows
* exclusively under `input.probe != null`. So once one exists, both of `onInputPicked`'s writes
* have landed and been laid out, and every `_state` write still in flight is either landed or
* superseded.
*
* `reattach` has **three** outcomes here, not two. It returns on its `_state.value !is Idle`
* guard; or it finds nothing; or — because `pruneWork()` is async and can leave a finished job
* unpruned — it passes that guard and starts an `observe()`. This paragraph used to name only
* the first two, which was wrong rather than merely incomplete: the third is a live coroutine
* with writes ahead of it.
*
* It is still harmless, and by a different mechanism than the guard. `reattach` reads
* `ownership.current` *before* its query and hands that token to `observe`, while
* `onInputPicked` calls `ownership.claim()` synchronously on the pick — so by the time a
* detail row exists the observation is superseded, and every emission returns at
* `stillHeldBy` before it writes. Outside that path `observe` is not started until
* `convert()` runs. **The card cannot change height again before the tap**, which is a
* different claim from waiting longer.
*
* The `Container` row specifically, rather than a new "probing finished" tag in `main`, because
* this fixture is an MP4 video and that row is already what
* [pickingAFileThroughTheSystemPickerFillsInTheFileCard] waits on and asserts. It is a
* *presence* wait, which cannot be satisfied by a composition that is momentarily absent — an
* absence wait can, and that would tap into nothing.
*
* **Not in [pickTheFixture].** The rotation test does not tap a Compose affordance in this
* window at all, and the picker test already makes this exact wait its own assertion. Putting
* it here keeps a broken read grant reddening one test with the message that explains it.
*/
private fun dismissThePermissionDialog() {
if (device.wait(Until.hasObject(By.pkg(PERMISSION_UI_PACKAGE)), PERMISSION_DIALOG_MS) != true) {
return
private fun awaitTheProbeHavingLanded() {
awaitNode(TestTags.Converter.detailRow(CONTAINER_LABEL))
}
/**
* Fails fast if the Convert tap started nothing, instead of waiting out the conversion budget.
*
* **A diagnostic, not the synchronisation** — [awaitTheProbeHavingLanded] is what makes the tap
* land, and this cannot rescue a tap that did not. It exists because of what a lost tap used to
* look like: `ComposeTimeoutException`, 300000 ms for `action.saveFile`, five minutes after a
* screen that had never left `Ready`, which names the save affordance and says nothing about
* the tap two steps earlier. Every #268 failure was read from logcat rather than from the
* message, and this is the message it should have had.
*
* The condition is monotonic and needs no budget of its own: `convert()` sets `Converting`
* synchronously, and `Ready` is the only state that renders a Convert button, so once the tag
* is gone it stays gone. [APP_TIMEOUT_MS] rather than a new constant, because "the app should
* have reacted by now" is exactly what that number already means here.
*/
private fun requireTheTapToHaveStartedTheJob() {
val tag = TestTags.Converter.CONVERT
try {
composeRule.waitUntil("the Convert tap left the Ready screen", APP_TIMEOUT_MS) {
// A composition that is momentarily absent throws, and must read as "not yet"
// rather than as "the button is gone" -- see awaitNode.
runCatching { composeRule.onAllNodesWithTag(tag).fetchSemanticsNodes().isEmpty() }
.getOrDefault(false)
}
} catch (timeout: ComposeTimeoutException) {
throw AssertionError(
"the Convert tap did not start a conversion: $tag is still on screen " +
"${APP_TIMEOUT_MS}ms after it was clicked, so the screen never left Ready",
timeout,
)
}
device.pressBack()
device.wait(Until.gone(By.pkg(PERMISSION_UI_PACKAGE)), PERMISSION_DIALOG_MS)
// And wait for the app to be in front again before anything asks Compose about it.
// Querying while another window still owns the screen raises "No compose hierarchies found
// in the app", which is what this test did on an API 35 leg: the back press had landed but
// the dialog had not finished going away.
//
// Asked of UiAutomator rather than through awaitAppFocus, which is the opposite of what the
// class KDoc argues for elsewhere and is right here: awaitAppFocus goes through
// composeRule.waitUntil, so it would raise the very error it is being used to avoid.
device.wait(Until.hasObject(By.pkg(context.packageName)), FOCUS_TIMEOUT_MS)
}
/**
@@ -857,6 +978,8 @@ class SafPickerRoundTripTest {
private fun requireAReadableScreen() {
val app = By.pkg(appPackage)
if (device.wait(Until.hasObject(app), READABLE_TIMEOUT_MS) == true) return
// The return value is deliberately dropped here: the wait on the next line IS the re-probe
// that dismissThePicker had to be given, so there is nothing for it to gate.
dismissASystemErrorDialog()
if (device.wait(Until.hasObject(app), READABLE_TIMEOUT_MS) == true) return
unlockTheDevice()
@@ -897,14 +1020,21 @@ class SafPickerRoundTripTest {
* would click whatever system window happened to be there. `aerr_wait` first: it dismisses the
* dialog and leaves the offending app alone, which is the polite answer when the app is not
* ours. Back is not tried — `BaseErrorDialog` swallows key events.
*
* **Returns whether it clicked anything, and the caller has to care.** Dismissing the dialog
* changes the window focus, so every reading taken before this ran is stale afterwards —
* which is the whole of #102's `MainActivity`-destroyed mode. [requireAReadableScreen] already
* re-probes after calling this; [dismissThePicker] could not, because it had no way to know
* whether there had been anything to dismiss.
*/
private fun dismissASystemErrorDialog() {
private fun dismissASystemErrorDialog(): Boolean {
for (id in ERROR_DIALOG_BUTTONS) {
val button = device.findObject(By.res(id)) ?: continue
button.click()
device.waitForIdle()
return
return true
}
return false
}
/**
@@ -1036,6 +1166,51 @@ class SafPickerRoundTripTest {
* enough from Recent and two are needed from inside the root, but a third from Recent would
* finish `MainActivity` and take the rest of the test with it.
*
* **That hazard was reached, and the guard above is why it could be** (#102). A system
* app-error dialog is a fullscreen `system_server` window, so it takes the focus away from
* `MainActivity` too — [awaitAppFocus] cannot tell "the picker is still up" from "a dialog is
* on top of an app that is already in front". Measured on the API 35 gating leg of run
* `34161043035` attempt 1, which is #269's own head:
*
* ```
* 20:59:35.689 UiObject2: Clicking on (927, 2274) <- iteration 2's dismissal, on button1
* 20:59:36.033 MainActivity RESUMED <- so the picker is gone, by our hand
* 20:59:36.350 VRI[PickActivity]: visibilityChanged ... newVisibility=false
* 20:59:37.068 UiDevice: Pressing back button. <- iteration 2 presses anyway
* 20:59:41.094 UiDevice: Retrieving node ... [RES='android:id/aerr_wait']
* 20:59:41.169 Input channel object 'Application Not Responding:
* com.google.android.apps.nexuslauncher' was disposed
* 20:59:41.713 UiDevice: Pressing back button. <- iteration 3
* 20:59:41.754 TopTaskTracker: onTaskMovedToFront: ... NexusLauncherActivity
* 20:59:42.278 MainActivity DESTROYED
* ```
*
* Read the first two lines before the rest, because they are the part that is easy to get
* wrong: **the picker did not close on its own — this function closed it**, on iteration 2,
* when [dismissASystemErrorDialog] fell through to `android:id/button1` and clicked what was
* almost certainly DocumentsUI's own positive button (#271). From `20:59:36.033` onwards there
* was nothing left to back out of. Iteration 2 pressed back regardless, iteration 3 dismissed
* the launcher's ANR dialog — #93's occluder, still ambient on these runners, and the only
* remaining reason the focus read false — and pressed again, and that press finished
* `MainActivity`. Every later `onActivity` in the test then threw
* `NullPointerException: Cannot run onActivity since Activity has been destroyed already`.
*
* **With the re-read below, iteration 2 returns** — the app is focused within a second of the
* `button1` click — and iterations 2 and 3 never press at all.
*
* **So the reading is retaken after the dialog goes, and only then.** This removes a back
* press sent on a stale reading; it does not retry one, and it does not make the dismissal
* more tolerant. A picker that really is in front still leaves the app unfocused, so the press
* still happens and a genuinely stuck picker still fails here. On the ordinary path — no
* dialog — nothing is re-read and nothing is waited on, which is why the check is behind the
* `&&`. [requireAReadableScreen] has always re-probed after dismissing a dialog; this is the
* same rule in the one place that did not follow it.
*
* **It cannot be proved by re-running**, and that is worth saying rather than glossing: the
* launcher ANR is ambient and unreproducible on demand, so a green sweep is not evidence. What
* the fix rests on is the trace above: the launcher comes to the front 41 ms after a back press
* that this change does not send, and the Activity is destroyed 565 ms after that.
*
* **[forceStopThePicker] is the escalation after the presses, and it exists because a back
* press is not always deliverable.** See its own KDoc for the measurement.
*/
@@ -1046,7 +1221,11 @@ class SafPickerRoundTripTest {
// so a back aimed at the picker lands on the dialog and nothing moves. Measured --
// API 34 of run 32813885120 exhausted all four presses with `android` in front, which
// is that dialog, while the launcher it belonged to went on ANRing behind everything.
dismissASystemErrorDialog()
//
// And re-read the focus if one was dismissed: the dialog is itself a reason the
// reading above can be false, so a press sent on it can land on an app that is
// already in front. See the KDoc -- that is how MainActivity got destroyed.
if (dismissASystemErrorDialog() && awaitAppFocus()) return
device.pressBack()
}
// The check after the last press, and not a spare one: `repeat` presses on its final
@@ -1205,8 +1384,9 @@ class SafPickerRoundTripTest {
* `fetchSemanticsNodes` **throws** `IllegalStateException: No compose hierarchies found in the
* app` when nothing is attached at that instant, and `waitUntil` propagates it on the first
* poll instead of waiting out the deadline. This class spends much of its time with another
* app in front — the picker, the create-document dialog, the permission dialog — so there is
* always a window where the app is coming back and has no composition yet. Before this, that
* app in front — the picker and the create-document dialog, and until #268 the permission
* dialog too — so there is always a window where the app is coming back and has no composition
* yet. Before this, that
* window was a hard failure: measured on the API 34 leg of run 34057196628, where **both** SAF
* tests died that way while the same commit passed API 33, 35, 36 and 37, and the previous
* commit passed API 34 and failed 35. A failing leg that moves between runs is #190's
@@ -1240,12 +1420,6 @@ class SafPickerRoundTripTest {
const val PICKER_TIMEOUT_MS = 30_000L
const val APP_TIMEOUT_MS = 30_000L
/** The runtime-permission dialog's package, so it can be recognised and dismissed. */
const val PERMISSION_UI_PACKAGE = "com.google.android.permissioncontroller"
/** Short: either the dialog is up almost immediately, or the permission was already held. */
const val PERMISSION_DIALOG_MS = 5_000L
/**
* Bounds a hang, and **the first number here was measured on one API level and wrong on
* another.** It read 120 s, on the strength of the whole test taking 11.8 s on the API 34
@@ -37,10 +37,16 @@ import java.util.concurrent.TimeUnit
* ## Why this fires the intent rather than reading the shade
*
* The obvious version asks `NotificationManager.getActiveNotifications()` for id 1001 and taps what
* it finds. That was rejected: the instrumented suite grants no runtime permissions, so
* `POST_NOTIFICATIONS` is denied throughout, and whether a suppressed foreground-service
* notification is returned there is a platform detail that varies — the test would be asserting
* something about notification *visibility* rather than about cancellation.
* it finds. That was rejected because it would be asserting something about notification
* *visibility* rather than about cancellation — and because whether the shade holds the
* notification at all is not this class's to know.
*
* **It used to say `POST_NOTIFICATIONS` is denied throughout, and since #268 that is no longer
* true.** `SafPickerRoundTripTest` grants it in `@Before`, so that its Convert tap cannot open a
* permission dialog, and a runtime grant cannot be undone in teardown without restarting the app's
* process. The suite runs without Orchestrator, so whether this class sees the permission held
* depends on class order — which is exactly the reading this test does not do, and the reason it
* stays the right shape rather than a reason to change it.
*
* The `PendingIntent` is the subject; where it is read from is incidental. Building the
* notification for a real, live work id and firing its action exercises exactly the thing that can
+207
View File
@@ -0,0 +1,207 @@
# When a gating E2E leg goes red and the diff cannot explain it
**Status:** a census of every gating E2E leg-attempt in the repo's history, classified by mode,
with a disposition for each. **1489 gating leg-attempts, 129 failures, 8.7%** — 2026-08-20 to
2026-09-07. This is the standing answer to "my docs-only PR turned an emulator leg red, what is
it?", and it is what #102 asked for before being closed as an umbrella.
**Last verified:** 2026-09-07, against `main` at `ef9d35e`. Mode 6's fix is in #272 and is the only
thing here not yet on `main`.
This document is about **the emulator failing underneath the suite**. It is not a defect record
(`docs/defect-audit.md`), not a coverage read (`docs/coverage-read-findings.md`), and not a
test-suite read (`docs/e2e-read-findings.md`). Nothing here is a bug in the app.
## Read this first: three counting rules, each learned by getting it wrong
**Count per leg-attempt, never per run.** Measured here rather than asserted: the 129 failing
leg-attempts sit in **83 distinct runs, and 45 of those 83 ended green** once someone re-ran them.
So a census that counts failed *runs* finds 38 events where there were 129 — it does not
under-report evenly, it deletes exactly the failures somebody already decided were noise, which are
the ones this document is about. Every number here is per leg-attempt, with `cancelled` legs
excluded: those are `concurrency: cancel-in-progress` cancellations rather than runs, and there are
135 of them.
**Every mode has its own denominator, and it is not 1489.** Derive it from where and when the
*test* ran, not from the leg count, and two things move it. The API 37 row filters out every test
carrying `@FailsOnEmulatorApi37` with `notAnnotation` — **all four of `SafPickerRoundTripTest` and
three of `Media3EngineTest`, seven today** — which is every mode in the table below except 3 and 5.
And **that set has grown across this window**: the picker test and the two saves only joined it on
2026-09-06, which is why `SafPickerRoundTripTest` has 25 API 37 failures on record — 14 of them
since 2026-08-27 — that could not happen now. The saves did
not exist at all before 2026-09-06T15:12. A rate quoted over "all gating leg-attempts" is wrong for
every one of them, and is how "8% of legs" gets said about a thing that happens on one row.
**Anchor the mode to the test name beside the `FAILED` marker, then to the message under it.**
The name alone is not enough: `transcodesH264ToH265AndReportsProgress` has failed for three
different reasons, one of which was the whole suite going down around it.
## The modes
| # | mode | signature | where | disposition |
|---|---|---|---|---|
| 1 | SAF picker will not close | `the system picker would not close: after 4 back presses ...` | 37 only, since #96 | **#108** — collateral of the gralloc abort |
| 1b | picker never showed, from the rotation test | `never showed BySelector [PKG=...], in 3 separate pickers` | 33, 34 — 3 times | #268/#269; no gating attempt on `main` since |
| 2 | wedge | gradle never returns; leg killed at `WEDGE_TIMEOUT`; `wedged: yes` in the shape row | 33/34 only | **#122**, addressed by #219 — see below |
| 3 | emulator never came up | `adb ... failed with exit code 224`, before any test | 37 only, 3 times | infra, before the suite; nothing to attribute |
| 4 | Media3 export watchdog | `ExportException: Muxer error` / `no output sample written in the last 25000 milliseconds` | 34, 36 | **environmental, measured** — see below |
| 5 | `system_server` gone mid-suite | `Can't find service: package`, `am get-current-user` fails, `INSTRUMENTATION_ABORTED` | 37 only | **#108** — `hasReadColorBufferDma` |
| 6 | app Activity destroyed under the SAF save tests | `NullPointerException: Cannot run onActivity since Activity has been destroyed already` | 35, once | **fixed** — see below |
**#96 held, and mode 1 is worth stating as a number rather than a memory.**
`pickingAFileThroughTheSystemPickerFillsInTheFileCard` — the test #93 and #96 were about — has
failed **zero times on API 33-36 in the 881 gating leg-attempts since #96 merged**. Every remaining
failure of that class on those four rows is a *different* test: three of the rotation test (1b) and
seven of the two save tests (mode 6). The picker mode is an API 37 mode now.
Background noise that is **not** a mode on its own: `Failed to find ColorBuffer: N` and `bad color
buffer handle N` never name anything in this app and appear on green legs. Measured over 12 green
gating legs sampled from 2026-09-02 onwards, all reporting `failed: 0`: `bad color buffer handle`
in **6** of them, `Failed to find ColorBuffer` in **2**. Neither is evidence of anything on its own.
## Mode 4 — the Media3 export watchdog is the emulator's codec HAL segfaulting
**This is the mode #102 was filed for, and it is not starvation.** The per-test logcat in
`e2e-report-api34` of run `34000816016` attempt 1, 62 ms after the test starts:
```
00:20:39.814 D MediaCodec: MediaCodec::reclaim(...) c2.goldfish.h264.decoder
00:20:39.822 F DEBUG : Cmdline: /vendor/bin/hw/android.hardware.media.c2@1.0-service-goldfish
00:20:39.822 F DEBUG : signal 0 (SIGSEGV), code 1 (SEGV_MAPERR)
00:20:39.822 F DEBUG : Cause: null pointer dereference
#00 C2Block2D::handle() const+4 libcodec2_vndk.so
#01 getClientUsage(std::shared_ptr<C2BlockPool> const&) libcodec2_goldfish_common.so
#02 android::C2GoldfishAvcDec::process(...) libcodec2_goldfish_avcdec.so
00:20:39.839 E CCodec : Codec2 component "c2.goldfish.h264.decoder" died.
00:20:39.846 E MediaCodec: Codec reported err 0xffffffe0/DEAD_OBJECT
```
The decoder HAL process dies and respawns. Media3 is left with a dead codec, writes no output
sample, and its own 25-second export watchdog aborts the export — which is the `Muxer error` the
job log shows. **The crashing code is `/vendor/lib64/*` inside the system image**, so this is
environmental in the same sense `@FailsOnEmulatorApi37` is, and now with the same kind of evidence.
**Six for six.** Every leg-attempt that has failed this way carries the crash in the same job's
`--- native crashes (tail 60) ---` dump. **Grep `c2@1.0-service-goldfish` and not the friendlier
line**: `Codec2 component "c2.goldfish.h264.decoder" died` is a `CCodec` message in the main
buffer and is in **none** of the six job logs, because that dump is `adb logcat -d -b crash` and
what reaches it is the tombstone, whose `Cmdline:` names the HAL. The six are
`32855014836` a1 (36), `32857067112` a1 (34),
`32919928048` a1 (36), `33261618358` a1 (34), `33588264439` a1 (36), `34000816016` a1 (34).
**Six in 1210 API 33-36 leg-attempts — 0.5%**, split 3 on API 34 and 3 on API 36, none on 33 or 35.
**It is the same weakness the API 37 marker names.** `FailsOnEmulatorApi37`'s stated reason is that
Media3 transcodes "fail inside the emulator's own `c2.goldfish.h264.decoder`". That is this HAL.
One weakness, deterministic on the android-37 images and 0.5% below them.
**What is not settled:** *why* it dereferences null. `MediaCodec::reclaim` is logged 8 ms earlier,
and a reclaim is the resource manager taking a codec instance away — so "a reclaim races
`C2GoldfishAvcDec::process` and the block pool goes out under it" is the obvious hypothesis and is
**untested**. Recorded as a hypothesis, not as a cause.
**Two failures of that test are excluded and it matters that they are.** `32545625459` a1 (API 37)
had 37 tests fail together with the gralloc assertion present — that is mode 5, and this test was
collateral. `32669190757` a1 (API 35) predates #111's shape report and carries a bare `FAILED`
marker with no message at all; it is **unclassifiable, and is not classified**.
## Mode 6 — the back press that finished `MainActivity`
Traced on the API 35 gating leg of run `34161043035` **attempt 1**, whose head is #269's own
commit:
```
20:59:35.689 UiObject2: Clicking on (927, 2274) <- iteration 2's dismissal, on button1
20:59:36.033 MainActivity RESUMED <- the picker is gone, by the test's own hand
20:59:36.350 VRI[PickActivity]: visibilityChanged ... newVisibility=false
20:59:37.068 UiDevice: Pressing back button. <- iteration 2 presses anyway
20:59:41.094 UiDevice: Retrieving node ... [RES='android:id/aerr_wait']
20:59:41.169 Input channel 'Application Not Responding: ...nexuslauncher' was disposed
20:59:41.713 UiDevice: Pressing back button. <- iteration 3
20:59:41.754 TopTaskTracker: onTaskMovedToFront: ... NexusLauncherActivity
20:59:42.278 MainActivity DESTROYED
```
`dismissThePicker` guarded its back presses on `Activity.hasWindowFocus`. A system app-error dialog
is a fullscreen `system_server` window, so **it makes that false too** — the guard could not tell
"the picker is still up" from "a dialog is on top of an app that is already in front".
**And the first two lines are the part to read carefully, because the obvious reading is wrong.**
The picker did not close on its own: `dismissASystemErrorDialog` closed it on iteration 2, by
falling through to `android:id/button1` and clicking DocumentsUI's own positive button (#271). From
`20:59:36.033` there was nothing to back out of — and the loop pressed back on iteration 2 anyway,
then dismissed the launcher's ANR dialog on iteration 3 and pressed again on the reading taken
before doing so. That press finished `MainActivity`. **So this mode and #271 are one incident**, and
the fix stops it at iteration 2, where the re-read now returns.
Fixed by re-reading the focus after a dialog is actually dismissed, and only then —
`SafPickerRoundTripTest.dismissThePicker` carries the trace. That **removes** a press sent on a
stale reading rather than retrying one, and a picker genuinely in front still fails there.
**It cannot be demonstrated by re-running.** The launcher ANR is ambient and not reproducible on
demand, so a green sweep is not evidence for this fix; the trace is.
### The other six failures of those save tests are four different things
Filed as one mode, they are not one: seven occurrences, **five distinct messages** counting the
destroy above. Three of the six below are on heads that predate their own follow-up fix, and one is
on a head that **contains** the fix meant for it. This is the worked example for "split by message
before diagnosing". **The two rows still open are #270**; the `button1` finding below is **#271**.
| run / attempt | head | message | what it is |
|---|---|---|---|
| `34041593697` a1 (35) | `fa10d94` — the commit that **added** the test | `No compose hierarchies found`, thrown directly | pre-`b23ff0f` |
| `34056545386` a1 (35) | `cbbaf74` | `ComposeTimeoutException ... after 120000 ms` | the `CONVERSION_TIMEOUT_MS` case `19e3539` fixed. **Not a system-service failure at all** — API 35's software encode measured 134.8 s against a 120 s bound |
| `34057706195` a1 (34) | `19e3539` | `No compose hierarchies found` ×2 | **contains `b23ff0f`**, so that fix did not close this shape. Open |
| `34067653670` a1 (35), `34146936252` a1 (35) | `d45abe7`, `73482520` | `waited 300000ms for a node tagged action.saveFile`, **no** composition error | `awaitNode` appends the composition error only when `fetchSemanticsNodes` threw, so the composition was readable throughout. `34067653670`'s per-test logcat has `MainActivity` `RESUMED` for the whole 300 s and **no conversion running at all**. Open |
| `34146936252` a2 (35) | `73482520` | `waited 300000ms ...; last composition error: No compose hierarchies` | app `PAUSED` and never resumed; the back press at `17:38:32.479` follows `Waiting 5000ms for ... permissioncontroller`, the permission-dialog helper #269 replaced with `pm grant` |
### And the dismissal can click a dialog that is not a system dialog (#271)
In the same trace, at `20:59:35.689`, `aerr_wait` and `aerr_close` both missed and
`android:id/button1` — the framework's generic `AlertDialog` positive button, present on every
`AlertDialog` on the device — was found and clicked. `MainActivity` came back 339 ms later and
`PickActivity`'s window went away with it, so what was clicked was a button inside **DocumentsUI's
own create-document flow**. It did no harm on that run. Filed rather than fixed here, because
narrowing the selector is a decision about what `dismissASystemErrorDialog` may reach.
## Mode 2 — the wedge, and why this says "consistent with" rather than "fixed"
Nine occurrences, **all on API 33/34**, 9 in 497 leg-attempts before 2026-09-06T02:00Z — **1.8%**
— and **0 in the 106 since**. The last one, `34001741668` (2026-09-06T00:36), is
`thePickedInputSurvivesARealRotation` again, and `git merge-base --is-ancestor 32ab54d <head>` says
that head **does not contain** #219's fix, so no wedge has ever been recorded against the fix.
At the prior rate, P(0 in 106) ≈ 0.15. **That is suggestive and it is not evidence.** Re-count
before writing "fixed" here.
Its diagnostics say the framework is fine, which is what separates it from every other mode in this
document: `e2e-wedge-api34` of `34001741668` has `started:` the rotation test with no `finished:`,
and `input`, `window`, `activity` and `media.player` all `found`.
## Reading the evidence, when the leg is already gone
Four things that are not obvious and each cost a wrong answer:
- **A re-run destroys the log.** `gh run view --job <id> --log` resolves by *run* and serves the
latest attempt, so after a re-run to green it hands back a green log for a red attempt. Use
`gh api --allow-escape-sequences /repos/{owner}/{repo}/actions/jobs/{job_id}/logs`, with the job
id from `/actions/runs/{run}/attempts/{n}/jobs`. Without `--allow-escape-sequences`, `gh` writes
nothing and exits 0.
- **A re-run does *not* destroy the artifacts, but the convenient command hides them.**
`/actions/runs/{run}/artifacts` returns every attempt's upload under the same name with different
ids and `created_at`; `gh run download` takes the newest, which after a re-run-to-green is the
green one. Match `created_at` to the attempt's window and fetch
`/actions/artifacts/{id}/zip`.
- **The per-test logcat is the evidence, not the job log.** `e2e-report-apiNN` carries
`outputs/androidTest-results/connected/debug/<device>/logcat-<class>-<method>.txt` — one file per
test, scoped to that test's window — plus the JUnit XML with the untruncated stack. The job log
truncates a stack to its first frame, which is why the `ActivityScenario` frames in mode 6 are
invisible there.
- **Grep the fault, not the thread.** #102 once split one bug into two by grepping
`TaskSnapshotPer` — a thread name from a ticket title — instead of `hasReadColorBufferDma`, the
assertion. The assertion is the invariant; the thread is only which caller tripped it.
## What this does not cover
The advisory `E2E API 37 Media3 hardware transcode (advisory)` job is **red on every PR by design**
and is not a signal. `docs/api-37-emulator-crash.md` has API 37's own story;
`.github/scripts/e2e-report-shape.sh` explains the shape table every leg prints.