From 026c9d06749831a5de0ff750aff731cd01044c6b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gonzalo=20Pe=C3=B1a-Castellanos?= Date: Thu, 29 Oct 2026 18:20:45 -0500 Subject: [PATCH 1/6] ci: print live test results to the job log --- .github/workflows/test-live.yml | 9 ++++++- scripts/live-test-report.sh | 26 ++++++++++++++++--- scripts/live-test-report_test.sh | 44 ++++++++++++++++++++++++++++++++ 3 files changed, 74 insertions(+), 5 deletions(-) create mode 100755 scripts/live-test-report_test.sh diff --git a/.github/workflows/test-live.yml b/.github/workflows/test-live.yml index 49b70f69..4919eaac 100644 --- a/.github/workflows/test-live.yml +++ b/.github/workflows/test-live.yml @@ -70,7 +70,14 @@ jobs: env: B2_APPLICATION_KEY_ID: ${{ secrets.B2_APPLICATION_KEY_ID }} B2_APPLICATION_KEY: ${{ secrets.B2_APPLICATION_KEY }} - run: go test -json -count=1 -timeout 30m ./b2/... ./base/... > test.json + run: | + set -o pipefail + go test -json -count=1 -timeout 30m ./b2/... ./base/... | tee test.json | jq -rj --unbuffered ' + if .Test == null and .Action == "output" then .Output + elif .Action == "pass" or .Action == "fail" or .Action == "skip" then + select(.Test != null and (.Test | contains("/") | not)) + | "\(.Action | ascii_upcase) \(.Package | sub(".*/blazer/"; "")) \(.Test) (\(.Elapsed // 0)s)\n" + else empty end' - name: Report live test results if: ${{ always() && steps.creds.outcome == 'success' }} run: scripts/live-test-report.sh test.json diff --git a/scripts/live-test-report.sh b/scripts/live-test-report.sh index 8c87a77f..99540770 100755 --- a/scripts/live-test-report.sh +++ b/scripts/live-test-report.sh @@ -1,12 +1,12 @@ #!/usr/bin/env bash # Summarizes a `go test -json` run of the live tests and fails unless they really ran against B2. # Usage: scripts/live-test-report.sh test.json -# Writes a Markdown summary to $GITHUB_STEP_SUMMARY when set. Exit 1 when a test failed, when any test +# Prints the Markdown summary and the output of failed tests to stdout (the job log) and, when set, also +# appends the summary to $GITHUB_STEP_SUMMARY. Exit 1 when a test failed, when any test # skipped, or when a test defined in a live test file did not pass. set -euo pipefail in=${1:?usage: live-test-report.sh test.json} -summary=${GITHUB_STEP_SUMMARY:-/dev/stdout} module=github.com/Backblaze/blazer # Every top-level test in these files must run and pass; there is no other way to tell they reached B2. live_files=(b2/integration_test.go b2/lock_test.go base/integration_test.go) @@ -34,7 +34,7 @@ list() { while IFS= read -r line; do echo "- \`${line#"$module"/}\`"; done <<<"$2" } -{ +report() { echo "## Live integration tests" echo echo "Commit \`${GITHUB_SHA:-local}\` ยท trigger \`${GITHUB_EVENT_NAME:-local}\`" @@ -46,7 +46,25 @@ list() { list "Failed packages" "$failed_pkgs" list "Skipped (no test may skip in the live run)" "$skipped" list "Live tests that did not pass" "$missing" -} >>"$summary" +} + +if [ -n "${GITHUB_STEP_SUMMARY:-}" ]; then + report | tee -a "$GITHUB_STEP_SUMMARY" +else + report +fi + +# Where the time went, per package, so the log shows what ran. +jq -r 'select(.Test == null and (.Action == "pass" or .Action == "fail" or .Action == "skip")) + | "\(.Action | ascii_upcase) \(.Package) (\(.Elapsed // 0)s)"' "$in" | sed "s#$module/##" + +if [ -n "$failed" ]; then + echo "::group::Output of failed tests" + jq -rs '[.[] | select(.Action == "fail" and .Test != null) | {p: .Package, t: .Test}] as $f + | .[] | select(.Action == "output" and .Test != null and ([{p: .Package, t: .Test}] | inside($f))) + | .Output' "$in" | head -n 300 + echo "::endgroup::" +fi status=0 [ -n "$failed" ] && { echo "::error::Tests failed in the live run."; status=1; } diff --git a/scripts/live-test-report_test.sh b/scripts/live-test-report_test.sh new file mode 100755 index 00000000..7696e311 --- /dev/null +++ b/scripts/live-test-report_test.sh @@ -0,0 +1,44 @@ +#!/usr/bin/env bash +# Tests scripts/live-test-report.sh against a small `go test -json` fixture. +set -euo pipefail + +here=$(cd "$(dirname "$0")" && pwd) +root=$(cd "$here/.." && pwd) +tmp=$(mktemp -d) +trap 'rm -rf "$tmp"' EXIT +cd "$root" + +# Every top-level test of the live files, all passing. +live=$(for f in b2/integration_test.go b2/lock_test.go base/integration_test.go; do + grep -oE '^func Test[A-Za-z0-9_]*\(t \*testing\.T\)' "$f" | + sed -E "s#^func (Test[A-Za-z0-9_]*).*#$(dirname "$f") \1#" +done) +ev() { printf '{"Action":"%s","Package":"github.com/Backblaze/blazer/%s","Test":"%s","Elapsed":0.5}\n' "$1" "$2" "$3"; } +while read -r dir name; do ev pass "$dir" "$name"; done <<<"$live" >"$tmp/pass.json" +echo '{"Action":"pass","Package":"github.com/Backblaze/blazer/b2","Elapsed":12.5}' >>"$tmp/pass.json" + +fail=0 +check() { # name, expected exit, expected log text, json file + : >"$tmp/summary.md" + set +e + out=$(GITHUB_STEP_SUMMARY="$tmp/summary.md" "$here/live-test-report.sh" "$4" 2>&1) + code=$? + set -e + if [ "$code" = "$2" ] && grep -qF -- "$3" <<<"$out"; then + echo "ok $1" + else + echo "FAIL $1: exit $code, want $2 with '$3'"; sed 's/^/ /' <<<"$out"; fail=1 + fi +} + +check "prints the summary to the log" 0 "Live integration tests" "$tmp/pass.json" +if grep -qF "Live integration tests" "$tmp/summary.md"; then echo "ok writes the summary file too"; else echo "FAIL summary file is empty"; fail=1; fi +check "prints the per-package result" 0 "PASS b2 (12.5s)" "$tmp/pass.json" + +cp "$tmp/pass.json" "$tmp/fail.json" +{ + printf '%s\n' '{"Action":"output","Package":"github.com/Backblaze/blazer/b2","Test":"TestAttrs","Output":" attrs_test.go:9: boom\n"}' + ev fail b2 TestAttrs +} >>"$tmp/fail.json" +check "prints the output of a failed test" 1 "attrs_test.go:9: boom" "$tmp/fail.json" +exit "$fail" From d2c4ace851aac08dacb24ba201f781211892b889 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gonzalo=20Pe=C3=B1a-Castellanos?= Date: Thu, 29 Oct 2026 18:22:46 -0500 Subject: [PATCH 2/6] ci: harden the live test log output --- .github/workflows/test-live.yml | 5 +++-- scripts/live-test-report.sh | 9 ++++++--- scripts/live-test-report_test.sh | 20 ++++++++++++++++++++ 3 files changed, 29 insertions(+), 5 deletions(-) diff --git a/.github/workflows/test-live.yml b/.github/workflows/test-live.yml index 4919eaac..ee32c244 100644 --- a/.github/workflows/test-live.yml +++ b/.github/workflows/test-live.yml @@ -72,8 +72,9 @@ jobs: B2_APPLICATION_KEY: ${{ secrets.B2_APPLICATION_KEY }} run: | set -o pipefail - go test -json -count=1 -timeout 30m ./b2/... ./base/... | tee test.json | jq -rj --unbuffered ' - if .Test == null and .Action == "output" then .Output + go test -json -count=1 -timeout 30m ./b2/... ./base/... | tee test.json | jq -Rrj --unbuffered ' + fromjson? | if .Action == "build-output" or (.Test == null and .Action == "output") then .Output + elif .Action == "build-fail" then "BUILD FAIL \(.ImportPath)\n" elif .Action == "pass" or .Action == "fail" or .Action == "skip" then select(.Test != null and (.Test | contains("/") | not)) | "\(.Action | ascii_upcase) \(.Package | sub(".*/blazer/"; "")) \(.Test) (\(.Elapsed // 0)s)\n" diff --git a/scripts/live-test-report.sh b/scripts/live-test-report.sh index 99540770..04f4de37 100755 --- a/scripts/live-test-report.sh +++ b/scripts/live-test-report.sh @@ -60,9 +60,12 @@ jq -r 'select(.Test == null and (.Action == "pass" or .Action == "fail" or .Acti if [ -n "$failed" ]; then echo "::group::Output of failed tests" - jq -rs '[.[] | select(.Action == "fail" and .Test != null) | {p: .Package, t: .Test}] as $f - | .[] | select(.Action == "output" and .Test != null and ([{p: .Package, t: .Test}] | inside($f))) - | .Output' "$in" | head -n 300 + out=$(mktemp) + jq -rjs '[.[] | select(.Action == "fail" and .Test != null) | "\(.Package) \(.Test)"] as $f + | .[] | select(.Action == "output" and .Test != null and ("\(.Package) \(.Test)" as $k | $f | index($k))) + | .Output' "$in" >"$out" + head -n 300 "$out" + rm -f "$out" echo "::endgroup::" fi diff --git a/scripts/live-test-report_test.sh b/scripts/live-test-report_test.sh index 7696e311..9bf749bd 100755 --- a/scripts/live-test-report_test.sh +++ b/scripts/live-test-report_test.sh @@ -41,4 +41,24 @@ cp "$tmp/pass.json" "$tmp/fail.json" ev fail b2 TestAttrs } >>"$tmp/fail.json" check "prints the output of a failed test" 1 "attrs_test.go:9: boom" "$tmp/fail.json" + +# A passing test whose name is a prefix of a failing one must not have its output printed. +cp "$tmp/fail.json" "$tmp/prefix.json" +{ + printf '%s\n' '{"Action":"output","Package":"github.com/Backblaze/blazer/b2","Test":"TestAttrsLong","Output":"PASSING-OUTPUT\n"}' + ev pass b2 TestAttrsLong +} >>"$tmp/prefix.json" +set +e +out=$(GITHUB_STEP_SUMMARY="$tmp/summary.md" "$here/live-test-report.sh" "$tmp/prefix.json" 2>&1) +set -e +if grep -qF PASSING-OUTPUT <<<"$out"; then echo "FAIL prints output of a passing test"; fail=1; else echo "ok prints only failed tests' output"; fi + +# More than 300 lines of output must still reach the closing group and the error line. +cp "$tmp/pass.json" "$tmp/long.json" +for i in $(seq 1 1000); do + printf '{"Action":"output","Package":"github.com/Backblaze/blazer/b2","Test":"TestAttrs","Output":"line %s\\n"}\n' "$i" +done >>"$tmp/long.json" +ev fail b2 TestAttrs >>"$tmp/long.json" +check "keeps the error line after long failure output" 1 "::error::Tests failed in the live run." "$tmp/long.json" + exit "$fail" From 8388b643a64d9547e9adc2fc93a19c8c7bc2c3c2 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gonzalo=20Pe=C3=B1a-Castellanos?= Date: Thu, 29 Oct 2026 18:23:44 -0500 Subject: [PATCH 3/6] test: make the long-output case fill the pipe --- scripts/live-test-report_test.sh | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/scripts/live-test-report_test.sh b/scripts/live-test-report_test.sh index 9bf749bd..98633c0a 100755 --- a/scripts/live-test-report_test.sh +++ b/scripts/live-test-report_test.sh @@ -55,9 +55,8 @@ if grep -qF PASSING-OUTPUT <<<"$out"; then echo "FAIL prints output of a passing # More than 300 lines of output must still reach the closing group and the error line. cp "$tmp/pass.json" "$tmp/long.json" -for i in $(seq 1 1000); do - printf '{"Action":"output","Package":"github.com/Backblaze/blazer/b2","Test":"TestAttrs","Output":"line %s\\n"}\n' "$i" -done >>"$tmp/long.json" +# Enough output to fill the pipe, so a `head` that exits early would SIGPIPE the writer. +awk 'BEGIN { pad = sprintf("%80s", ""); for (i = 1; i <= 5000; i++) printf "{\"Action\":\"output\",\"Package\":\"github.com/Backblaze/blazer/b2\",\"Test\":\"TestAttrs\",\"Output\":\"line %d%s\\n\"}\n", i, pad }' >>"$tmp/long.json" ev fail b2 TestAttrs >>"$tmp/long.json" check "keeps the error line after long failure output" 1 "::error::Tests failed in the live run." "$tmp/long.json" From 8c51636822c2694dd8714bc1d8070f7b3f0efd4a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gonzalo=20Pe=C3=B1a-Castellanos?= Date: Thu, 29 Oct 2026 18:30:52 -0500 Subject: [PATCH 4/6] ci: show timeout and panic output in the live test log --- scripts/live-test-report.sh | 15 ++++++++++++--- scripts/live-test-report_test.sh | 27 +++++++++++++++++++++++---- 2 files changed, 35 insertions(+), 7 deletions(-) diff --git a/scripts/live-test-report.sh b/scripts/live-test-report.sh index 04f4de37..0387cc54 100755 --- a/scripts/live-test-report.sh +++ b/scripts/live-test-report.sh @@ -58,11 +58,20 @@ fi jq -r 'select(.Test == null and (.Action == "pass" or .Action == "fail" or .Action == "skip")) | "\(.Action | ascii_upcase) \(.Package) (\(.Elapsed // 0)s)"' "$in" | sed "s#$module/##" -if [ -n "$failed" ]; then +# Output of failed tests, and of tests a panic or timeout cut off: Go attributes that stack trace to the +# running test but emits no failure event for it, only one for the package. +if [ -n "$failed" ] || [ -n "$failed_pkgs" ]; then echo "::group::Output of failed tests" out=$(mktemp) - jq -rjs '[.[] | select(.Action == "fail" and .Test != null) | "\(.Package) \(.Test)"] as $f - | .[] | select(.Action == "output" and .Test != null and ("\(.Package) \(.Test)" as $k | $f | index($k))) + jq -rjs ' + def key: "\(.Package) \(.Test)"; + [.[] | select(.Action == "fail" and .Test == null) | .Package] as $badpkgs + | [.[] | select(.Test != null and (.Action == "pass" or .Action == "fail" or .Action == "skip")) | key] as $done + | [.[] | select(.Action == "run" and (.Package as $p | $badpkgs | index($p) != null)) | key | select(. as $k | $done | index($k) == null)] as $cut + | [.[] | select(.Action == "fail" and .Test != null) | key] as $f + | .[] | select(.Action == "output" and ( + (.Test != null and ((key as $k | $f | index($k) != null) or (key as $k | $cut | index($k) != null))) + or (.Test == null and (.Package as $p | $badpkgs | index($p) != null)))) | .Output' "$in" >"$out" head -n 300 "$out" rm -f "$out" diff --git a/scripts/live-test-report_test.sh b/scripts/live-test-report_test.sh index 98633c0a..8094169f 100755 --- a/scripts/live-test-report_test.sh +++ b/scripts/live-test-report_test.sh @@ -43,15 +43,34 @@ cp "$tmp/pass.json" "$tmp/fail.json" check "prints the output of a failed test" 1 "attrs_test.go:9: boom" "$tmp/fail.json" # A passing test whose name is a prefix of a failing one must not have its output printed. -cp "$tmp/fail.json" "$tmp/prefix.json" +cp "$tmp/pass.json" "$tmp/prefix.json" { - printf '%s\n' '{"Action":"output","Package":"github.com/Backblaze/blazer/b2","Test":"TestAttrsLong","Output":"PASSING-OUTPUT\n"}' - ev pass b2 TestAttrsLong + printf '%s\n' '{"Action":"output","Package":"github.com/Backblaze/blazer/b2","Test":"TestAttrs","Output":"PASSING-OUTPUT\n"}' + printf '%s\n' '{"Action":"output","Package":"github.com/Backblaze/blazer/b2","Test":"TestAttrsLong","Output":"FAILING-OUTPUT\n"}' + ev fail b2 TestAttrsLong } >>"$tmp/prefix.json" set +e out=$(GITHUB_STEP_SUMMARY="$tmp/summary.md" "$here/live-test-report.sh" "$tmp/prefix.json" 2>&1) set -e -if grep -qF PASSING-OUTPUT <<<"$out"; then echo "FAIL prints output of a passing test"; fail=1; else echo "ok prints only failed tests' output"; fi +if grep -qF FAILING-OUTPUT <<<"$out" && ! grep -qF PASSING-OUTPUT <<<"$out"; then + echo "ok prints only failed tests' output" +else + echo "FAIL exact test-name matching"; sed 's/^/ /' <<<"$out"; fail=1 +fi + +# A timeout: Go attributes the stack trace to the running test and emits only a package failure. +cp "$tmp/pass.json" "$tmp/timeout.json" +{ + printf '%s\n' '{"Action":"run","Package":"github.com/Backblaze/blazer/b2","Test":"TestHangs"}' + printf '%s\n' '{"Action":"output","Package":"github.com/Backblaze/blazer/b2","Test":"TestHangs","Output":"panic: test timed out after 30m0s\n"}' + printf '%s\n' '{"Action":"output","Package":"github.com/Backblaze/blazer/b2","Test":"TestAttrs","Output":"UNRELATED-OUTPUT\n"}' + printf '%s\n' '{"Action":"fail","Package":"github.com/Backblaze/blazer/b2","Elapsed":1800}' +} >>"$tmp/timeout.json" +check "prints the timeout reason of a cut-off test" 1 "panic: test timed out after 30m0s" "$tmp/timeout.json" +set +e +out=$(GITHUB_STEP_SUMMARY="$tmp/summary.md" "$here/live-test-report.sh" "$tmp/timeout.json" 2>&1) +set -e +if grep -qF UNRELATED-OUTPUT <<<"$out"; then echo "FAIL prints output of a passing test in a failed package"; fail=1; else echo "ok skips finished tests in a failed package"; fi # More than 300 lines of output must still reach the closing group and the error line. cp "$tmp/pass.json" "$tmp/long.json" From a946c0c496b30effd2d6a16e690b02f0bbd68b52 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gonzalo=20Pe=C3=B1a-Castellanos?= Date: Fri, 30 Oct 2026 13:05:08 -0500 Subject: [PATCH 5/6] ci: keep both ends of long failed-test output --- scripts/live-test-report.sh | 10 +++++++++- scripts/live-test-report_test.sh | 16 ++++++++++++++++ 2 files changed, 25 insertions(+), 1 deletion(-) diff --git a/scripts/live-test-report.sh b/scripts/live-test-report.sh index 0387cc54..ca3b3357 100755 --- a/scripts/live-test-report.sh +++ b/scripts/live-test-report.sh @@ -73,7 +73,15 @@ if [ -n "$failed" ] || [ -n "$failed_pkgs" ]; then (.Test != null and ((key as $k | $f | index($k) != null) or (key as $k | $cut | index($k) != null))) or (.Test == null and (.Package as $p | $badpkgs | index($p) != null)))) | .Output' "$in" >"$out" - head -n 300 "$out" + # Keep both ends: a timeout puts its reason first, a t.Fatal puts the failure last. + total=$(wc -l <"$out") + if [ "$total" -le 300 ]; then + cat "$out" + else + head -n 100 "$out" + echo "... $((total - 300)) lines omitted ..." + tail -n 200 "$out" + fi rm -f "$out" echo "::endgroup::" fi diff --git a/scripts/live-test-report_test.sh b/scripts/live-test-report_test.sh index 8094169f..efc9ca9e 100755 --- a/scripts/live-test-report_test.sh +++ b/scripts/live-test-report_test.sh @@ -79,4 +79,20 @@ awk 'BEGIN { pad = sprintf("%80s", ""); for (i = 1; i <= 5000; i++) printf "{\"A ev fail b2 TestAttrs >>"$tmp/long.json" check "keeps the error line after long failure output" 1 "::error::Tests failed in the live run." "$tmp/long.json" + +# The failure message comes last, after the noise (David's case): 400 log lines, then the t.Fatal line. +cp "$tmp/pass.json" "$tmp/fatal.json" +awk 'BEGIN { for (i = 1; i <= 400; i++) printf "{\"Action\":\"output\",\"Package\":\"github.com/Backblaze/blazer/b2\",\"Test\":\"TestAttrs\",\"Output\":\" noise %d\\n\"}\n", i }' >>"$tmp/fatal.json" +printf '%s\n' '{"Action":"output","Package":"github.com/Backblaze/blazer/b2","Test":"TestAttrs","Output":" attrs_test.go:99: FATAL-MESSAGE\n"}' >>"$tmp/fatal.json" +ev fail b2 TestAttrs >>"$tmp/fatal.json" +check "keeps the last lines of long failure output" 1 "FATAL-MESSAGE" "$tmp/fatal.json" +check "says how many lines were omitted" 1 "lines omitted" "$tmp/fatal.json" + +# A timeout keeps its reason (first lines) even when the stack trace is long. +cp "$tmp/pass.json" "$tmp/longtimeout.json" +printf '%s\n' '{"Action":"run","Package":"github.com/Backblaze/blazer/b2","Test":"TestHangs"}' '{"Action":"output","Package":"github.com/Backblaze/blazer/b2","Test":"TestHangs","Output":"panic: test timed out after 30m0s\n"}' >>"$tmp/longtimeout.json" +awk 'BEGIN { for (i = 1; i <= 600; i++) printf "{\"Action\":\"output\",\"Package\":\"github.com/Backblaze/blazer/b2\",\"Test\":\"TestHangs\",\"Output\":\"goroutine %d [running]\\n\"}\n", i }' >>"$tmp/longtimeout.json" +printf '%s\n' '{"Action":"fail","Package":"github.com/Backblaze/blazer/b2","Elapsed":1800}' >>"$tmp/longtimeout.json" +check "keeps the timeout reason above a long stack trace" 1 "panic: test timed out after 30m0s" "$tmp/longtimeout.json" + exit "$fail" From 1e1279f03401f5dd5cf2e027cf8f87a068986fce Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gonzalo=20Pe=C3=B1a-Castellanos?= Date: Fri, 30 Oct 2026 13:21:27 -0500 Subject: [PATCH 6/6] ci: budget live test failure output per test --- .github/workflows/test-live.yml | 1 + scripts/live-test-report.sh | 33 ++++++++++++++++---------------- scripts/live-test-report_test.sh | 22 +++++++++++++++++++++ 3 files changed, 40 insertions(+), 16 deletions(-) diff --git a/.github/workflows/test-live.yml b/.github/workflows/test-live.yml index ee32c244..d3f76d34 100644 --- a/.github/workflows/test-live.yml +++ b/.github/workflows/test-live.yml @@ -74,6 +74,7 @@ jobs: set -o pipefail go test -json -count=1 -timeout 30m ./b2/... ./base/... | tee test.json | jq -Rrj --unbuffered ' fromjson? | if .Action == "build-output" or (.Test == null and .Action == "output") then .Output + elif .Action == "output" and (.Output | test("^panic: |test timed out|^fatal error: ")) then .Output elif .Action == "build-fail" then "BUILD FAIL \(.ImportPath)\n" elif .Action == "pass" or .Action == "fail" or .Action == "skip" then select(.Test != null and (.Test | contains("/") | not)) diff --git a/scripts/live-test-report.sh b/scripts/live-test-report.sh index ca3b3357..f4d28fe5 100755 --- a/scripts/live-test-report.sh +++ b/scripts/live-test-report.sh @@ -59,30 +59,31 @@ jq -r 'select(.Test == null and (.Action == "pass" or .Action == "fail" or .Acti | "\(.Action | ascii_upcase) \(.Package) (\(.Elapsed // 0)s)"' "$in" | sed "s#$module/##" # Output of failed tests, and of tests a panic or timeout cut off: Go attributes that stack trace to the -# running test but emits no failure event for it, only one for the package. +# running test but emits no failure event for it, only one for the package. Each test (and each failed +# package) gets its own budget so a noisy one cannot hide another's failure. Past 300 lines the first 100 +# and last 200 are kept, and panic, timeout and fatal lines are always kept. if [ -n "$failed" ] || [ -n "$failed_pkgs" ]; then echo "::group::Output of failed tests" - out=$(mktemp) - jq -rjs ' + jq -rs ' def key: "\(.Package) \(.Test)"; + def important: test("^panic: |test timed out|^fatal error: "); + def cap: if length <= 300 then . else + ([.[:100][], .[-200:][]]) as $kept + | ([.[] | select(important)] | .[:20] - $kept) as $key + | .[:100] + ["... \(length - 300) lines omitted ..."] + (if ($key | length) > 0 then ["... key lines from the omitted part ..."] + $key + ["..."] else [] end) + .[-200:] + end; [.[] | select(.Action == "fail" and .Test == null) | .Package] as $badpkgs | [.[] | select(.Test != null and (.Action == "pass" or .Action == "fail" or .Action == "skip")) | key] as $done | [.[] | select(.Action == "run" and (.Package as $p | $badpkgs | index($p) != null)) | key | select(. as $k | $done | index($k) == null)] as $cut | [.[] | select(.Action == "fail" and .Test != null) | key] as $f - | .[] | select(.Action == "output" and ( + | [.[] | select(.Action == "output" and ( (.Test != null and ((key as $k | $f | index($k) != null) or (key as $k | $cut | index($k) != null))) - or (.Test == null and (.Package as $p | $badpkgs | index($p) != null)))) - | .Output' "$in" >"$out" - # Keep both ends: a timeout puts its reason first, a t.Fatal puts the failure last. - total=$(wc -l <"$out") - if [ "$total" -le 300 ]; then - cat "$out" - else - head -n 100 "$out" - echo "... $((total - 300)) lines omitted ..." - tail -n 200 "$out" - fi - rm -f "$out" + or (.Test == null and (.Package as $p | $badpkgs | index($p) != null))))] + | group_by(if .Test != null then key else .Package end) + | .[] + | "=== \(.[0] | if .Test != null then key else .Package end)", + ((map(.Output) | join("") | split("\n") | if length > 0 and .[-1] == "" then .[:-1] else . end | cap)[]) + ' "$in" echo "::endgroup::" fi diff --git a/scripts/live-test-report_test.sh b/scripts/live-test-report_test.sh index efc9ca9e..2297da69 100755 --- a/scripts/live-test-report_test.sh +++ b/scripts/live-test-report_test.sh @@ -95,4 +95,26 @@ awk 'BEGIN { for (i = 1; i <= 600; i++) printf "{\"Action\":\"output\",\"Package printf '%s\n' '{"Action":"fail","Package":"github.com/Backblaze/blazer/b2","Elapsed":1800}' >>"$tmp/longtimeout.json" check "keeps the timeout reason above a long stack trace" 1 "panic: test timed out after 30m0s" "$tmp/longtimeout.json" + +# The timeout reason sits after 150 lines of progress output and before a 600-line stack trace. +cp "$tmp/pass.json" "$tmp/latepanic.json" +printf '%s\n' '{"Action":"run","Package":"github.com/Backblaze/blazer/b2","Test":"TestHangs"}' >>"$tmp/latepanic.json" +awk 'BEGIN { for (i = 1; i <= 150; i++) printf "{\"Action\":\"output\",\"Package\":\"github.com/Backblaze/blazer/b2\",\"Test\":\"TestHangs\",\"Output\":\"progress %d\\n\"}\n", i }' >>"$tmp/latepanic.json" +printf '%s\n' '{"Action":"output","Package":"github.com/Backblaze/blazer/b2","Test":"TestHangs","Output":"panic: test timed out after 30m0s\n"}' >>"$tmp/latepanic.json" +awk 'BEGIN { for (i = 1; i <= 600; i++) printf "{\"Action\":\"output\",\"Package\":\"github.com/Backblaze/blazer/b2\",\"Test\":\"TestHangs\",\"Output\":\"goroutine %d [running]\\n\"}\n", i }' >>"$tmp/latepanic.json" +printf '%s\n' '{"Action":"fail","Package":"github.com/Backblaze/blazer/b2","Elapsed":1800}' >>"$tmp/latepanic.json" +check "keeps a timeout reason that follows 150 progress lines" 1 "panic: test timed out after 30m0s" "$tmp/latepanic.json" + +# Three failing tests: the quiet one sits between two noisy ones and must not lose its message. +cp "$tmp/pass.json" "$tmp/two.json" +noisy() { # test, count: that many noise lines, then the failure message and the fail event + awk -v t="$1" -v n="$2" 'BEGIN { for (i = 1; i <= n; i++) printf "{\"Action\":\"output\",\"Package\":\"github.com/Backblaze/blazer/b2\",\"Test\":\"%s\",\"Output\":\"noise %d\\n\"}\n", t, i }' + printf '{"Action":"output","Package":"github.com/Backblaze/blazer/b2","Test":"%s","Output":" x_test.go:1: FATAL-%s\\n"}\n' "$1" "$1" + ev fail b2 "$1" +} +{ noisy TestA 400; noisy TestB 0; noisy TestC 500; } >>"$tmp/two.json" +check "keeps the failure of the first of three failing tests" 1 "FATAL-TestA" "$tmp/two.json" +check "keeps the failure of the quiet test between two noisy ones" 1 "FATAL-TestB" "$tmp/two.json" +check "keeps the failure of the last of three failing tests" 1 "FATAL-TestC" "$tmp/two.json" + exit "$fail"