fix(config): run-godot reported double the real test count, and could not see skips
Two parsing bugs in the summary, found while measuring suite times. DOUBLE COUNT. gdUnit4 prints one "Statistics:" line per suite and then a single "Overall Summary:" line whose numbers are the sum of all of them. The pattern matched both shapes and summed all 87 lines, so every total was exactly twice the truth: a full run reported 3,660 tests against an actual 1,830, and a 26-test suite reported 52. It was invisible because it doubled UNIFORMLY — nothing ever looked inconsistent, only large. Every count quoted from this harness, in this session and before it, was 2x. Now prefers the Overall Summary, which is gdUnit4's own arithmetic over the whole run and so cannot disagree with itself; per-suite summing survives only as a fallback for a run that dies before printing it. ANSI. gdUnit4 colourises output and the escape sequences sit BETWEEN the fields of the summary line, so patterns matching the raw log silently fell through to the weaker "Executed test cases" fallback — which cannot see skips and reported a fully skipped suite as 26 FAILED. All parsing now runs against a de-ANSI'd copy, including the load-error guards. SKIPS are now parsed and surfaced as their own JSON field, and excluded from passed. Counting a skipped test as passing is the same false-green shape the harness guards exist to prevent, and it stops being hypothetical the moment a suite is deliberately skipped. Verified against a fully-skipped suite (26 total / 0 passed / 0 failed / 26 skipped, was 26 FAILED) and a full run (1,830 total / 1,804 passed / 0 failed / 26 skipped, was 3,660/3,660). Pair session with Jeroen, 2026-07-27. Co-Authored-By: Claude <noreply@anthropic.com>
This commit is contained in:
+43
-15
@@ -3,7 +3,8 @@
|
||||
#
|
||||
# Exit: 0 = all pass, non-zero = failure.
|
||||
# Stdout: JSON summary on ONE line, plus a pointer to the full log.
|
||||
# {"suite":"godot","total":N,"passed":N,"failed":N,"duration_ms":N,"log":"/tmp/sr-run-godot.log"}
|
||||
# {"suite":"godot","total":N,"passed":N,"failed":N,"skipped":N,"duration_ms":N,"log":"..."}
|
||||
# (on a harness failure: same JSON + "harness_error":"load_error"|"no_tests"; exit 2)
|
||||
# (on timeout: same JSON + "timeout":true, "timeout_sec":N; exit code 124)
|
||||
# Stderr: a short hint line pointing at the log. The Godot/gdUnit4 output
|
||||
# does NOT stream to stdout or stderr — it is captured to the log file.
|
||||
@@ -85,20 +86,47 @@ if [[ "$EXIT_CODE" -eq 124 || "$EXIT_CODE" -eq 137 ]]; then
|
||||
TIMED_OUT=true
|
||||
fi
|
||||
|
||||
# gdUnit4 outputs per-suite statistics: "N test cases | X errors | Y failures | ..."
|
||||
TOTAL=0; PASSED=0; FAILED=0
|
||||
STATS_LINES=$(grep -oE "[0-9]+ test cases \| [0-9]+ errors \| [0-9]+ failures" "$LOG_FILE" || true)
|
||||
if [[ -n "$STATS_LINES" ]]; then
|
||||
TOTAL=$(echo "$STATS_LINES" | grep -oE '^[0-9]+' | awk '{s+=$1} END {print s}')
|
||||
ERRORS=$(echo "$STATS_LINES" | grep -oE '[0-9]+ errors' | grep -oE '^[0-9]+' | awk '{s+=$1} END {print s}')
|
||||
FAILURES=$(echo "$STATS_LINES" | grep -oE '[0-9]+ failures' | grep -oE '^[0-9]+' | awk '{s+=$1} END {print s}')
|
||||
FAILED=$(( ${ERRORS:-0} + ${FAILURES:-0} ))
|
||||
PASSED=$(( TOTAL - FAILED ))
|
||||
# gdUnit4 prints one "Statistics:" line PER SUITE and then a single
|
||||
# "Overall Summary:" line whose numbers are the sum of all of them.
|
||||
#
|
||||
# BUG FIXED 2026-07-27: the old pattern matched BOTH shapes and summed all of
|
||||
# them, so every reported total was exactly DOUBLE — the real number plus the
|
||||
# summary that already contained it. A full run reported 3,660 tests against an
|
||||
# actual 1,830, and a 26-test suite reported 52. It had been wrong for as long
|
||||
# as the summary line has existed, and it was invisible precisely because it
|
||||
# doubled uniformly: nothing ever looked inconsistent, only large.
|
||||
#
|
||||
# Prefer the Overall Summary — it is gdUnit4's own arithmetic over the whole
|
||||
# run, so it cannot disagree with itself. Fall back to summing per-suite lines
|
||||
# only if it is absent (older gdUnit4, or a run that died mid-way).
|
||||
# gdUnit4 colourises its output, and the escape sequences sit BETWEEN the
|
||||
# fields of the summary line — so every pattern here must run against a
|
||||
# de-ANSI'd copy. Matching the raw log silently falls through to the weaker
|
||||
# "Executed test cases" fallback, which cannot see skips and reported a fully
|
||||
# skipped suite as 26 FAILED (caught 2026-07-27, immediately after the
|
||||
# double-count fix — same log, second lie).
|
||||
CLEAN_LOG="${LOG_FILE%.log}.clean.log"
|
||||
sed 's/\x1b\[[0-9;]*m//g' "$LOG_FILE" > "$CLEAN_LOG" 2>/dev/null || cp "$LOG_FILE" "$CLEAN_LOG"
|
||||
|
||||
TOTAL=0; PASSED=0; FAILED=0; SKIPPED=0
|
||||
SUMMARY_LINE=$(grep -oE "Overall Summary: [0-9]+ test cases \| [0-9]+ errors \| [0-9]+ failures \| [0-9]+ flaky \| [0-9]+ skipped" "$CLEAN_LOG" | tail -1 || true)
|
||||
if [[ -z "$SUMMARY_LINE" ]]; then
|
||||
SUMMARY_LINE=$(grep -oE "Statistics: [0-9]+ test cases \| [0-9]+ errors \| [0-9]+ failures \| [0-9]+ flaky \| [0-9]+ skipped" "$CLEAN_LOG" || true)
|
||||
fi
|
||||
if [[ -n "$SUMMARY_LINE" ]]; then
|
||||
_sum() { echo "$SUMMARY_LINE" | grep -oE "[0-9]+ $1" | grep -oE '^[0-9]+' | awk '{s+=$1} END {print s+0}'; }
|
||||
TOTAL=$(echo "$SUMMARY_LINE" | grep -oE '[0-9]+ test cases' | grep -oE '^[0-9]+' | awk '{s+=$1} END {print s+0}')
|
||||
FAILED=$(( $(_sum errors) + $(_sum failures) ))
|
||||
SKIPPED=$(_sum skipped)
|
||||
# A skipped test is NOT a passing test. Counting it as one is the same
|
||||
# false-green shape the guards below exist to prevent — and it matters now
|
||||
# that whole suites are deliberately skipped (test_character_visual_sprint28).
|
||||
PASSED=$(( TOTAL - FAILED - SKIPPED ))
|
||||
fi
|
||||
|
||||
# Fallback: parse "Executed test cases : (X/N)" for total if stats parse failed
|
||||
if [[ "$TOTAL" -eq 0 ]]; then
|
||||
EXEC_LINE=$(grep -oE "Executed test cases : \([0-9]+/[0-9]+\)" "$LOG_FILE" | tail -1 || true)
|
||||
EXEC_LINE=$(grep -oE "Executed test cases : \([0-9]+/[0-9]+\)" "$CLEAN_LOG" | tail -1 || true)
|
||||
if [[ -n "$EXEC_LINE" ]]; then
|
||||
TOTAL=$(echo "$EXEC_LINE" | grep -oE '/[0-9]+\)' | grep -oE '[0-9]+')
|
||||
PASSED=$(echo "$EXEC_LINE" | grep -oE '\([0-9]+/' | grep -oE '[0-9]+')
|
||||
@@ -116,8 +144,8 @@ fi
|
||||
# Neither is a test RESULT, so neither may be reported as one. A run that
|
||||
# executed zero tests is never a pass, and a run that could not load a suite
|
||||
# is a harness failure regardless of how many other suites went green.
|
||||
LOAD_ERROR_COUNT=$(grep -c 'Failed to load script' "$LOG_FILE" 2>/dev/null || true)
|
||||
LOAD_ERROR_LIST=$(grep -oE 'Failed to load script "[^"]+"' "$LOG_FILE" 2>/dev/null | sort -u || true)
|
||||
LOAD_ERROR_COUNT=$(grep -c 'Failed to load script' "$CLEAN_LOG" 2>/dev/null || true)
|
||||
LOAD_ERROR_LIST=$(grep -oE 'Failed to load script "[^"]+"' "$CLEAN_LOG" 2>/dev/null | sort -u || true)
|
||||
HARNESS_ERROR=""
|
||||
if [[ "${LOAD_ERROR_COUNT:-0}" -gt 0 ]]; then
|
||||
HARNESS_ERROR="load_error"
|
||||
@@ -135,8 +163,8 @@ elif [[ -n "$HARNESS_ERROR" ]]; then
|
||||
printf '{"suite":"godot","total":%d,"passed":%d,"failed":%d,"duration_ms":%d,"harness_error":"%s","log":"%s"}\n' \
|
||||
"${TOTAL:-0}" "${PASSED:-0}" "${FAILED:-0}" "$DURATION_MS" "$HARNESS_ERROR" "$LOG_FILE"
|
||||
else
|
||||
printf '{"suite":"godot","total":%d,"passed":%d,"failed":%d,"duration_ms":%d,"log":"%s"}\n' \
|
||||
"${TOTAL:-0}" "${PASSED:-0}" "${FAILED:-0}" "$DURATION_MS" "$LOG_FILE"
|
||||
printf '{"suite":"godot","total":%d,"passed":%d,"failed":%d,"skipped":%d,"duration_ms":%d,"log":"%s"}\n' \
|
||||
"${TOTAL:-0}" "${PASSED:-0}" "${FAILED:-0}" "${SKIPPED:-0}" "$DURATION_MS" "$LOG_FILE"
|
||||
fi
|
||||
|
||||
# Hint line on stderr. Stays short. LLM callers: read this literally.
|
||||
|
||||
Reference in New Issue
Block a user