fix(analyze): divide per-hour rates by time actually worked

A host asleep mid-run tested nothing, and charging that sleep to an arm reports
it slower for a reason unrelated to the arm. The legend also claimed wall clock
while the number was monotonic. Campaigns written before the split are still
read through the old field name so their run hours do not silently zero.

Claude-Session: https://claude.ai/code/session_01A5KmftdEJ49A9z5mF5ESrX
This commit is contained in:
pj committed 2026-08-14 17:43:12 +05:30
1 parent c63a2e4897
commit eacf3fd11f
4 files changed
+67 -13

No files matched your search

+1 -1
View File
@@ -150,7 +150,7 @@ func summarize(current arm) armSummary {
// steps whose action was never dispatched. Only dispatched actions // steps whose action was never dispatched. Only dispatched actions
// exercised the app, so only they belong in a per-action rate. // exercised the app, so only they belong in a per-action rate.
summary.TotalActions += item.Actions summary.TotalActions += item.Actions
summary.TotalRunHours += float64(item.DurationMillis) / float64(time.Hour/time.Millisecond) summary.TotalRunHours += float64(item.MonotonicMillis) / float64(time.Hour/time.Millisecond)
if item.ClampedToBudget { if item.ClampedToBudget {
summary.EventsHeldAtBudget++ summary.EventsHeldAtBudget++
} }
+43 -5
View File
@@ -2,6 +2,7 @@ package main
import ( import (
"math" "math"
"path/filepath"
"testing" "testing"
"time" "time"
) )
@@ -11,7 +12,7 @@ func violatingRun(seed int64, steps, origin int, properties ...string) classifie
Seed: seed, Seed: seed,
Steps: steps, Steps: steps,
Actions: steps, Actions: steps,
DurationMillis: 60_000, MonotonicMillis: 60_000,
OriginStep: origin, OriginStep: origin,
Violated: true, Violated: true,
ViolatedProperties: properties, ViolatedProperties: properties,
@@ -19,7 +20,7 @@ func violatingRun(seed int64, steps, origin int, properties ...string) classifie
} }
func cleanRun(seed int64, steps int) classifiedRun { func cleanRun(seed int64, steps int) classifiedRun {
return classifiedRun{Seed: seed, Steps: steps, Actions: steps, DurationMillis: 60_000} return classifiedRun{Seed: seed, Steps: steps, Actions: steps, MonotonicMillis: 60_000}
} }
func TestSummarize_ArmWhereNoRunViolated(t *testing.T) { func TestSummarize_ArmWhereNoRunViolated(t *testing.T) {
@@ -85,9 +86,9 @@ func TestSummarize_CountsDispatchedActionsNotSteps(t *testing.T) {
Name: "declines", Name: "declines",
Budget: 40, Budget: 40,
Runs: []classifiedRun{ Runs: []classifiedRun{
{Seed: 1, Steps: 40, Actions: 10, DurationMillis: 3_600_000, {Seed: 1, Steps: 40, Actions: 10, MonotonicMillis: 3_600_000,
Violated: true, OriginStep: 12, ViolatedProperties: []string{"cartTotal"}}, Violated: true, OriginStep: 12, ViolatedProperties: []string{"cartTotal"}},
{Seed: 2, Steps: 40, Actions: 6, DurationMillis: 3_600_000}, {Seed: 2, Steps: 40, Actions: 6, MonotonicMillis: 3_600_000},
}, },
}) })
if summary.TotalSteps != 80 { if summary.TotalSteps != 80 {
@@ -110,7 +111,7 @@ func TestSummarize_ArmThatDispatchedNothingHasNoPerActionRate(t *testing.T) {
Name: "inert", Name: "inert",
Budget: 20, Budget: 20,
Runs: []classifiedRun{ Runs: []classifiedRun{
{Seed: 1, Steps: 20, Actions: 0, DurationMillis: 3_600_000, {Seed: 1, Steps: 20, Actions: 0, MonotonicMillis: 3_600_000,
Violated: true, OriginStep: 3, ViolatedProperties: []string{"cartTotal"}}, Violated: true, OriginStep: 3, ViolatedProperties: []string{"cartTotal"}},
}, },
}) })
@@ -125,6 +126,43 @@ func TestSummarize_ArmThatDispatchedNothingHasNoPerActionRate(t *testing.T) {
} }
} }
func runHoursFor(t *testing.T, record map[string]any) float64 {
t.Helper()
directory := filepath.Join(t.TempDir(), "campaign")
record["seed"] = 1
writeCampaign(t, directory,
map[string]any{"arm": "seeded", "max_steps": 50, "seeds": []int{1}},
[]map[string]any{record})
arms, err := groupArms([]string{directory})
if err != nil {
t.Fatal(err)
}
return summarize(arms[0]).TotalRunHours
}
// A host asleep mid-run advanced the wall clock while testing nothing, so the
// sleep has no place in the denominator of a per-hour rate.
func TestSummarize_RunHoursCountTheTimeWorkedNotTheTimeThatPassed(t *testing.T) {
hours := runHoursFor(t, map[string]any{
"exit_code": 0, "steps": 50, "actions": 50,
"monotonic_millis": 3_600_000, "wall_clock_millis": 5_400_000,
})
if hours != 1 {
t.Errorf("run hours %v, want the 1 hour worked rather than the 1.5 hours that passed", hours)
}
}
// Campaigns recorded before the two clocks were split gave the same monotonic
// reading the name duration_millis, and their hours still have to count.
func TestSummarize_RunHoursReadCampaignsWrittenBeforeTheClocksWereSplit(t *testing.T) {
hours := runHoursFor(t, map[string]any{
"exit_code": 0, "steps": 50, "actions": 50, "duration_millis": 3_600_000,
})
if hours != 1 {
t.Errorf("run hours %v, want 1 from the older duration_millis field", hours)
}
}
func TestSummarize_ArmWithNoUsableRunsAfterExclusions(t *testing.T) { func TestSummarize_ArmWithNoUsableRunsAfterExclusions(t *testing.T) {
summary := summarize(arm{ summary := summarize(arm{
Name: "broken", Name: "broken",
+21 -6
View File
@@ -30,10 +30,18 @@ type manifest struct {
// runRecord mirrors the fields analyze reads from one line of runs.jsonl. // runRecord mirrors the fields analyze reads from one line of runs.jsonl.
type runRecord struct { type runRecord struct {
Seed int64 `json:"seed"` Seed int64 `json:"seed"`
ExitCode int `json:"exit_code"` ExitCode int `json:"exit_code"`
LaunchError string `json:"launch_error"` LaunchError string `json:"launch_error"`
TimedOut bool `json:"timed_out"` TimedOut bool `json:"timed_out"`
// MonotonicMillis is how long the run worked, and it is what every
// per-hour rate here divides by: a host asleep mid-run tested nothing, so
// charging that time to the arm would report it as slower for a reason
// that has nothing to do with the arm. The wall clock the campaign also
// records answers the other question, how much time passed.
MonotonicMillis int64 `json:"monotonic_millis"`
// DurationMillis is the name campaigns written before the two clocks were
// split gave the same monotonic reading, so those files still read.
DurationMillis int64 `json:"duration_millis"` DurationMillis int64 `json:"duration_millis"`
TraceError string `json:"trace_error"` TraceError string `json:"trace_error"`
Steps int `json:"steps"` Steps int `json:"steps"`
@@ -61,7 +69,7 @@ type classifiedRun struct {
Seed int64 Seed int64
Steps int Steps int
Actions int Actions int
DurationMillis int64 MonotonicMillis int64
OriginStep int OriginStep int
Violated bool Violated bool
ClampedToBudget bool ClampedToBudget bool
@@ -130,13 +138,20 @@ func loadCampaign(directory string) (manifest, []runRecord, error) {
return declared, records, nil return declared, records, nil
} }
func (r runRecord) workingMillis() int64 {
if r.MonotonicMillis != 0 {
return r.MonotonicMillis
}
return r.DurationMillis
}
// classify turns one record into the run the analysis works with, deciding // classify turns one record into the run the analysis works with, deciding
// whether it is usable and, if it is, whether it is an event or censored. // whether it is usable and, if it is, whether it is an event or censored.
func classify(record runRecord, budget int) classifiedRun { func classify(record runRecord, budget int) classifiedRun {
item := classifiedRun{ item := classifiedRun{
Seed: record.Seed, Seed: record.Seed,
Steps: record.Steps, Steps: record.Steps,
DurationMillis: record.DurationMillis, MonotonicMillis: record.workingMillis(),
ViolatedProperties: slices.Clone(record.ViolatedProperties), ViolatedProperties: slices.Clone(record.ViolatedProperties),
} }
if record.Actions != nil { if record.Actions != nil {
+2 -1
View File
@@ -31,7 +31,8 @@ func writeReport(result analysis, out io.Writer) {
}) })
fmt.Fprintln(out) fmt.Fprintln(out)
fmt.Fprintln(out, "a detection is one distinct property violated in one run; run hours sum the per-run wall clock") fmt.Fprintln(out, "a detection is one distinct property violated in one run; run hours sum the time the runs worked,")
fmt.Fprintln(out, "on the monotonic clock, so a host that slept mid-run is not charged for the sleep")
fmt.Fprintln(out, "actions count the steps that dispatched one; the rest chose nothing or had the choice thrown away") fmt.Fprintln(out, "actions count the steps that dispatched one; the rest chose nothing or had the choice thrown away")
writeTable(out, []string{"arm", "steps", "actions", "run hours", "detections", "defects/1k actions", "defects/hour", "distinct defects", "found in one run"}, writeTable(out, []string{"arm", "steps", "actions", "run hours", "detections", "defects/1k actions", "defects/hour", "distinct defects", "found in one run"},
func(add func(...string)) { func(add func(...string)) {