Compare commits

..
Author SHA1 Message Date
JMR-devandClaude Opus 5 cae050fcfb Bound the wedge diagnostics, so a wedged leg reports as a wedge (#122)
A wedge already reports itself correctly, and then the leg spends half an hour
not saying so. From #151, run 33071570911:

    12:31:29  > Task :app:connectedDebugAndroidTest
    12:48:44  wedged: yes -- gradle was killed after 1200s and never returned
    12:49:20  ::warning::E2E api37 WEDGED (api37)
              ... 36 minutes of nothing ...
    13:25:05  ##[error]The operation was canceled.        <- timeout-minutes: 60
    13:25:09  Terminate orphan process: qemu-system-x86_64-headless, adb, java, java

WEDGE_TIMEOUT=1200 fired exactly as designed. What overran was everything after
it: `capture_wedge` and `dump_diagnostics` probe the device with adb, and the
device they are probing has just finished proving it stopped answering.

WHY `|| true` DID NOT COVER THIS. Every probe carries one, and the file header
says why:

    # Every probe is guarded with `|| true`. A diagnostic must never be the thing
    # that turns a run red.

`|| true` guards a probe that exits non-zero. It does nothing about one that
never exits at all. The discipline was enforced for exit codes and not for time,
and this is the other half of it.

WHAT IT COSTS BEYOND THE 36 MINUTES. The job ends `cancelled` rather than failing
with the wedge's own status, so `gh pr checks` renders a failure with no cause and
the carefully-built `wedged:` row sits above half an hour of silence -- the one
mechanism built to explain a wedge is the least likely to be read. `kill
"$LOGCAT_PID"` never runs either, which is the orphaned adb and qemu above. And a
cancelled required check blocks merges: this one stopped a seven-PR stack.

THE FIX. An `adbq` wrapper -- `timeout -k 5s 20 adb "$@"` -- applied to all 18
probes in `capture_wedge`, `dump_diagnostics`, and the pre-run memory snapshot.
20s is far more than any of them needs on a healthy device and far less than any
costs on a dead one; `-k` because adb itself can ignore the first signal when its
server is wedged.

WHAT IS DELIBERATELY LEFT UNBOUNDED, and it is not everything else by accident:

  - The API 37 SystemUI disable machinery (`adb shell stop`/`start`, the
    `service check` loop). Functional, not diagnostic, and it already carries its
    own verify-and-retry -- see the comment block above it.
  - The backgrounded `adb logcat -v time` stream. It is meant to run for the whole
    leg; bounding it would truncate the log at 20 seconds.

Verified rather than assumed. Wrapper semantics, smoke-tested against a fake adb:
passthrough works, a non-zero exit is preserved (rc=7), a hang is killed at the
deadline (rc=124 after 2s), and `|| true` still swallows that -- so a bounded
probe cannot turn a run red either, which is the property the header demands.

shellcheck clean at the pinned digest over `git ls-files '*.sh'`, actionlint clean
at its pinned digest, `bash -n` clean.

One thing this does NOT do: it does not stop the wedge. #122 is still open for
that. It stops a wedge from being reported as a cancellation.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-09-01 20:45:38 -05:00
2 changed files with 37 additions and 106 deletions
+37 -18
View File
@@ -79,6 +79,21 @@ WEDGE_TIMEOUT=1200
# package against `pm list packages -d`, and require a 45 s window with zero new aborts.
# Three rounds, because one is not reliable and the failure is silent.
# ---------------------------------------------------------------------------
# Every device probe below is aimed at an emulator that has already failed, and on the wedge path
# at one that has just finished proving it stopped answering. So each is bounded in time as well as
# in exit status.
#
# `|| true` guards a probe that exits non-zero. It does nothing about one that never exits -- which
# is how #122's wedge path spent 36 minutes after printing its own diagnosis, lost the job to the
# 60-minute cap, and so reported `cancelled` instead of the wedge's own status. The header's rule
# that "a diagnostic must never be the thing that turns a run red" was enforced for exit codes and
# not for time; this is the other half of it.
#
# 20s is far more than any of these needs on a healthy device and far less than any of them costs
# on a dead one. `-k` because adb itself can ignore the first signal when its server is wedged.
ADB_PROBE_TIMEOUT=20
adbq() { timeout -k 5s "$ADB_PROBE_TIMEOUT" adb "$@"; }
count_aborts() { adb logcat -d -b crash 2> /dev/null | grep -c 'hasReadColorBufferDma'; }
systemui_disabled() { adb shell pm list packages -d 2> /dev/null | grep -q 'com.android.systemui'; }
@@ -155,11 +170,11 @@ LOGCAT_PID=$!
dump_diagnostics() {
{
echo "===== E2E api${LABEL} failure diagnostics -- $(date -u +%FT%TZ) ====="
echo "--- adb devices ---"; adb devices -l 2>&1 || true
echo "--- guest memory ---"; adb shell cat /proc/meminfo 2>&1 | grep -E 'MemTotal|MemAvailable|SwapTotal' || true
echo "--- guest storage ---"; adb shell df /data 2>&1 || true
echo "--- is the app even installed? ---"; adb shell pm list packages 2>&1 | grep -a libremedia || true
echo "--- native crashes ---"; adb logcat -d -b crash 2>&1 | tail -80 || true
echo "--- adb devices ---"; adbq devices -l 2>&1 || true
echo "--- guest memory ---"; adbq shell cat /proc/meminfo 2>&1 | grep -E 'MemTotal|MemAvailable|SwapTotal' || true
echo "--- guest storage ---"; adbq shell df /data 2>&1 || true
echo "--- is the app even installed? ---"; adbq shell pm list packages 2>&1 | grep -a libremedia || true
echo "--- native crashes ---"; adbq logcat -d -b crash 2>&1 | tail -80 || true
echo "--- runner: kvm ---"; ls -l /dev/kvm 2>&1 || true
echo "--- runner: memory ---"; free -h 2>&1 || true
echo "--- runner: disk ---"; df -h 2>&1 || true
@@ -167,9 +182,9 @@ dump_diagnostics() {
# Also to the step log, so the common case needs no artifact download.
echo "----- FAILURE SUMMARY (api${LABEL}) -----"
adb shell cat /proc/meminfo 2>&1 | grep -E 'MemTotal|MemAvailable' || true
adbq shell cat /proc/meminfo 2>&1 | grep -E 'MemTotal|MemAvailable' || true
echo "--- native crashes (tail 60) ---"
adb logcat -d -b crash 2>&1 | tail -60 || true
adbq logcat -d -b crash 2>&1 | tail -60 || true
}
capture_wedge() {
@@ -182,35 +197,39 @@ capture_wedge() {
echo "--- running/last instrumented test (logcat TestRunner) ---"
grep -a TestRunner "$LOGCAT_LOG" 2>/dev/null | tail -25 || true
echo "--- boot state ---"
adb shell getprop sys.boot_completed 2>&1 || true
adbq shell getprop sys.boot_completed 2>&1 || true
echo "--- are the binder services published? ---"
for svc in input window activity media.player; do
echo " service check $svc:"; adb shell service check "$svc" 2>&1 || true
echo " service check $svc:"; adbq shell service check "$svc" 2>&1 || true
done
APP_PID="$(adb shell pidof "$APP_ID" 2>/dev/null | tr -d '\r')" || true
TEST_PID="$(adb shell pidof "$TEST_ID" 2>/dev/null | tr -d '\r')" || true
APP_PID="$(adbq shell pidof "$APP_ID" 2>/dev/null | tr -d '\r')" || true
TEST_PID="$(adbq shell pidof "$TEST_ID" 2>/dev/null | tr -d '\r')" || true
echo "--- pids --- app: ${APP_PID:-<none>} test: ${TEST_PID:-<none>}"
# SIGQUIT makes ART dump every thread's stack to logcat and /data/anr. This is what
# distinguishes a deadlocked test from a stuck native encode from a dead device.
echo "--- SIGQUIT thread dumps ---"
for pid in $APP_PID $TEST_PID; do
[ -n "$pid" ] && adb shell kill -3 "$pid" 2>&1 || true
[ -n "$pid" ] && adbq shell kill -3 "$pid" 2>&1 || true
done
sleep 5
echo "--- /data/anr/* ---"
adb shell 'cat /data/anr/* 2>/dev/null' 2>&1 || true
echo "--- dumpsys activity ---"; adb shell dumpsys activity 2>&1 || true
echo "--- dumpsys window ---"; adb shell dumpsys window 2>&1 || true
adbq shell 'cat /data/anr/* 2>/dev/null' 2>&1 || true
echo "--- dumpsys activity ---"; adbq shell dumpsys activity 2>&1 || true
echo "--- dumpsys window ---"; adbq shell dumpsys window 2>&1 || true
# FFmpeg and Media3 both run through MediaCodec; a wedged transcode shows up here.
echo "--- dumpsys media.player ---"; adb shell dumpsys media.player 2>&1 || true
echo "--- dumpsys media.player ---"; adbq shell dumpsys media.player 2>&1 || true
echo "--- logcat -d (tail 400, includes the SIGQUIT dump) ---"
adb logcat -d 2>&1 | tail -400 || true
adbq logcat -d 2>&1 | tail -400 || true
} >> "$WEDGE_LOG" 2>&1 || true
echo "::warning::E2E api${LABEL} WEDGED ($1) -- see the wedge-diagnostics-api${LABEL} artifact"
}
echo "::group::E2E api${LABEL}"
adb shell cat /proc/meminfo 2>&1 | grep -E 'MemTotal|MemAvailable|SwapTotal' || true
# Bounded like the probes in the two diagnostic functions, and for the same reason. This one runs
# against a freshly booted emulator rather than a wedged one, so it is the least likely of them to
# hang -- but it is still a `|| true` diagnostic, and the rule this file now states is that a
# diagnostic must never be the thing that ends the leg.
adbq shell cat /proc/meminfo 2>&1 | grep -E 'MemTotal|MemAvailable|SwapTotal' || true
status=0
# -k 30s SIGKILLs a gradle client that ignores SIGTERM. The wrapper covers ONLY the foreground
@@ -1,88 +0,0 @@
package org.libremediaconverter.work
import android.content.pm.ServiceInfo
import org.junit.Assert.assertEquals
import org.junit.Test
import org.junit.runner.RunWith
import org.robolectric.RobolectricTestRunner
import org.robolectric.annotation.Config
/**
* [ConversionForegroundType.current] answers differently on each of the three API regimes, and
* until this file only one of them was ever executed.
*
* `app/src/test/resources/robolectric.properties` pins the whole JVM suite to `sdk=36`, so every
* Robolectric test that reaches a `ForegroundInfo` takes the `mediaProcessing` arm and no other.
* The 33 and 34 arms were cold: 3 lines and 3 of 4 branches, measured on `main` at `d354f64`.
*
* **The instrumented test is not a substitute, and the reason is specific.**
* `ConversionWorkerTest.foregroundTypeMatchesTheRunningApiLevel` asserts against whichever API the
* leg happens to be — one arm per leg, never the other two — and the legs that would cover 33 and
* 34 are the ones issue #122 wedges. `docs/coverage-read-findings.md` records an API 33 run that
* reported `received: 60` and `failed: unknown`: the regime *was* exercised, and that leg could
* not have said so if it had broken. Four `@Config` classes here pin all three arms
* deterministically, in the same `./gradlew` invocation as everything else.
*
* `minSdk` is 33, so none of these is dead code — each is a device someone is running the app on.
*
* **SDK 35 is in the list for the boundary, not for the answer.** It shares its answer with 36,
* which would make it look redundant. It is not: relaxing `>= VANILLA_ICE_CREAM` to `>` is invisible
* at every level except exactly 35, so without this class that mutation survives the suite.
*/
@RunWith(RobolectricTestRunner::class)
@Config(sdk = [33])
class ForegroundTypeApi33Test {
/**
* Zero rather than a named constant because there is no constant to name: API 33 does not
* require a type, and `mediaProcessing` does not exist here to pass. `ForegroundInfo` reads 0
* as "no type at all", which is what this regime wants.
*/
@Test
fun `api 33 asks for no foreground service type`() {
assertEquals(0, ConversionForegroundType.current())
}
}
/**
* API 34 makes a type mandatory and still has no `mediaProcessing`, so `dataSync` is the only
* sensible fit. See [ForegroundTypeApi33Test] for why this file exists.
*/
@RunWith(RobolectricTestRunner::class)
@Config(sdk = [34])
class ForegroundTypeApi34Test {
@Test
fun `api 34 falls back to dataSync, the only type that fits`() {
assertEquals(ServiceInfo.FOREGROUND_SERVICE_TYPE_DATA_SYNC, ConversionForegroundType.current())
}
}
/**
* The first level with `mediaProcessing`, and therefore the one that tells `>=` from `>`.
* See [ForegroundTypeApi33Test].
*/
@RunWith(RobolectricTestRunner::class)
@Config(sdk = [35])
class ForegroundTypeApi35Test {
@Test
fun `api 35 is the first level that takes mediaProcessing`() {
assertEquals(ServiceInfo.FOREGROUND_SERVICE_TYPE_MEDIA_PROCESSING, ConversionForegroundType.current())
}
}
/**
* The level the rest of the suite runs at, asserted here rather than assumed — it is the one arm
* that was already covered, and leaving it out would make this file look like it is about the old
* levels rather than about all three regimes. See [ForegroundTypeApi33Test].
*/
@RunWith(RobolectricTestRunner::class)
@Config(sdk = [36])
class ForegroundTypeApi36Test {
@Test
fun `api 36 keeps mediaProcessing`() {
assertEquals(ServiceInfo.FOREGROUND_SERVICE_TYPE_MEDIA_PROCESSING, ConversionForegroundType.current())
}
}