diff --git a/cmd/codeaf-census/demandedlanes_test.go b/cmd/codeaf-census/demandedlanes_test.go new file mode 100644 index 0000000000..1ec707943a --- /dev/null +++ b/cmd/codeaf-census/demandedlanes_test.go @@ -0,0 +1,39 @@ +package main + +import ( + "bytes" + "strings" + "testing" +) + +// TestServedInsideTheDemandedSetIsNotAskedNotServed is #969's second acceptance: +// once a row carries the set the chooser demanded (`lanes`), served being a +// DIFFERENT member of that set is the router choosing inside the choice we made, +// not routing around it - so it is not counted as "asked for is not the machine +// that served". Only served landing OUTSIDE the set is. +func TestServedInsideTheDemandedSetIsNotAskedNotServed(t *testing.T) { + log := writeLines(t, + // Served tinder, demanded {cinnabar, tinder}: inside the set, agreement + // even though served != lane. + `{"ts":"2026-09-08T10:00:00.000Z","id":"1","model":"m/one","served":"tinder","lane":"cinnabar","lanes":["cinnabar","tinder"],"status":200,"ms":500}`, + // Served tinder, ranked cinnabar, no set: the pre-#937 shape, a real + // asked != served. + `{"ts":"2026-09-08T10:00:01.000Z","id":"2","model":"m/one","served":"tinder","lane":"cinnabar","status":200,"ms":500}`, + // Served ember, demanded {cinnabar, tinder}: outside the set, a real + // asked != served. + `{"ts":"2026-09-08T10:00:02.000Z","id":"3","model":"m/one","served":"ember","lane":"cinnabar","lanes":["cinnabar","tinder"],"status":200,"ms":500}`, + ) + rows, err := readLog(log) + if err != nil { + t.Fatal(err) + } + var out bytes.Buffer + report(&out, log, rows, defaults()) + got := out.String() + + // Three rows are attributed; the one served inside its set is agreement, the + // two served outside their admitted machines are not. + if !strings.Contains(got, "| the machine asked for is not the machine that served | 2 | 3 |") { + t.Errorf("served-inside-the-set was counted as asked != served:\n%s", got) + } +} diff --git a/cmd/codeaf-census/report.go b/cmd/codeaf-census/report.go index 5b11907ce1..db2cd4ec0d 100644 --- a/cmd/codeaf-census/report.go +++ b/cmd/codeaf-census/report.go @@ -521,7 +521,12 @@ func surprises(out io.Writer, rows, finishes []row) { } if r.Served != "" && r.Lane != "" { attributed++ - if !strings.EqualFold(r.Served, r.Lane) { + // A SET THE CHOOSER ADMITTED IS NOT A SINGLE RANKED NAME. When the + // row carries the demanded set, served being INSIDE it is the router + // picking a member of the choice we made, not routing around it - so + // only served landing OUTSIDE the set (or outside the lone name, on + // a row with no set) counts as asked != served (calllog's Lanes). + if !servedWasAdmitted(r) { disagreed++ } } @@ -649,6 +654,25 @@ func firstNonEmpty(values ...string) string { return "" } +// servedWasAdmitted reports whether the machine that served was one the request +// would have accepted. On a row that carries the demanded set ([calllog.Record]'s +// Lanes) that means served is a MEMBER of the set, because the chooser told the +// router it may serve any of them; on a row with no set it means served matches +// the single ranked name in Lane, which is the only machine such a row named. +// Both comparisons are case-insensitive, as the rest of this file reads machine +// names. +func servedWasAdmitted(r row) bool { + if len(r.Lanes) > 0 { + for _, lane := range r.Lanes { + if strings.EqualFold(r.Served, lane) { + return true + } + } + return false + } + return strings.EqualFold(r.Served, r.Lane) +} + // cell makes one string safe to sit in a markdown table: a pipe inside a cell // would end the column, and a signature full of router prose is exactly where // one turns up. diff --git a/docs/changes/unreleased/1796-demanded-lanes-on-the-row.md b/docs/changes/unreleased/1796-demanded-lanes-on-the-row.md new file mode 100644 index 0000000000..a5e8796b83 --- /dev/null +++ b/docs/changes/unreleased/1796-demanded-lanes-on-the-row.md @@ -0,0 +1,14 @@ +--- +kind: fixed +title: the call row carries the demanded set, so served ≠ asked means what it says again +pr: 1796 +surface: [] +invalidates: + - "The call log's `Record.Lane` named ONE machine - the ranked head of the request's preference. Since the chooser was taught to demand the whole admitted set (`provider.only` with `allow_fallbacks: false`), the router may serve any member of that set, so a row where `served != lane` could no longer tell `the router chose a different member of the set we admitted` from `the router went somewhere we never named`, and the census family built on it (asked ≠ served) silently changed what it measured. The row now also carries `Record.Lanes`, the whole demanded set, filled from `laneChoice.Only` while the demand is still being sent and present only when the set has two or more members (a one-machine demand is left to `Lane` alone, which is also every pre-set-demand row). The census counts asked ≠ served only when served fell OUTSIDE the admitted set." +--- + +Raised out of #937's review as the owed follow-up: the measurement was ruled +honest and sufficient, and this is the field it named. Scoped to the log and the +census; widening `cmd/*-replay`'s `Policy.Demand` to return the set is the second +half, worth doing only now the log can say whether the served machine was inside +one. diff --git a/internal/calllog/calllog.go b/internal/calllog/calllog.go index 8efe015e0a..ac213d98bb 100644 --- a/internal/calllog/calllog.go +++ b/internal/calllog/calllog.go @@ -252,6 +252,22 @@ type Record struct { // Empty for a call to an endpoint that is not a router, and for one sent // with no preference at all. Lane string `json:"lane,omitempty"` + // Lanes is the SET the request demanded, when it demanded more than one. + // Since the chooser was taught to admit the whole set it believed in + // (`provider.only` with `allow_fallbacks` off over every machine that + // survived the gate), the router is free to pick any member of it, so + // [Lane] above - the ranked head of that set - is no longer the only + // machine the request would accept. Served matching [Lane] exactly stopped + // being the question; served being INSIDE this set is, and a reader with + // only the head cannot tell "the router chose another machine we admitted" + // from "the router went somewhere we never named". + // + // Empty when the request demanded nothing (it ranked machines and the + // router was free to leave the set) or demanded exactly one - the single + // case [Lane] alone already answers - which is also the state of every row + // written before the set-demanding chooser existed. The members are the + // endpoint names in the order the choice ranked them, [Lane] first. + Lanes []string `json:"lanes,omitempty"` // Hedged marks the row of a call that was rescued by a second request to // another lane. Both halves of the pair leave their own rows; this is what // says they were a pair. diff --git a/internal/provider/calllog.go b/internal/provider/calllog.go index a63a654fcc..2c400353c1 100644 --- a/internal/provider/calllog.go +++ b/internal/provider/calllog.go @@ -449,6 +449,7 @@ func (c *Client) record(facts recordFacts) { // the row of the request it rescued says what happened to that one. if wait, watched := streamWatchFrom(facts.ctx).facts(); watched { record.Lane = recordedLane(body, wait.lane) + record.Lanes = demandedLanes(body) record.HazardCeilingMs = wait.deadline.Milliseconds() // WHAT WAS PLANNED AND WHAT HAPPENED ARE TWO FIELDS, AND THE ROW MAY // CARRY BOTH. The ceiling above is when the watch was going to start @@ -687,6 +688,37 @@ func soleDemandedLane(knobs callKnobs) string { return "" } +// demandedLanes is the SET this attempt's body demanded, and "" (an absent +// field) when it demanded nothing or demanded exactly one. It is the whole of +// `laneChoice.Only` - every machine the chooser admitted and told the router it +// may not leave - and it is read under the same discipline as [soleDemandedLane]: +// only when the demand is still being SENT ([callKnobs.carriesTheDemand]), never +// off knobs the widen has already relaxed, so the row cannot claim a set a +// retired pin's bare retry no longer carries. +// +// A single-machine demand is left to [Lane] alone, which already answers it; a +// hedge demands its one arm and is the same single case. This field exists for +// the one thing [Lane] cannot say - that served being a DIFFERENT member of the +// set was the router choosing inside the choice, not routing around it. +func demandedLanes(knobs callKnobs) []string { + if !knobs.carriesTheDemand() { + return nil + } + if knobs.laneChoice == nil || len(knobs.laneChoice.Only) < 2 { + return nil + } + lanes := make([]string, 0, len(knobs.laneChoice.Only)) + for _, name := range knobs.laneChoice.Only { + if name = strings.TrimSpace(name); name != "" { + lanes = append(lanes, name) + } + } + if len(lanes) < 2 { + return nil + } + return lanes +} + // recordedLane is the machine THIS ATTEMPT'S preference asked for: the head of // the order it sent, or the one machine it demanded. // diff --git a/internal/provider/demandedlanes_test.go b/internal/provider/demandedlanes_test.go new file mode 100644 index 0000000000..552218a01c --- /dev/null +++ b/internal/provider/demandedlanes_test.go @@ -0,0 +1,62 @@ +package provider + +import ( + "context" + "testing" + + "github.com/Agent-Field/codeaf/internal/calllog" + lanes "github.com/Agent-Field/codeaf/internal/lane" +) + +// TestADemandedSetLeavesEveryAdmittedMachineOnTheRow is #969's first acceptance: +// a call that demands a SET (every machine the chooser admitted, `provider.only` +// with fallbacks off) writes a row that carries the whole set in `lanes` and the +// ranked head in `lane`. Without the set, `served != lane` cannot tell "the +// router chose another machine we admitted" from "the router went somewhere we +// never named". +func TestADemandedSetLeavesEveryAdmittedMachineOnTheRow(t *testing.T) { + read := loggingTo(t) + client, _, _ := pacedPair(t) + + if _, err := client.CompleteWithMessages(context.Background(), userMessages("hello")); err != nil { + t.Fatal(err) + } + calllog.Close() + + finishes := ended(read()) + if len(finishes) != 1 { + t.Fatalf("one call should leave one finished row; got %d: %+v", len(finishes), finishes) + } + row := finishes[0] + if len(row.Lanes) != 2 || !hasName(row.Lanes, "cinnabar") || !hasName(row.Lanes, "tinder") { + t.Fatalf("lanes = %v, want both admitted machines on the row: %+v", row.Lanes, row) + } + if row.Lane != row.Lanes[0] { + t.Fatalf("lane = %q, want the ranked head of the demanded set %v", row.Lane, row.Lanes) + } + if row.Served == "" || !hasName(row.Lanes, row.Served) { + t.Fatalf("served = %q is not inside the admitted set %v", row.Served, row.Lanes) + } +} + +// TestASingleMachineDemandLeavesNoSetOnTheRow is the emptiness side: a demand of +// exactly one machine is the case `lane` alone already answers, so no `lanes` +// field is written - which is also the state of every row from before the +// set-demanding chooser existed. +func TestASingleMachineDemandLeavesNoSetOnTheRow(t *testing.T) { + if got := demandedLanes(callKnobs{laneChoice: &lanes.Choice{Only: []string{"cinnabar"}}}); got != nil { + t.Fatalf("a one-machine demand wrote lanes = %v, want nothing", got) + } + if got := demandedLanes(callKnobs{}); got != nil { + t.Fatalf("a call that demanded nothing wrote lanes = %v, want nothing", got) + } +} + +func hasName(names []string, want string) bool { + for _, name := range names { + if name == want { + return true + } + } + return false +}