Milestone 5: the tail is published, and the throughput curve has an end

[skyoo2003]

Pull Request

Summary

This project had never measured a latency distribution. Every published figure was a
mean over a sequential replay — 50 queries, one at a time — and a mean is exactly the
statistic a tail is invisible in. grep 'func Benchmark' returned nothing.

This is milestone 5. It brings an instrument (internal/loadgen, weft-eval bench),
a comparison quarantined in its own module (bench/), and the measurement design
written down before the numbers so the judgment rules could not be chosen after
them (docs/PERF.md).

Both clauses of the PRD's outcome sentence hold. weft's p99 at the registered load
point is 108.193 ms, of which stop-the-world accounts for 411 µs — 0.38%. bleve
v2.6.0 on the same machine, corpus, query set, arm and load generator is 57.525 ms,
so weft is 1.88× it against an order-of-magnitude bar.

Two things are not buried.

The plan's prediction was wrong twice, and the correction generalises. It predicted
the tail would be a working-set problem rather than a GC problem, against the PRD's own
risk row saying the opposite. Below saturation it is neither: STW is 0.062% of a rung,
GC CPU share 1.1%, and majflt is 0 across the whole warm ladder. The arithmetic error
is worth repeating because it is easy to repeat — milestone 3a's published
74,504-byte live heap was measured at rest, and during a query 30,549 candidates
are alive at once, so the GOGC target sits at 46–53 MiB rather than on its 4 MiB floor.
A heap figure measured at rest does not predict a collector under load.

And the ladder found something no pass line asked for: weft cannot sustain its own
sequential throughput, and bleve can. At 27.28/s — exactly the rate its sequential
replay achieved — weft does not slow down, it collapses: p50 39.2 ms → 1.27 s, 1,438
of 10,000 requests shed, RSS 126 → 853 MiB. bleve at the corresponding rung of its own
ladder posts its best p99 of the sweep, sheds nothing, and sits at 59.3 MiB. bleve has a
knee too — p99 turns up to 83.468 ms at 314/s — but it sheds nothing and its RSS moves
8 MiB: a queue forming, not a memory collapse. The mechanism is live heap under
concurrency, which is Index.Doc decoding a whole record per candidate — the same
decode milestone 3b costed as a 1.4× tax on the working set, reappearing as the thing
that ends the throughput curve.

No engine code changed. pkg/fusion and pkg/scorer are both 0 lines.

Changes

• internal/loadgen — an open-loop driver. Request i is due at
  start + i/rate whatever request i−1 is doing, and latency is measured from that
  due time. A closed loop lets a stalled server receive less load, so the stall appears
  as one slow request and the p99 that comes out is a p99 of a load the server chose.
  Exceeding the in-flight cap sheds and counts rather than blocking, because
  blocking would restore that bias at the load where it matters most.
• Quantiles by nearest rank, absent when thin. An interpolated quantile is a
  latency no request experienced. A quantile needs 100 samples beyond it — p99 needs
  10,000, p99.9 needs 100,000 — or it is left out rather than printed with a caveat.
• GC accounting, second design. The first classified samples as GC-hit or GC-free
  by the cycle counter; a smoke run produced 200 hits out of 200, because at 485
  collections over 200 queries every request overlaps one. Replaced by charging
  stop-the-world time per sample, with GC CPU share printed beside it for the mark
  assist that is not stop-the-world and would otherwise go unaccounted.
• weft-eval bench — the ladder, plus page faults and context switches from
  getrusage, which is what separates a query waiting on a disk from one waiting on a
  core.
• weft-eval bench -writes — what a commit costs the reads beside it, which is the
  question milestone 3b §4.3 left open. It copies the index first: a Commit
  against .eval-data/index would rewrite the corpus every published number names.
• bench/, a separate module — bleve v2.6.0 and its ~20 transitive modules live
  there, so go list -m all at the root still prints one line and
  TestNoExternalDependencies still passes. Both harnesses share internal/loadgen
  through a replace directive: a comparison measured by two implementations of an
  open loop is not a comparison.
• Five instrument defects, found by review and fixed before the published run.
  GCPause was charged over a shorter window than the Lat it is subtracted from —
  64% of the p99 elapsed before accounting began. -writes stamped its commit window
  after the Add loop, filing the writer's own lock contention under the baseline it
  is compared against. The unloaded median was 50 samples where the package's own rule
  wants 200, and it is the denominator of every arrival rate. GCPauseTotal allocated
  per call, producing ~150 MiB of garbage per ladder that the report then charged to
  the query. GC CPU share was a ratio of process-since-start totals rather than of
  per-rung differences. Every one biased toward a flattering number and none was
  visible in the output; four ladders were discarded across the milestone. FINDINGS
  §4.1 tabulates before and after.
• docs/PERF.md — the measurement design and both judgment rules, written before
  the numbers. It also registers what a favourable number would not mean.
• docs/DECISIONS.md D-009, FINDINGS milestone 5, docs/testing/weft-m5.tdd.md,
  changie entries. (.claude/ is gitignored, so the PRD's milestone row, performance
  metric and GC risk row are updated locally and are not part of this diff.)
• CI — make bench-build. go build ./... does not descend into a nested module,
  so 427 lines carrying half of clause 2 had no gate at all. Neither bench target is
  in all or in CI: a shared runner's tail is a function of its neighbours.

Validation

• go test -race ./... — all packages ok

• golangci-lint run ./... — 0 issues

• make deps — github.com/skyoo2003/weft, one line, after bleve entered bench/

• make arch — fusion sees no scorer, both API goldens unmoved

• make spdx, make changelog-check, gofmt -l . — clean

• (cd bench && go build ./... && go vet ./...), GOOS=windows go build ./...

• git diff --stat main -- pkg/ — empty

• Measured on Apple M4 / 16 GiB / macOS 26.5.2 / Go 1.26.1 / GOMAXPROCS 10, against the
  171,332-document evaluation index and the 50 judged TREC-COVID queries at k=10:

  rate (weft)	3.41/s	6.82/s	13.64/s	27.28/s	54.56/s
  p50	83.371 ms	51.515 ms	39.187 ms	1.2688 s	1.8816 s
  p99	108.193 ms	78.605 ms	64.709 ms	—	—
  shed	0	0	0	1,438	6,272
  peak RSS	120.7 MiB	123.2 MiB	126.3 MiB	853.0 MiB	921.7 MiB

  rate (bleve)	19.64/s	39.28/s	78.56/s	157.13/s	314.25/s
  p50	15.401 ms	11.745 ms	8.350 ms	7.797 ms	8.208 ms
  p99	57.525 ms	35.390 ms	25.597 ms	25.370 ms	83.468 ms
  shed	0	0	0	0	0

• Write lock: lock held 11.063 s, of which the commit itself was 11.014 s and the
  20,000 Add calls 49 ms; worst read due inside the window 12.539 s, p50 outside
  83.401 ms. Published index verified intact afterwards.

Review Focus

• internal/loadgen.Drive is where a measurement bias would hide. The open-loop
  schedule, the shed-rather-than-block path, and Sample.Due are what every number in
  this PR rests on.
• The clock around the driver. Five defects in it were found by review and none by
  test, because a latency distribution looks equally plausible whether or not the
  instrument measuring it is honest. GCPauseTotal's reused buffer, the window
  GCPause is read over, and where -writes stamps its window are the three worth a
  second pair of eyes — and it is not obvious what test would have caught any of them,
  which is recorded as a gap rather than resolved.
• benchWrites takes no do from its caller — deliberately. The ladder's closure
  is bound to the published index, and the arm must build its own against the copy;
  reads and the commit have to contend for one lock or the number means nothing.
• bench/go.mod's replace. If bench is ever moved under pkg/ or cmd/, weft
  acquires ~20 external modules and a stated success metric becomes false. make deps
  is the mechanical check.

Risks / Notes

• The saturation rule fires at rung 1 for both engines and that is a flaw in the
  rule, reported rather than fixed. p50 falls as load rises on both — a sparse open
  loop lets the machine cool between requests, a tight sequential loop does not — so
  the "unloaded" denominator is optimistic and the headline lands on the slowest rung.
  The rule was registered before the numbers, so it stands as it fired. What would fix
  it (an open-loop rung as the denominator) is named in FINDINGS §3.1 and left to
  whoever owns the rule. It is conservative for weft either way: its best measured p99
  is 64.709 ms, not the 108.193 ms quoted, and at the two engines’ best rungs the ratio is
  2.55× — worse than the headline’s 1.88×, so the rule is not flattering weft either.
• One repetition of the corrected instrument, where docs/PERF.md requires the median
  of three. 108.193 ms is a
  single observation whose run-to-run spread is unknown, so the 1.88× ratio has unknown
  error bars. It clears a 10× bar widely enough that no plausible spread reaches it,
  which is why the verdict stands and the caveat is recorded anyway — FINDINGS §4.5.
• text+vector has no published tail. The deployable arm is 4× slower per query, so
  10,000 samples at 12.5% of its throughput is over five hours. The published p99 is
  for the arm bleve can be compared against, not the arm a user would run.
• The comparison is not analyzer-matched. bleve's standard analyzer stems and
  drops stop words; engine.Tokenize does neither. The effects run in opposite
  directions and neither is worth 10×, which is all rule 2 asks — docs/PERF.md §4.
• The hybrid arm is not compared at all. bleve's kNN needs a build tag and cgo
  faiss; taking that on changes the subject from "a Go search engine" to "a Go wrapper
  around faiss" — D-009.
• A 20 MB bench/bench binary was committed and removed in this branch. It is
  gitignored now but remains in this branch's history; a rewrite is the only way out and
  is not worth one here.
• A rung is silent for 51 minutes. bench prints nothing between the header and the
  end of a rung, which reads as a hung process and is not. A progress line would fix it
  and was deliberately not written between two measurements.
• Follow-up, unscheduled: nothing bounds a commit's lock window. Two shapes are
  visible — train the partition outside the write lock (both argmax passes touch no
  shared state), or give Commit a context. FINDINGS milestone 5 §5.