Files
LibreMediaConverter/.github/scripts/e2e-report-shape.sh
T
JMR-devandClaude Opus 5 25aac95db9 Say in the run-shape table when the wedge timeout was what killed the leg
The report added by #111 runs on every path out of e2e-run.sh, including the
wedge, and until now it answered a question it had not been asked. On job
98035980326 -- API 34, a docs-only PR -- it printed `received: 59` and
`completed cleanly: yes` six seconds before `##[warning] ... WEDGED`, for a leg
the WEDGE_TIMEOUT had killed 22 minutes in. `completed cleanly` means only
"instrumentation was not aborted", which was true; a reader scanning the table
had to notice a separate warning line to learn the leg had died.

The wedge cannot be read out of the log, which is why it is passed in: a wedge
is gradle never returning, so gradle printed no verdict, no truncation line and
no INSTRUMENTATION_ABORTED, and the log it leaves is the log of a run that just
stops. Only e2e-run.sh saw `timeout` exit 124. It now derives that fact once and
tells the report as E2E_WEDGED_AFTER, and reuses the same variable for
capture_wedge so the two cannot drift.

The table gains a `wedged:` row above `completed cleanly`, and `completed
cleanly` flips to no -- but only where it would have said yes. An abort already
says no and names the abort, which the wedge row does not, and a run that left
no evidence still says unknown; a wedge on top of either prints both facts.

`received`'s source line told the same lie in the same table -- "the run was not
truncated, so every expected test reported" is only "gradle never got as far as
saying so" when the leg was killed -- so it is qualified on that path. The
number itself is unchanged, and so is `failed: unknown`: gradle printed no
summary line, so that count genuinely is not knowable.

Nothing here decides anything. No exit status, no pass/fail rule, no baseline
comparison and no `::notice::` behaviour changes; the leg already failed
correctly and still does.

Verified against captured CI output rather than a live emulator, as #111 was and
for the same reason -- this host cannot run API 37 and cannot wedge on demand.
Four real logs (the wedged leg, a green API 34 leg, a failing gating leg, and an
advisory leg with its baseline deviation) through both versions of the script,
in both env states, comparing stdout and the job summary: only the wedged run
with the signal set differs, byte for byte.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-08-25 21:59:54 -05:00

331 lines
18 KiB
Bash
Executable File

#!/usr/bin/env bash
#
# Reports the SHAPE of an instrumented run -- how many tests were expected, how many
# reported, how many failed, and whether the run completed at all -- to the step log and to
# the job summary. In advisory mode it also compares that shape against a committed baseline
# and says plainly whether it matches.
#
# WHY THIS EXISTS (#83): the advisory API 37 leg is red on every PR by design, so a NEW failure
# joining the known ones is invisible -- nothing in a red X distinguishes "the known ones" from
# "the known ones plus yours". CLAUDE.md tells everyone not to read that job's red as their
# change breaking something, which is correct, and which also means nobody looks.
#
# WHY NOT A BARE FAILURE COUNT, measured rather than assumed. On this image the run is usually
# truncated: `Test run failed to complete. Expected 3 tests, received 2.` with
# `INSTRUMENTATION_ABORTED: System has crashed.` A count taken from a truncated run misleads in
# both directions -- a fourth marked test can still yield the same number if the abort lands
# earlier, and the known set getting worse can LOWER it. So all four fields are recorded, and
# the one saying the run was truncated is recorded with them.
#
# WHY IT IS A SEPARATE SCRIPT rather than a function inside e2e-run.sh: it is a pure seam. It
# reads a captured log plus the test XML and writes a report, so it can be run against a REAL
# log saved from a REAL CI run -- which is how the baseline comparison was shown to fire
# without waiting on an emulator. `git ls-files '*.sh'` also picks it up for shellcheck for
# free.
#
# THIS SCRIPT NEVER FAILS A RUN. It is a diagnostic, and e2e-run.sh's header explains why that
# rule is absolute here. Every field defaults to `unknown` and every comparison is guarded,
# because an unset variable under `set -u`, or a `[ "" -eq 3 ]`, is exactly how a diagnostic
# becomes the thing that turns a leg red. It exits 0 unconditionally.
#
# Usage:
# e2e-report-shape.sh <label> <gradle-log> [<baseline-file>]
# E2E_WEDGED_AFTER=<seconds> the wrapper timeout killed gradle after that many seconds
#
# With a third argument the run is compared against the baseline in that file (advisory mode)
# and a `::notice::` is emitted per deviation. NEVER `::error::`: the advisory job is
# `continue-on-error: true` and stays that way, and an error annotation would be a new way for
# a diagnostic to change a conclusion.
#
# WHY THE WEDGE ARRIVES AS AN ENV VAR (#118) rather than being read out of the log like every
# other field: there is nothing in the log to read. A wedge is gradle never returning, so gradle
# never printed a verdict, never printed a truncation line, and never aborted instrumentation --
# the log of a wedged leg is the log of a run that simply stops. Measured on job 98035980326:
# `expected: 59`, `received: 59`, `completed cleanly: yes`, six seconds before the wedge warning,
# for a leg that the timeout had killed 22 minutes in. Only e2e-run.sh knows, because only it
# saw `timeout` exit 124, so it says so. Guessing it from a log that ends abruptly would call
# every cancelled run a wedge.
#
# It is read as a STRING and only ever interpolated into one. `[ -n ... ]`, never `-gt`: it
# crosses a process boundary from a shell that deliberately sets it EMPTY on every non-wedge
# path, and an arithmetic test on an empty string is the header's rule four paragraphs up.
set -uo pipefail
LABEL="${1:-unknown}"
LOG="${2:-}"
BASELINE_FILE="${3:-}"
WEDGED_AFTER="${E2E_WEDGED_AFTER:-}"
SCRIPT_DIR="$(cd -- "$(dirname -- "${BASH_SOURCE[0]}")" && pwd)"
REPO_ROOT="$(cd -- "$SCRIPT_DIR/../.." && pwd)"
XML_DIR="$REPO_ROOT/app/build/outputs/androidTest-results/connected/debug"
# Gradle colours its output even when it is piped, so `FAILED` arrives wrapped in escape codes.
# The numeric lines parsed below are not coloured, but stripping is cheap insurance against a
# pattern that would otherwise silently match nothing.
ESC="$(printf '\033')"
scan() { [ -s "$LOG" ] && sed -e "s/${ESC}\[[0-9;]*[a-zA-Z]//g" -- "$LOG"; }
first_number() { grep -oE '[0-9]+' | head -1; }
# ---------------------------------------------------------------------------
# Source 1: the runner's own output. This is the ONLY place a truncation is visible. The test
# XML read below is written even for an aborted run and says nothing whatever about the abort
# -- measured on run 32865281555, where the XML reports a tidy tests="3" failures="3" for a run
# the runner had just described as truncated. That is the reason this parses stdout at all.
# ---------------------------------------------------------------------------
starting_line="$(scan | grep -aoE 'Starting [0-9]+ tests on .*' | tail -1)"
abort_line="$(scan | grep -aoE 'Test run failed to complete\. Expected [0-9]+ tests, received [0-9]+\.' | tail -1)"
aborted_hits="$(scan | grep -ac 'INSTRUMENTATION_ABORTED' || true)"
failure_line="$(scan | grep -aoE 'There was [0-9]+ failure\(s\)\.' | tail -1)"
failed_names="$(scan | grep -aoE 'Execute [A-Za-z0-9_.$]+: FAILED' | sed -e 's/^Execute //' -e 's/: FAILED$//' | sort -u)"
expected="$(printf '%s' "$starting_line" | first_number)"
expected_src="\`$starting_line\`"
abort_expected="$(printf '%s' "$abort_line" | grep -oE 'Expected [0-9]+' | first_number)"
abort_received="$(printf '%s' "$abort_line" | grep -oE 'received [0-9]+' | first_number)"
log_failed="$(printf '%s' "$failure_line" | first_number)"
# `Starting N tests` is missing when the framework restarted under the run and Gradle never got
# a test list. The truncation line still carries the number it was told to expect.
if [ -z "$expected" ] && [ -n "$abort_expected" ]; then
expected="$abort_expected"
expected_src="\`$abort_line\`"
fi
# ---------------------------------------------------------------------------
# Source 2: the JUnit XML. Measured on both a truncated advisory run and a green gating leg:
# `<testsuites tests="N" failures="M">` is present in both, and aggregates every suite. It is
# the authority on how many results landed and how many were failures. It is NOT an authority
# on whether the run finished, which is what source 1 is for.
# ---------------------------------------------------------------------------
#
# Read ONLY when the runner said a test run happened. `app/build` survives between runs on a
# developer machine -- tools/local-emulator/run-e2e.sh drives several API levels against one
# checkout -- so a leg that never got as far as starting tests would otherwise be reported from
# the previous leg's XML, which is a wrong answer rather than a missing one.
xml_head=""
xml_count=0
if [ -n "$starting_line$abort_line" ] && [ -d "$XML_DIR" ]; then
while IFS= read -r f; do
xml_count=$((xml_count + 1))
[ -z "$xml_head" ] && xml_head="$(grep -ao '<testsuites[^>]*>' "$f" | head -1)"
done < <(find "$XML_DIR" -maxdepth 1 -name 'TEST-*.xml' -print 2> /dev/null | sort)
fi
xml_tests="$(printf '%s' "$xml_head" | grep -oE ' tests="[0-9]+"' | first_number)"
xml_failed="$(printf '%s' "$xml_head" | grep -oE ' failures="[0-9]+"' | first_number)"
# ---------------------------------------------------------------------------
# Derive the four fields, each with where its number came from. Everything stays a string, so a
# missing source reads `unknown` rather than becoming 0 -- a report claiming 0 tests when it
# merely could not see them would announce a deviation on every cancelled run.
# ---------------------------------------------------------------------------
received="unknown"
received_src="no source"
if [ -n "$xml_tests" ]; then
received="$xml_tests"
received_src="test XML \`<testsuites tests=\"$xml_tests\">\`"
elif [ -n "$abort_received" ]; then
received="$abort_received"
received_src="\`$abort_line\`"
elif [ -n "$expected" ] && [ -z "$abort_line" ]; then
received="$expected"
received_src="the run was not truncated, so every expected test reported"
# ... unless it was killed, in which case "not truncated" is only "gradle never got as far as
# saying so". This is the branch the wedged leg in #118 took -- with no XML written yet, the
# number is what the runner was TOLD to run, and the source line said the opposite in the same
# table that called the leg clean. The number is deliberately left alone: it is still the best
# available answer, and only the claim about where it came from was wrong.
[ -n "$WEDGED_AFTER" ] \
&& received_src="no test XML was written and gradle never printed a truncation line — but the leg was killed mid-run, so this is what it was told to run, not what reported"
fi
failed="unknown"
failed_src="no source"
if [ -n "$xml_failed" ]; then
failed="$xml_failed"
failed_src="test XML \`<testsuites failures=\"$xml_failed\">\`"
elif [ -n "$log_failed" ]; then
failed="$log_failed"
failed_src="\`$failure_line\`"
fi
if [ -z "$expected" ]; then
expected="unknown"
expected_src="no \`Starting N tests\` line"
fi
# A run whose start nobody can see is not a run of zero tests. Cancellation (this workflow sets
# cancel-in-progress) and the `Starting 0 tests` shape a framework restart produces both land
# here, and both have to say so rather than compare a number that does not exist.
no_run="none"
if [ "$expected" = "unknown" ] && [ "$received" = "unknown" ]; then
no_run="nothing"
elif [ "$expected" = "0" ]; then
no_run="zero"
fi
if [ -n "$abort_line" ]; then
completed="**no**"
completed_src="\`$abort_line\` with \`INSTRUMENTATION_ABORTED\`"
elif [ "${aborted_hits:-0}" -gt 0 ]; then
completed="**no**"
completed_src="\`INSTRUMENTATION_ABORTED\` in the runner output"
elif [ "$no_run" = "nothing" ]; then
# "cleanly" would be a lie about a run that left no evidence it happened.
completed="unknown"
completed_src="no runner output to read"
elif [ -n "$WEDGED_AFTER" ]; then
# The wedge is checked LAST of the four, so it only ever overrides the `yes`. The two "no"s
# above are already right and name the abort, which the wedge row does not; `unknown` is
# already right too. A wedge on top of an abort is both facts, and both get printed.
completed="**no**"
completed_src="the wrapper timeout killed gradle after ${WEDGED_AFTER}s — instrumentation itself was never aborted, which is why nothing in the log says so"
else
completed="yes"
completed_src="no truncation line and no \`INSTRUMENTATION_ABORTED\`"
fi
# ---------------------------------------------------------------------------
# Advisory mode: compare against the committed baseline.
#
# ONE number covers both compared fields, and that is deliberate rather than a shortcut. The
# marker means "cannot pass on this image", so the number of tests carrying it is both how many
# the advisory leg should run and how many should fail. A smaller `failed` means one now passes
# -- which is the trigger to delete the annotation, written down in FailsOnEmulatorApi37.kt.
# ---------------------------------------------------------------------------
#
# `advisory` and `baseline` are two variables on purpose. "A comparison was asked for" and "a
# number was found to compare against" are different facts, and collapsing them is how this
# report would go quietly back to being the thing #83 filed: the `sed` below is anchored, so
# indenting the const into an object -- or renaming it, or moving it to another file -- empties
# `baseline`, and a single flag would take the whole comparison down with it while the table
# kept printing. An unreadable baseline is itself a deviation, and is announced as one.
advisory="no"
baseline=""
marked=""
deviations=()
if [ -n "$BASELINE_FILE" ]; then
advisory="yes"
[ -f "$BASELINE_FILE" ] \
&& baseline="$(sed -nE 's/^const val FAILS_ON_EMULATOR_API37_BASELINE = ([0-9]+).*/\1/p' "$BASELINE_FILE" | head -1)"
# The #81 check, verbatim: what the tree actually carries. Reported next to the baseline so a
# stale baseline shows up here rather than only once the emulator disagrees with it.
if [ -d "$REPO_ROOT/app/src/androidTest" ]; then
marked="$(grep -rn "@FailsOnEmulatorApi37" "$REPO_ROOT/app/src/androidTest" --include='*.kt' \
| grep -v import | grep -c FailsOn || true)"
fi
fi
if [ "$advisory" = "yes" ] && [ -z "$baseline" ]; then
deviations+=("the committed baseline could not be read from \`$(basename -- "$BASELINE_FILE")\` — has \`FAILS_ON_EMULATOR_API37_BASELINE\` been renamed, indented into a class, or moved? Nothing was compared")
fi
if [ -n "$baseline" ]; then
if [ "$no_run" = "nothing" ]; then
deviations+=("no test run observed — the runner never reported starting one, where the baseline expects $baseline tests carrying \`@FailsOnEmulatorApi37\`")
elif [ "$no_run" = "zero" ]; then
deviations+=("the runner started 0 tests, where the baseline expects $baseline — on this image that is the framework having restarted under the run, not an empty test list")
else
if [ "$expected" != "unknown" ] && [ "$expected" != "$baseline" ]; then
deviations+=("the runner started $expected tests, the baseline is $baseline")
fi
if [ "$failed" != "unknown" ] && [ "$failed" != "$baseline" ]; then
deviations+=("$failed tests failed, the baseline is $baseline — every test carrying the marker is expected to fail on this image, so fewer means one now passes and more means a new one joined")
fi
fi
if [ -n "$marked" ] && [ "$marked" != "$baseline" ]; then
deviations+=("the tree carries $marked tests marked \`@FailsOnEmulatorApi37\` but the baseline says $baseline — update FAILS_ON_EMULATOR_API37_BASELINE")
fi
fi
# ---------------------------------------------------------------------------
# Emit. Step log first, so the common case needs neither the summary page nor an artifact.
# ---------------------------------------------------------------------------
echo "----- RUN SHAPE (api${LABEL}) -----"
echo " expected: $expected"
echo " received: $received"
echo " failed: $failed"
# Above `completed cleanly`, because it is the line that says what happened to the leg and the
# other one only qualifies it. A reader who stops after three rows still sees it.
if [ -n "$WEDGED_AFTER" ]; then
echo " wedged: yes -- gradle was killed after ${WEDGED_AFTER}s and never returned"
fi
echo " completed cleanly: ${completed//\*/}"
if [ -n "$abort_received" ]; then
echo " received before the abort: $abort_received"
fi
if [ -n "$failed_names" ]; then
echo " failed tests:"
printf '%s\n' "$failed_names" | sed -e 's/^/ /'
fi
if [ "$advisory" = "yes" ]; then
if [ "${#deviations[@]}" -eq 0 ]; then
echo " baseline: matches ($baseline expected, $baseline failed)"
else
printf ' baseline DEVIATION: %s\n' "${deviations[@]}"
fi
fi
# A notice, never an error. See the header.
if [ "${#deviations[@]}" -gt 0 ]; then
for d in "${deviations[@]}"; do
echo "::notice::E2E api${LABEL}: $d"
done
fi
if [ -n "${GITHUB_STEP_SUMMARY:-}" ]; then
{
echo "### E2E api${LABEL} — run shape"
echo
echo "| field | value | where it came from |"
echo "| --- | --- | --- |"
echo "| expected | $expected | $expected_src |"
echo "| received | $received | $received_src |"
echo "| failed | $failed | $failed_src |"
if [ -n "$WEDGED_AFTER" ]; then
echo "| wedged | **yes** | \`timeout\` fired after ${WEDGED_AFTER}s and killed gradle (exit 124), which is what e2e-run.sh then captured the wedge diagnostics for |"
fi
echo "| completed cleanly | $completed | $completed_src |"
if [ -n "$abort_received" ]; then
echo "| received before the abort | $abort_received | the same line — the XML above counts the truncated test as a failure, this number does not |"
fi
echo
if [ -n "$failed_names" ]; then
echo "Failed:"
echo
printf '%s\n' "$failed_names" | sed -e 's/^/- `/' -e 's/$/`/'
echo
fi
if [ "$xml_count" -gt 1 ]; then
echo "> $xml_count test XML files were present; the counts above come from the first."
echo
fi
if [ "$advisory" = "yes" ]; then
if [ "${#deviations[@]}" -eq 0 ]; then
echo "**Matches the committed baseline of $baseline** — $baseline tests carry \`@FailsOnEmulatorApi37\` and all $baseline failed, which is what this job is for."
elif [ -z "$baseline" ]; then
echo "**The committed baseline could not be read, so nothing was compared.** Announced as a notice, not an error: this job is advisory and its conclusion is unchanged by anything here."
echo
printf -- '- %s\n' "${deviations[@]}"
else
echo "**DEVIATION from the committed baseline of $baseline.** Announced as a notice, not an error: this job is advisory and its conclusion is unchanged by anything here."
echo
printf -- '- %s\n' "${deviations[@]}"
fi
echo
echo "<sub>The baseline lives beside the marker, in \`FailsOnEmulatorApi37.kt\`. \`completed cleanly\` is recorded rather than compared: the truncation is intermittent — of eight advisory runs read on 2026-08-25, seven aborted and one did not — so comparing it would announce a deviation on a run that is fine.</sub>"
else
echo "<sub>No baseline comparison: that is the advisory API 37 leg only. The shape is recorded here anyway because a truncated run reports fewer results than it ran, which is what issue #108 looks like on a gating leg.</sub>"
fi
echo
} >> "$GITHUB_STEP_SUMMARY"
# The summary page is the deliverable -- "readable without opening a log" is what #83 asked
# for -- and GitHub exposes no API for reading a job summary back, so a write that silently
# did not happen would be invisible. This line is in the step log, which can be read.
echo " (the table above is also on the job summary page)"
else
echo " (GITHUB_STEP_SUMMARY is unset -- step log only)"
fi
exit 0