Skip to content

ci: print live test results to the job log - #242

Merged
goanpeca merged 6 commits into
mainfrom
fix-live-test-log-output
Oct 30, 2026
Merged

goanpeca merged 6 commits into
mainfrom
fix-live-test-log-output

Conversation

@goanpeca

@goanpeca goanpeca commented Oct 29, 2026 •

Copy link
Copy Markdown
Contributor

Motivation

The live test job log showed nothing about what ran. go test -json ... > test.json sent all test output to a file, and the report step wrote its table only to the run's Summary page. In run 40964119112 the log had a 3m26s gap and no test names, counts or failures. You had to open the Summary tab or download the artifact to see that 37 of 37 live tests passed.

Changes

  • test-live.yml: go test -json now runs as go test -json ... | tee test.json | jq ... under set -o pipefail. The log streams one line per top-level test (PASS pkg Test (time)), plus package-level output, build errors and panics. test.json is still written in full and uploaded; the jq side skips non-JSON lines so it cannot cut the artifact short.
  • scripts/live-test-report.sh: prints the summary table to the log as well as the Summary page, then per-package results with timings, then the output of failed tests in a collapsible group (each failing test and failed package gets its own 300-line budget, so a noisy test cannot hide another's failure; past 300 lines the first 100 and last 200 are kept with an omitted-lines marker, and panic:, test timed out and fatal error: lines from the omitted part are always kept; matched by exact package and test name). The live stream in the workflow also prints those panic and timeout lines as they happen. A panic or timeout is covered too: Go attributes the stack trace to the running test but emits only a package failure, so the group also prints output of tests that started and never finished in a failed package, plus that package's own output.
  • scripts/live-test-report_test.sh (picked up by make scripts-test): summary in the log and the summary file, per-package line, failed-test output, a failing TestAttrsLong printing while a passing TestAttrs (prefix name) does not, a timeout fixture whose stack trace is attributed to a cut-off test, finished tests in a failed package not being printed, and a long failure output (5,000 lines) still reaching the ::error:: lines, the t.Fatal message surviving 400 lines of noise, a timeout reason surviving a 600-line stack trace and 150 lines of progress output before it, and three failing tests where the quiet one sits between two noisy ones keeping its message.

Testing

make ci passes (including scripts-test); actionlint and shellcheck are clean. I ran the new jq filter and the report script on the real live-test-json artifact from run 40964119112: the report prints 37 of 37 live tests and PASS b2 (199.314s), PASS base (15.224s), PASS b2/sync (2.577s).

I also reproduced a real go test -timeout 1s hang and ran its JSON through the report: it prints panic: test timed out after 1s. Each fix reverted makes a test fail: the old report script (no log output), matching by substring (prints a passing test's output), reporting only tests with a failure event (the timeout case), and piping straight into head (exit 141 instead of 1 once output exceeds the pipe buffer).

NOT RUN: the workflow on GitHub. It needs the live-tests environment secrets, so the first real check is the next live run on main or a manual workflow_dispatch; the log should then list each test.

Risk

CI logging only; no library code or wire behavior changes. The log gets longer: one line per top-level live test (a few hundred). No new secret exposure: the added output is test names, timings and test output, and the B2 keys are not printed by either script. A test that itself logged a credential would now show in the job log.

How to revert

Reverting the commits is enough.

Self-review

An independent subagent reviewed the diff and found 4 issues, all fixed in d2c4ace and the follow-up test commit. (1) jq | head -n 300 under set -euo pipefail exited 141 and skipped the ::error:: lines on long output; now written to a temp file first. (2) The failed-test filter matched by substring, so a passing TestAttrs printed when TestAttrsLong failed; now exact match. (3) Failed-test output was double-spaced; now jq -j. (4) The workflow filter dropped build-output and build-fail events and would abort on a non-JSON line, truncating test.json; now handled with fromjson?. Copilot and Codex then raised two more, both fixed in the latest commit: a timeout or panic left no explanation in the log (Go emits no failure event for the cut-off test, so its output was dropped), and the prefix-name fixture had the failing and passing tests reversed, so a substring matcher would still have passed. Not run: /code-review and /security-review as skills; the reviewer was a general-purpose subagent that did not write the code.

Checklist

  • make ci passes locally.
  • A fresh-context review (/code-review, /security-review or a subagent) ran on the diff; findings are fixed or answered below.
  • No library change; labelled skip-changelog.

Review from David: head -n 300 dropped the t.Fatal message when a test logged more than 300 lines first. Fixed by keeping the first 100 and last 200 lines with an omitted-lines marker, not tail alone, which would cut a timeout's panic: test timed out line (it comes first, followed by a long stack). Reproduced first with a failing test, then confirmed on a real go test run that logs 400 lines and then calls t.Fatal: the failure message is now printed. Reverting to head or to tail alone each fails a test.

Review from Copilot on the head-plus-tail fix: with 150 progress lines before panic: test timed out and 600 stack lines after it, the truncation dropped the reason, and one shared budget let a noisy test hide another test's t.Fatal. Both reproduced first with failing fixtures, then fixed with a per-test budget and always-kept panic and timeout lines; reverting either fails a test. Re-checked on real go test runs (a 1 s timeout, and 400 log lines then t.Fatal).

@goanpeca goanpeca added this to the 0.10.0 milestone Oct 29, 2026
@goanpeca goanpeca added ci Continuous integration and workflow changes skip-changelog No changelog entry needed; skips the changelog check labels Oct 29, 2026
Copilot AI balanced review requested due to automatic review settings October 29, 2026 23:23
@goanpeca goanpeca self-assigned this Oct 29, 2026

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Changes recommended

Panic and timeout diagnostics can be lost for interrupted tests, and the prefix-regression fixture does not verify exact test-name matching.

2 open issues
What changed in this PR

2 Important, 0 Nit, 0 Pre-existing.

This PR makes live B2 test results visible in GitHub Actions job logs while preserving the JSON artifact and Summary-page report.

Changes:

  • Streams top-level test results and selected diagnostic output.
  • Prints summary counts, package timings, and capped failed-test output.
  • Adds shell regression tests for report logging and failure handling.

Checked the supplied diff and relevant script context against the stated logging behavior. No tests or live workflow runs were executed during this review. A human code owner must review the workflow changes.

File Description
scripts/​live-test-report.sh Prints summaries, package timings, and failed-test output to the log.
scripts/​live-test-report_test.sh Adds fixtures for log output, exact-name matching, and long failures.
.github/​workflows/​test-live.yml Streams readable test events while retaining the full JSON artifact.

Review effort: Balanced

Comment thread .github/workflows/test-live.yml Resolved
Comment thread scripts/live-test-report_test.sh Resolved
Copilot AI balanced review requested due to automatic review settings October 29, 2026 23:30

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟢 Approval recommended

No active review issues are recorded, although no commands or live tests were run and the workflow changes still require human code-owner review.

No open issues 🎉

2 resolved since last review

Review effort: Balanced

@david-santacruz-backblaze david-santacruz-backblaze left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

One thing on the failed-test output, see inline.

Comment thread scripts/live-test-report.sh Outdated
(.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"

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

head -n 300 keeps the start of the output, but the t.Fatal message usually comes last. I tried a failing test that logs 400 lines first, and the actual failure never made it into the log. Maybe tail -n 300 instead?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks! will take a look 🚀

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good catch, reproduced: with 400 lines of noise before the t.Fatal, head -n 300 dropped the failure message. Fixed in the latest commit. I did not switch to tail alone, because a timeout puts its reason (panic: test timed out) first, followed by a long stack, and tail would cut it. The report now keeps the first 100 and last 200 lines with an omitted-lines marker. Tests cover both cases and fail if reverted to head or to tail. I checked it on a real go test run with 400 log lines and a t.Fatal: the failure message is printed. Leaving the thread open for you to resolve.

Copilot AI balanced review requested due to automatic review settings October 30, 2026 18:05

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Changes recommended

The report’s truncation and shared output budget can hide timeout reasons and other tests’ fatal messages, leaving important failure diagnostics unavailable.

1 open issue

Review effort: Balanced

Comment thread scripts/live-test-report.sh Resolved
Copilot AI balanced review requested due to automatic review settings October 30, 2026 18:21

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟢 Approval recommended

No active review issues are reported, though verification commands were not run and workflow changes still require human code-owner review.

No open issues 🎉

1 resolved since last review

Review effort: Balanced

@goanpeca
goanpeca merged commit 1e5b888 into main Oct 30, 2026
25 of 26 checks passed
@goanpeca
goanpeca deleted the fix-live-test-log-output branch October 30, 2026 20:37

@david-santacruz-backblaze david-santacruz-backblaze left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hey, give a quick look at these please before merging. All suggestions, no hard violations.

  1. cap in scripts/live-test-report.sh can drop key lines the description says are always kept. It takes the first 20 panic: / test timed out / fatal error: matches and then subtracts the kept head and tail, so early matches inside the kept lines can crowd out later ones in the omitted middle. Subtracting first and then taking 20 would avoid that. A fixture with 30 early panic: lines and a test timed out line in the omitted middle would pin it.
  2. The failed-output group never prints build-output events, so a build failure shows only FAIL … [build failed]. The live stream does print them. Consider adding them to the group, or note in the description that it's intentional.
  3. The inline jq filter in .github/workflows/test-live.yml (fromjson?, build-output, build-fail) has no test. One fixture through the same filter would cover it.
  4. The panic regex lives in both test-live.yml and live-test-report.sh. Defining it once, or a comment in each place pointing to the other, would keep them in sync.
  5. The omitted-lines count (length - 300) ignores the re-added key lines, so it slightly overstates what was dropped.
  6. In scripts/live-test-report_test.sh, "(David's case)" could describe the scenario instead. The repeated awk generator and the hardcoded github.com/Backblaze/blazer/b2 could move into helpers (ev() already takes a package), and a check_absent would cover the three set +e blocks.
  7. In cap, $key holds important lines and shadows def key, so a rename would help.

Verified: bash scripts/live-test-report_test.sh passes 15/15. The workflow run on GitHub is still NOT RUN.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

ci Continuous integration and workflow changes skip-changelog No changelog entry needed; skips the changelog check

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants