From 8a531cd398bfad96cd71006d2670379bcad6bcac Mon Sep 17 00:00:00 2001 From: Martin Vogel Date: Tue, 6 Oct 2026 03:36:33 +0200 Subject: [PATCH] fix(test): a failed Windows preflight contract leaves its reason in the leg log The isolated-venue contract ran the native preflight contract under `set -e`, so a failure ended the script before its log was printed, and the directory it announced as retained is swept by the next win.sh call's preflight. A full Windows leg failed there once (not reproduced: three runs under the same protected temp root passed) and left nothing to attribute. The native log is now always printed, and on failure each case's output too, with PowerShell's UTF-16 bytes dropped so the log stays text. The VM verdict also reads the log as text (grep -a): a NUL or a UTF-16 byte-order mark made grep call the log binary and print no matches with -o, so failures after such bytes were counted as zero -- an iteration-mode run reporting "2 failed" with a lost exit status was green. The verdict contract pins that case (15 cases). Signed-off-by: Martin Vogel --- test-infrastructure/vm/vm-run-tests.sh | 8 +++++--- tests/test_vm_isolation_contract.sh | 19 +++++++++++++++++-- tests/test_vm_verdict_contract.sh | 8 +++++++- 3 files changed, 29 insertions(+), 6 deletions(-) diff --git a/test-infrastructure/vm/vm-run-tests.sh b/test-infrastructure/vm/vm-run-tests.sh index d3672d3bd..ee45b7539 100644 --- a/test-infrastructure/vm/vm-run-tests.sh +++ b/test-infrastructure/vm/vm-run-tests.sh @@ -60,20 +60,22 @@ vm_verdict() { local log="$1" local rc="$2" local mode="${3:-full}" - if ! grep -Eq '[0-9]+ passed' "$log"; then + # -a: a NUL or UTF-16 byte anywhere makes grep call the log binary and + # print no matches, which would count its failures as zero. + if ! grep -aEq '[0-9]+ passed' "$log"; then echo "GUARD: test runner produced no completion summary — the suites did" \ "not validly run; treating as failure (runner rc=$rc)" >&2 return 90 fi local failed_total local complete - failed_total=$(grep -Eo '[0-9]+ failed' "$log" | grep -Eo '^[0-9]+' | + failed_total=$(grep -aEo '[0-9]+ failed' "$log" | grep -Eo '^[0-9]+' | awk '{s += $1} END {print s + 0}') # The marker counts only as the last step header of the log: the full leg's # own contract steps echo runner-shaped lines (a stubbed entry prints the # marker), so a marker followed by another step is that step's output. complete=0 - if [ "$(grep -E '^=== ' "$log" | tail -n 1 | tr -d '\r')" = '=== All tests passed ===' ]; then + if [ "$(grep -aE '^=== ' "$log" | tail -n 1 | tr -d '\r')" = '=== All tests passed ===' ]; then complete=1 fi if [ "${failed_total:-0}" -gt 0 ]; then diff --git a/tests/test_vm_isolation_contract.sh b/tests/test_vm_isolation_contract.sh index 9c7f5236f..e1fc49144 100644 --- a/tests/test_vm_isolation_contract.sh +++ b/tests/test_vm_isolation_contract.sh @@ -16,14 +16,29 @@ env -u CBM_VM_RUNNER -u CBM_VM_SOAK_BINARY bash \ "$task_repo/tests/test_vm_isolated_dispatch.sh" "$task_repo" "$task_contract_dir/dispatch" case "$(uname -s)" in MINGW* | MSYS* | CYGWIN*) + # The log is printed before the verdict: the retained directory does not + # outlive the next win.sh call (its preflight sweeps cbm-* roots), so the + # leg's own log is the only post-mortem a failure leaves. + task_native_rc=0 MSYS2_ARG_CONV_EXCL='*' powershell.exe -NoLogo -NoProfile -NonInteractive \ -ExecutionPolicy Bypass \ -File "$(cygpath -w "$task_repo/tests/test_windows_preflight_contract.ps1")" \ -ScriptPath "$(cygpath -w "$task_repo/scripts/ci/clean-test-residue.ps1")" \ -OutputDirectory "$(cygpath -w "$task_contract_dir/native")" \ - > "$task_contract_dir/native.log" 2>&1 + > "$task_contract_dir/native.log" 2>&1 || task_native_rc=$? cat "$task_contract_dir/native.log" - grep -Fq 'WINDOWS_CHECK_ONLY_COMPLETE failures=0 sentinels=2' "$task_contract_dir/native.log" + if [ "$task_native_rc" -ne 0 ] || + ! grep -Fq 'WINDOWS_CHECK_ONLY_COMPLETE failures=0 sentinels=2' "$task_contract_dir/native.log"; then + echo "native preflight contract failed (exit $task_native_rc); per-case output:" >&2 + for task_case_file in "$task_contract_dir"/native/*.out "$task_contract_dir"/native/*.err; do + [ -f "$task_case_file" ] || continue + echo "--- ${task_case_file##*/}" >&2 + # PowerShell 5.1 redirects in UTF-16LE: drop the NULs and the + # byte-order mark, which would make the leg log read as binary. + LC_ALL=C tr -d '\000\376\377' <"$task_case_file" >&2 + done + exit 1 + fi ;; *) # Native PowerShell/DACL behavior is covered by this same contract on the diff --git a/tests/test_vm_verdict_contract.sh b/tests/test_vm_verdict_contract.sh index 0aa9b4d13..835797a25 100755 --- a/tests/test_vm_verdict_contract.sh +++ b/tests/test_vm_verdict_contract.sh @@ -43,6 +43,10 @@ printf '%s\n' '=== Step 0y2: isolated Windows venue contract ===' \ 'capacity_accept exit=0 expected=0 passed=True' \ '=== Step 0z6: per-test coverage map builder contract ===' \ 'FAIL: missing output: tests.tsv' > "$WORK/marker_before_last_step" +# A NUL or a UTF-16 byte-order mark anywhere (PowerShell 5.1 redirects in +# UTF-16LE) makes grep call the log binary and print no matches with -o: the +# failures after it were counted as zero. +printf ' 10 passed, 0 failed\n\377\376b\000o\000m\000\n 5 passed, 2 failed\n' > "$WORK/binary_bytes" failures=0 expect() { # description log rc want [mode] @@ -73,6 +77,8 @@ expect "a summary without the completion marker is red" no_marker 0 1 # step came from that step's output, not from the end of the leg. expect "a marker before the last step is red with a lost rc" marker_before_last_step 1 1 expect "a marker before the last step is red with rc 0" marker_before_last_step 0 1 +# Bytes grep calls binary must not hide the failures after them. +expect "failures after binary bytes are red in iteration mode" binary_bytes 0 1 iteration # No summary at all keeps its own distinct code, so "never ran" stays # distinguishable from "ran and failed". @@ -95,4 +101,4 @@ if [ "$failures" -gt 0 ]; then echo "VM verdict contract VIOLATED: $failures case(s)" >&2 exit 1 fi -echo "VM verdict contract passed (14 cases: lost exit status, false green, partial runs, iteration mode)" +echo "VM verdict contract passed (15 cases: lost exit status, false green, partial runs, iteration mode)"