From 6fde490e70d0d2c1b53e17fba484cffdf7ff736d Mon Sep 17 00:00:00 2001 From: Manuel de Brito Fontes Date: Mon, 26 Oct 2026 16:06:58 -0300 Subject: [PATCH] proven: tests carries what a lane measured, beside the job that measured it A release's evidence said which tests passed and how long each took; a figure a reader can compare - how long a boot, a snapshot, a resume takes - was nowhere, and a test's duration measures the test. A measuring test logs `measure =`, the unit in the name, and proven tests reads every such line off the jobs' logs into the record as measures, each with the workflow, run, job and runner labels, so the website shows a number with the machine it was measured on. Co-Authored-By: Claude Fable 5.1 --- cmd/proven/main.go | 22 ++++++++++++++++++++-- cmd/proven/main_test.go | 13 ++++++++----- internal/proven/tests.go | 22 ++++++++++++++++++++++ internal/proven/tests_test.go | 15 +++++++++++++++ site/src/content/docs/proven.md | 5 ++++- 5 files changed, 69 insertions(+), 8 deletions(-) diff --git a/cmd/proven/main.go b/cmd/proven/main.go index b205380..91f3a3d 100644 --- a/cmd/proven/main.go +++ b/cmd/proven/main.go @@ -132,6 +132,9 @@ type evidence struct { Commit string `json:"commit"` Runs []evidenceRun `json:"runs"` Tests []evidenceOf `json:"tests"` + // Measures is every number the jobs' tests logged for the record (proven.Measures): what + // a lane timed, on the machine the job names. + Measures []evidenceMeasure `json:"measures"` } // evidenceRun is one run that answers for the commit: the gate's, found by the commit's tree, @@ -148,6 +151,17 @@ type evidenceRun struct { // evidenceOf is one test's answer in one job. type evidenceOf struct { proven.Test + evidenceJob +} + +// evidenceMeasure is one number a job's test logged, with the job that ran it. +type evidenceMeasure struct { + proven.Measure + evidenceJob +} + +// evidenceJob is where an answer or a measurement was logged. +type evidenceJob struct { Workflow string `json:"workflow"` Run int64 `json:"run"` Job string `json:"job"` @@ -185,7 +199,7 @@ func tests(ctx context.Context, gh proven.GitHub, trees proven.Trees, sha, workf } } } - e := evidence{Commit: sha, Runs: answering, Tests: []evidenceOf{}} + e := evidence{Commit: sha, Runs: answering, Tests: []evidenceOf{}, Measures: []evidenceMeasure{}} for _, r := range answering { jobs, err := gh.Jobs(ctx, r.ID) if err != nil { @@ -199,8 +213,12 @@ func tests(ctx context.Context, gh proven.GitHub, trees proven.Trees, sha, workf if err != nil { return fmt.Errorf("job %d of run %d: %w", j.ID, r.ID, err) } + where := evidenceJob{Workflow: r.Workflow, Run: r.ID, Job: j.Name, JobURL: j.URL, Runner: j.Labels} for _, test := range proven.Tests(log) { - e.Tests = append(e.Tests, evidenceOf{Test: test, Workflow: r.Workflow, Run: r.ID, Job: j.Name, JobURL: j.URL, Runner: j.Labels}) + e.Tests = append(e.Tests, evidenceOf{Test: test, evidenceJob: where}) + } + for _, m := range proven.Measures(log) { + e.Measures = append(e.Measures, evidenceMeasure{Measure: m, evidenceJob: where}) } } } diff --git a/cmd/proven/main_test.go b/cmd/proven/main_test.go index 91ffc2e..2e27365 100644 --- a/cmd/proven/main_test.go +++ b/cmd/proven/main_test.go @@ -105,7 +105,7 @@ func setup(t *testing.T) *fixture { case "/repos/o/r/actions/runs/3/jobs": _, _ = w.Write([]byte(`{"jobs": [{"id": 31, "name": "e2e-verify:1/1"}]}`)) case "/repos/o/r/actions/jobs/42/logs": - _, _ = w.Write([]byte("--- PASS: TestA (1.50s)\n")) + _, _ = w.Write([]byte(" measure_test.go:40: measure boot_to_running_ms=12345\n--- PASS: TestA (1.50s)\n")) case "/repos/o/r/actions/jobs/31/logs": _, _ = w.Write([]byte("--- PASS: TestA (1.40s)\n--- FAIL: TestB (2s)\n")) default: @@ -301,6 +301,7 @@ func TestTestsAreWhatTheAnsweringRunsLogged(t *testing.T) { require.NoError(t, err) var got evidence require.NoError(t, json.Unmarshal(raw, &got)) + fleet := evidenceJob{Workflow: "ci.yml", Run: 4, Job: "e2e-verify:1/1", JobURL: "j42", Runner: []string{"runs-on/fleet=kvm"}} assert.Equal(t, evidence{ Commit: f.main[1], Runs: []evidenceRun{ @@ -308,10 +309,12 @@ func TestTestsAreWhatTheAnsweringRunsLogged(t *testing.T) { {Workflow: "kvm.yml", ID: 30, URL: "u30", Conclusion: "failure", Head: f.main[1]}, }, Tests: []evidenceOf{ - {Test: proven.Test{Name: "TestA", Passed: true, Seconds: 1.5}, Workflow: "ci.yml", Run: 4, Job: "e2e-verify:1/1", JobURL: "j42", Runner: []string{"runs-on/fleet=kvm"}}, - {Test: proven.Test{Name: "TestA", Passed: true, Seconds: 1.4}, Workflow: "kvm.yml", Run: 30, Job: "e2e-verify:1/1"}, - {Test: proven.Test{Name: "TestB", Passed: false, Seconds: 2}, Workflow: "kvm.yml", Run: 30, Job: "e2e-verify:1/1"}, + {Test: proven.Test{Name: "TestA", Passed: true, Seconds: 1.5}, evidenceJob: fleet}, + {Test: proven.Test{Name: "TestA", Passed: true, Seconds: 1.4}, evidenceJob: evidenceJob{Workflow: "kvm.yml", Run: 30, Job: "e2e-verify:1/1"}}, + {Test: proven.Test{Name: "TestB", Passed: false, Seconds: 2}, evidenceJob: evidenceJob{Workflow: "kvm.yml", Run: 30, Job: "e2e-verify:1/1"}}, }, + // What job 42's test timed, beside the machine it ran on. + Measures: []evidenceMeasure{{Measure: proven.Measure{Name: "boot_to_running_ms", Value: 12345}, evidenceJob: fleet}}, }, got) assert.Contains(t, f.asked, "/repos/o/r/actions/jobs/41/logs", "a job whose log is gone is asked, and says nothing") @@ -320,7 +323,7 @@ func TestTestsAreWhatTheAnsweringRunsLogged(t *testing.T) { f.kvm = nil said = stdout(t, func() { err = run(t.Context(), []string{"tests", "-sha", f.main[0]}) }) require.NoError(t, err) - want, err := json.MarshalIndent(evidence{Commit: f.main[0], Runs: []evidenceRun{{Workflow: "ci.yml", ID: 6, URL: "u6", Conclusion: "failure", Head: f.main[0]}}, Tests: []evidenceOf{}}, "", " ") + want, err := json.MarshalIndent(evidence{Commit: f.main[0], Runs: []evidenceRun{{Workflow: "ci.yml", ID: 6, URL: "u6", Conclusion: "failure", Head: f.main[0]}}, Tests: []evidenceOf{}, Measures: []evidenceMeasure{}}, "", " ") require.NoError(t, err) assert.Equal(t, "1 runs answer for "+f.main[0]+": 0 tests logged\n"+string(want)+"\n", said) } diff --git a/internal/proven/tests.go b/internal/proven/tests.go index 968757d..0a0fe2e 100644 --- a/internal/proven/tests.go +++ b/internal/proven/tests.go @@ -30,6 +30,28 @@ var pwTest = regexp.MustCompile(`([✓✘])\s+\d+\s+(?:\[[^\]]+\] › )?([^\s› // lastTitle is the test's own title: what follows the last › of the titles. var lastTitle = regexp.MustCompile(`^(?:.* › )?(.+)$`) +// Measure is one number a test logged for the record: "measure =", the unit in the +// name (boot_to_running_ms), as a lane's measuring test prints what it timed on the machine it +// ran on. +type Measure struct { + Name string `json:"name"` + Value float64 `json:"value"` +} + +// measured is the line a test logs for a measurement; what the log puts before it - go test's +// file and line, a timestamp - is let through. +var measured = regexp.MustCompile(`\bmeasure ([a-z][a-z0-9_]*)=(-?[0-9]+(?:\.[0-9]+)?)\b`) + +// Measures is every measurement a log holds, in the order they were logged. +func Measures(log string) []Measure { + var out []Measure + for _, m := range measured.FindAllStringSubmatch(log, -1) { // mutate-exempt: any n < 0 is every match + v, _ := strconv.ParseFloat(m[2], 64) // mutate-exempt: any bit size but 32 is 64; the expression matched a number + out = append(out, Measure{Name: m[1], Value: v}) + } + return out +} + // Tests is every test a log says ended, in the order they did, each with whether it passed and // how long it took. A test run again on a retry is there once per answer. func Tests(log string) []Test { diff --git a/internal/proven/tests_test.go b/internal/proven/tests_test.go index 7910c66..24084c8 100644 --- a/internal/proven/tests_test.go +++ b/internal/proven/tests_test.go @@ -29,3 +29,18 @@ func TestEveryTestALogSaysEnded(t *testing.T) { }, Tests(log)) assert.Empty(t, Tests("nothing ended here\n")) } + +// A measurement is a "measure =" line, however the log prefixes it; a name with a +// capital or a value with letters is not one. +func TestEveryMeasurementALogHolds(t *testing.T) { + log := "2026-10-26T13:00:01.0000000Z measure_test.go:40: measure boot_to_running_ms=12345\n" + + "=== RUN TestX\n" + + " measure_test.go:52: measure diff_etc_ms=0.5 measure snapshot_disk_ms=-1\n" + + "not a measure Boot_ms=3 nor measure disk=fast\n" + assert.Equal(t, []Measure{ + {Name: "boot_to_running_ms", Value: 12345}, + {Name: "diff_etc_ms", Value: 0.5}, + {Name: "snapshot_disk_ms", Value: -1}, + }, Measures(log)) + assert.Empty(t, Measures("--- PASS: TestA (1.50s)\n")) +} diff --git a/site/src/content/docs/proven.md b/site/src/content/docs/proven.md index 8596063..d6460ca 100644 --- a/site/src/content/docs/proven.md +++ b/site/src/content/docs/proven.md @@ -106,7 +106,10 @@ the commit's tree, as `tree` finds it, and the newest finished run of `-also` on `release` reads it. `runs` is those runs - workflow, id, URL, conclusion and the commit each was of - and `tests` is each test's answer in each job: `name` (a Go test's, or a Playwright test's own title under its describe, with its `spec`), `passed`, `seconds`, and the `workflow`, `run`, -`job` and `jobUrl` that ran it, with the labels the job asked of its `runner`. A job whose log +`job` and `jobUrl` that ran it, with the labels the job asked of its `runner`. `measures` is +every number a test logged for the record - a line `measure =`, the unit in the +name, as a lane's measuring test prints what it timed - each with the same job and runner, so a +figure is read beside the machine it was measured on. A job whose log the API no longer holds says nothing. The record is what a release publishes beside its files, for a reader with no access to the repository: which test ran, where, and what it answered - `-out` names the file, and without it the document is stdout.