Skip to content

AC-019 was met all along: fix the measurement, drop the runner - #5

Merged
pashagolub merged 12 commits into
mainfrom
fix/ac-019-scaling-measurement
Sep 2, 2026
Merged

AC-019 was met all along: fix the measurement, drop the runner#5
pashagolub merged 12 commits into
mainfrom
fix/ac-019-scaling-measurement

Conversation

@pashagolub

Copy link
Copy Markdown
Contributor

Closes #3.

ParallelScan already met AC-019. It had never been measured.

Pinned clocks, idle machine, GOMAXPROCS=8, 30 interleaved reps:

32 MiB : 1w 111.7ms -> 8w 16.35ms   6.83x median, 6.82x best   7.91 of 8 CPUs busy
128 MiB: 1w 451.5ms -> 8w 65.32ms   6.91x median, 6.88x best   7.95 of 8 CPUs busy

Under the same conditions, main scores 6.38× and this branch 6.35×. The code contributes nothing to the ratio. The move from the reported 3.69–4.33× to 6.8× was the measurement, start to finish.

What #3 got wrong

The issue argued that three machines agreeing on ~4× — including a 16-core Threadripper with eight cores idle — proved the ceiling was in the code rather than in any test machine. They agreed because they shared a measurement, not a bottleneck:

  • TestParallelScanScales took one testing.Benchmark sample per side, in sequence, and divided them. The same binary and benchmark produced 3.27× to 5.72× depending only on GOGC, GOMAXPROCS, and whether the two sides ran in one process or two.
  • Boost clocks favour the 1-worker side. One active core boosts, eight do not. That deflates a scaling ratio in a way indistinguishable from poor scaling.
  • The Threadripper ran a periodic heavy job. Interference only makes runs slower, so it widened the spread without moving the floor — the 8-worker figure swung 4.06–7.41 ms in one session.

Both recorded causes are withdrawn. Not memory bandwidth: growing the working set makes scaling better. Not a fixed per-call cost either — a CPU profile at 8 workers puts 91.5% of samples in Parser.Next, with no GC, lock, allocator or scheduler frame above 2%, and gctrace shows the collector at ~2.5% of wall against a flat 4 MB heap goal. There was nothing there to fix.

The measurement

TestParallelScanScales now interleaves the two sides A/B/A/B, discards warmups, repeats (default 10, PGLOGWATCH_BENCH_REPS), and reports median/min/max. It also reports how many CPUs were actually busy, via runtime/metrics — because "4× at 8 workers" has two different causes, idle cores and slow cores, and the old harness could not tell them apart.

It asserts only when PGLOGWATCH_BENCH=1 marks a deliberate benchmark and the measurement supports one: GOMAXPROCS equals the worker count, and median and best agree. Asserting unconditionally was tried and failed on a dev machine at 5.79× with boost on — red for everybody is ignored by everybody.

The runtime accumulates /cpu/classes/* only at GC termination, so a window that collects nothing shows no change — precisely the 1-worker side. It forces a collection outside the timed region; the bias is documented.

Kept anyway, worth ~2%

  • planShards no longer clamps parts to --jobs. It made the shape of the work depend on the worker count: eight 4 MiB files became 8 shards at --jobs 1 and 64 at --jobs 8. main's 6.38× is the right answer from the wrong measurement; this branch compares 32 shards against 32. Irrelevant to a threshold met by a wide margin, and the whole point for PERF-030.
  • Workers draw from a shared cursor instead of a fixed share. Achieved parallelism 7.0 → 7.9 of 8.
  • Config.LinePrefix compiled once, up front. It was compiled per worker by New, which sets the error before assigning the template — and scanShard's Reset cleared it, so an unparseable prefix was silently replaced by auto-detection. A serial Parser refused the same Config and read nothing; ParallelScan read the whole file and returned nil.

One thing tried and reverted: one slab for all worker buffers. Tidier, and 1.8× slower in one configuration — a page lands on the NUMA node that first touches it, and the read buffer is the hottest memory in the scan.

The dedicated runner is gone

bench/RUNNER.md deleted. SVC-002 removed; INF-002/INF-003/TST-008/TST-014 amended to "measure on a named machine and say which". PERF-030 and AC-020 become a pre-release benchstat comparison rather than a CI gate — a 5% threshold on shared capacity measures variance, and a job that reports noise as a regression gets ignored. The allocation half still runs on every push, because 0 allocs/op is exact rather than statistical.

bench/pinned-run.sh replaces it: fixes the governor and boost, measures, restores on any exit including Ctrl-C. Safe on a machine other people use.

VAL-004 is not removed. It requires the comparative table to be published honestly including the workloads where no comparison was possible — that is the anti-cherry-picking rule. bench/MACHINE.md had glossed it as "no figure from an unpinned machine may be published", which appears nowhere in the spec; that gloss is gone.

Note on overlap

Commit b576571 (the csvlog record loss) is also #4, sent separately against main for a patch release. If #4 merges first, git will drop the duplicate on rebase.

Verification

  • go vet and go test -race clean across all modules
  • Parallel test inputs enlarged first and deliberately: at 90 KB–1 MB they now fall inside a single shard and would pass while covering no boundary at all
  • TestParallelScanUsesEveryWorker rewritten — with a work queue, "every worker got a record" is a scheduling accident, not a contract

🤖 Generated with Claude Code

pashagolub and others added 12 commits September 2, 2026 15:20
TestParallelScanScales took one testing.Benchmark sample per side, in
sequence, and divided them. That is not a measurement. The same binary and
the same benchmark produce between 3.27x and 5.72x depending only on GOGC,
GOMAXPROCS and whether the two sides ran in one process or two, so a ratio of
two single samples cannot tell a ceiling in the code from thermal state -- and
the three-machine table that issue #3's central argument rests on was produced
that way.

The measurement now interleaves the two sides, discards two warmup reps,
repeats ten times, and reports median, min and max. It also reports how many
CPUs were actually BUSY, which is the distinction the old harness could not
make: "4x at 8 workers" has two entirely different causes -- cores that sat
idle, and cores that ran slower or did more work than they do alone -- and the
remedy is different for each.

On the development laptop (8c/16t, windows/amd64) the new output already
separates them:

  32 MiB : 4.33x, parallelism 7.02  -> 0.62 throughput per busy CPU
  128 MiB: 5.78x, parallelism 7.68  -> 0.75 throughput per busy CPU

The cores are busy, not idle. So the shortfall is work that does not become
throughput, which is what planShards clamping shards to the worker count and
the per-worker buffer allocation both produce -- and it is why the larger
working set, which amortises a fixed per-call cost, scales better.

Two working-set sizes are measured for that reason. It asserts only on the
reference machine AND at the GOMAXPROCS the requirement is stated for, rather
than reporting a number that looks like AC-019 and is not.

The CPU counters need a forced collection to be readable at all: the runtime
accumulates /cpu/classes/* at the end of a GC cycle, not continuously, so a
window that collects nothing shows no change -- which is precisely the
1-worker side, since it makes an eighth of the garbage.

bench/scaling-baseline.sh is the confounder sweep around it: machine facts,
governor and boost state, the ladder in one process, a GOGC x GOMAXPROCS
matrix, a taskset run pinned to eight distinct physical cores, and achieved
parallelism from a profile. It is what to run on the benchmark machine before
attributing anything to the code.

Also drops the memory-bandwidth explanation from the doc comment, which
bench/THRESHOLDS.md and COMPLIANCE.md already retract.

No change to ParallelScan itself.

Refs: #3
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The script was committed with CRLF endings and does not run on Linux: bash
reads the carriage return as part of the command and stops at the first line
with "$'\r': command not found". I introduced it by patching the file through
a text-mode write on Windows.

The rest of the tree is LF, apart from the two csvlog fixtures that carry CRLF
on purpose (COR-006, E10) and are protected by the existing testdata rule. So
this is one file, not a convention -- but a shell script is the one place
where the ending is executable rather than cosmetic, and it costs a round trip
to the benchmark machine to find out. The .gitattributes rule pins *.sh so a
checkout or an editor cannot reintroduce it.

Also: TestParallelScanScales now says so when NumCPU exceeds GOMAXPROCS. The
first Linux run measured a serial-side spread of 90.9ms to 204.2ms -- better
than two to one -- with 8 workers roaming over 32 CPUs. A thread that migrates
across dies arrives with none of its cache, and that spread is wide enough to
swamp the effect being measured, so the log now names taskset as the remedy.

And "laptop" is wrong for the development machine, which is a mini PC.

Refs: #3
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Three changes to ParallelScan, none of which alters what it produces.

planShards no longer takes a worker count. It clamped parts per source to
--jobs, so the same eight 4 MiB files became 8 shards for --jobs 1 and 64 for
--jobs 8: the parallel side paid eight times the per-shard prologue and the
ratio between the two sides was not a measure of parallelism at all. Shards
are now sized from the input at targetShardBytes, so both sides divide a
corpus identically. Dropping the parameter is what makes that checkable at
compile time.

256 KiB, not a megabyte, because the binding constraint is the tail rather
than the prologue: wg.Wait means wall time is the slowest worker, so one shard
is the smallest imbalance a plan can have. At 256 KiB an 8-worker run of the
AC-019 corpus gets sixteen shards each and a tail under a tenth of the work.

Workers now draw shards from a shared cursor instead of being dealt a fixed
share round-robin. Shards are near-equal in bytes by construction, but equal
bytes are not equal time -- a shard dense in continuation lines costs more per
byte than one of short records -- and the tail is bounded by one shard rather
than by the worst accumulation over a worker's whole share. Measured, achieved
parallelism at 8 workers rises from 7.0 to 7.9 of 8 CPUs.

The workers' read buffers come from one allocation instead of one apiece, and
the log_line_prefix is compiled once and shared. Building them inside the
goroutines meant N concurrent large-object allocations at the same instant of
every call. 184 allocations per call at 8 workers becomes 121; the BYTES are
unchanged, which is the part still open.

Compiling the prefix up front also fixes a silent failure. New reports an
unparseable LinePrefix through Err, but sets it before assigning p.prefix, and
scanShard's Reset cleared err and done -- so every worker started with no
prefix and quietly auto-detected one. A serial Parser refused the Config and
read nothing; ParallelScan read the whole file and returned nil.

The parallel tests are enlarged first and deliberately: their inputs were 90 KB
to 1 MB and would now fall inside a single shard, passing while covering none
of the boundary behaviour they were written for. TestParallelScanUsesEveryWorker
is rewritten -- with a queue, "every worker got a record" is a scheduling
accident, not a contract.

Measured at 8 workers, GOMAXPROCS=8: 3.25ms to 3.04ms per call, ratio 3.51x to
3.74x. The larger prize is the per-call buffer bytes, which this does not
touch.

Refs: #3
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The previous commit allocated all the workers' read buffers as one slab on the
parent goroutine, to turn N concurrent large-object allocations into one. That
is the tidier shape and it is slower where it matters.

A page lands on the NUMA node that first touches it. One slab is touched by
whichever goroutine allocated it, so every worker's read buffer -- the hottest
memory in the scan -- ends up on a single node, and half the workers read it
across the interconnect. Allocating inside each worker gives first-touch
locality instead.

Measured on the Threadripper 2950X, 2 NUMA nodes, 8 workers, GOGC=off: the
slab ran at 6.52ms per call against 3.62ms for the per-worker allocation it
replaced. With the collector on, the difference was hidden -- recycled spans
have arbitrary locality either way -- which is why the first measurement of
this change looked like an improvement.

The prefix compilation stays on the parent. That was never about allocation:
it is what makes an unparseable LinePrefix an error from ParallelScan rather
than something every worker silently swallows.

So the allocation COUNT goes back up and the bytes are unchanged. Neither was
the cost. gctrace on the same machine shows 170 collections in 3.98s at about
0.5ms each, roughly 2.5% of wall, against a flat 4 MB heap goal -- the
collector was never what GOGC=off was switching off.

Refs: #3
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
bench/MACHINE.md requires the performance governor and no boost before any
PERF-0xx figure may be quoted, and bench/RUNNER.md gives the two commands. Both
assume a dedicated machine. The one available is shared, so leaving it pinned
is not an option and running unpinned makes the AC-019 ratio unquotable.

This narrows the window instead. It saves the governor of every CPU and the
boost flag, builds the test binary BEFORE touching anything so compilation does
not run on a pinned box, pins, measures, and restores. The restore is a trap on
EXIT INT TERM HUP, so it also runs on Ctrl-C, on a failed build and on kill,
and it is guarded so it cannot run twice. sudo is taken once up front, because
a password prompt appearing halfway through would block the restore behind
somebody who had walked away.

Both settings are volatile and nothing is written to disk, so the worst case is
already a reboot -- but on a shared machine a reboot is not available either,
which is the whole reason for the trap.

Refs: #3
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
AC-019 moved from 3.82x to 6.83x across a stretch in which the code changed,
the governor was pinned and a neighbouring workload was paused. Attributing
that to any one of the three is guesswork, and COMPLIANCE.md has to say which.

This builds both binaries before pinning, pins once, and runs them interleaved
over three rounds so any remaining drift lands on both sides. It compares only
the benchmarks: the baseline than TestParallelScanScales measures something
different by construction, so running it on both would compare two harnesses
rather than two implementations.

Restores clocks on EXIT, INT, TERM and HUP as pinned-run.sh does, and also
returns the checkout to the branch it started on rather than leaving somebody
on a detached HEAD.

Refs: #3
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The dirty-tree check runs after the trap is installed but before any clock is
saved, so bailing there printed "== restoring" and a pair of governor values.
Nothing had been changed and nothing was put back -- but on a shared machine
that output reads as though the script had pinned the box, and the next person
to look has no way to tell the difference.

Refs: #3
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
They are shell scripts with a shebang, committed at 644. Anyone who ran chmod
+x to invoke one directly then carried a permanent mode diff in their working
tree -- which is how this was found: bench/pinned-ab.sh refuses to run against
a dirty tree, and the only thing dirty was the bit.

Refs: #3
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Measured with the governor fixed, boost off and the machine's periodic job
paused, ParallelScan reaches 6.83x at 8 workers against a 6x floor -- and so
does the code as it stood when the shortfall was filed, at 6.38x against this
branch's 6.35x. The threshold was already met and had never been measured.

The previous record was wrong twice over. It first blamed memory bandwidth,
then a fixed per-call cost in ParallelScan, and treated three machines agreeing
on ~4x as proof that the ceiling was in the code. They agreed because they
shared a measurement, not a bottleneck: one testing.Benchmark sample per side,
taken in sequence, on hardware whose boost clocks favour the 1-worker side --
one active core boosts, eight do not -- and, on the machine used for the
decisive Threadripper figure, alongside a periodic heavy job.

A CPU profile at 8 workers puts 91.5% of samples in Parser.Next, with no GC,
lock, allocator or scheduler frame above 2%, and gctrace shows the collector
taking about 2.5% of wall against a flat 4 MB heap goal. There was nothing
there to fix.

The remedial work still stands, at about 2% of throughput and none of the gap:
shards are planned from the input rather than from --jobs, so the two sides of
the ratio do equal work. main's 6.38x compares 8 shards against 64; this
branch's 6.35x compares 32 against 32. That distinction is irrelevant to a
threshold met by a wide margin and is the whole point once PERF-030's 5% gate
exists.

AC-019 is recorded as measured-met and NOT publishable. VAL-004 bars a PERF
figure from a machine that is not dedicated, and a shared box with a paused
neighbour is not one; bench/MACHINE.md is still unfilled and bench/RUNNER.md's
runner still does not exist. The figure also comes from a 16-core machine
running 8 workers, where AC-019 is stated for 8 cores -- a harder case, since
there the workers would contend for physical cores and share SMT siblings.

Also recorded: the csvlog record loss this uncovered, and that the
auto-detecting path remains unmeasured.

Refs: #3
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
A pinned self-hosted runner is infrastructure this project does not need. Best
effort benchmarks, measured on a named machine with the clocks fixed for the
duration of the run, answer every question it would have answered -- and the
apparatus around it had started to obstruct the work: AC-019 was recorded as
unmet for months, then as met-but-unpublishable, when the actual measurement
was 6.83x and always had been.

Deleted: bench/RUNNER.md, the provisioning procedure for hardware nobody was
going to buy. T146 is dropped and T147 stays removed.

Amended in the specification:

  SVC-002  removed. There is no benchmark runner service.
  INF-002  a machine with 8+ cores and enough RAM, not a pinned reference one.
  INF-003  pgbadger and pgweasel installed, versions recorded next to any
           ratio quoted against them.
  TST-008  benchmarks must be REPEATABLE -- the procedure committed and
           runnable -- rather than run on a dedicated runner.
  TST-014  record the machine a figure came from, rather than pin one machine
           and reproduce it verbatim. Different machines are expected;
           unstated ones are not.
  PERF-030 a pre-release benchstat comparison rather than a CI gate that fails
  AC-020   the build. A 5 % threshold on shared capacity measures variance,
           and a job that reports noise as a regression is one everybody
           learns to ignore, which leaves a green tick attached to nothing.
           The allocation half still runs on every push: 0 allocs/op is exact.
  AC-019   "at least 8 cores" rather than "an 8-core reference machine".

VAL-004 is NOT removed, and was never the rule I had been citing. It requires
the comparative table to be published honestly, including the workloads where
no comparison was possible. That is not overhead, that is the point.
bench/MACHINE.md had glossed it as "no figure from an unpinned machine may be
published", which appears nowhere in the specification; that gloss is gone.

bench/MACHINE.md now records the two machines actually measured on and how to
repeat a figure, instead of an unfilled template for a machine that did not
exist.

TestParallelScanScales gates on PGLOGWATCH_BENCH=1 rather than
PGLOGWATCH_BENCH_MACHINE=1: intent, not a blessed host. It still refuses to
assert when GOMAXPROCS is not the worker count or when the median and best-case
ratios disagree, because both mean the number describes the machine. Asserting
unconditionally was tried first and failed on the development machine at 5.79x
with boost enabled -- which is exactly the "red for everybody, ignored by
everybody" failure this commit is about.

Refs: #3
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
It was labelled "best of N" and is nothing of the sort. It divides each side's
FASTEST run, and taking the quickest 1-worker run shrinks the numerator -- so
it can land either side of the median ratio, and on the 128 MiB corpus it
landed below: 6.88x against 6.91x, because the 1-worker minimum sat 1.07% under
its median while the 8-worker minimum sat only 0.65% under its.

The statistic stays. Interference only ever makes a run slower, so each side's
minimum is the best estimate of its uncontended time and the ratio of the two
is the best estimate of the true speedup. Two estimators of one quantity that
disagree are how a busy machine is detected, which is the entire reason both
are printed.

Only the name was wrong, and a reader who takes "best" at face value concludes
the harness is broken when the second number comes in lower.

Refs: #3
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
#4 merged the csvlog fix to main with a regression test in
parallel_boundary_test.go. This branch carried its own copy of that test in
parallel_shard_test.go, written when the fix lived here, so the merge declared
TestParallelScanKeepsMultiLineCSVRecords twice and every job that compiles the
test binary failed.

Rebased onto main, which dropped the now-duplicate fix commit, and kept one
test -- in the file main put it in, so the diff against main stays small.

The two versions were not the same test, and the surviving one takes the
stronger axis. main's sweeps the WORKER count, because when it was written
planShards derived the shard count from --jobs and that was how to reach enough
shards for a boundary to land inside a record whose message spans lines. On
this branch the plan is a function of the input alone, so every worker count
produces identical shards and a worker sweep runs one configuration seven times
over. It sweeps the input size instead, and asserts the plan really did produce
several shards. The worker sweep is kept underneath, since concurrency is still
worth varying -- it just no longer varies the thing this bug needs.

Refs: #3
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@pashagolub
pashagolub force-pushed the fix/ac-019-scaling-measurement branch from cb9b8bf to 541dbd8 Compare September 2, 2026 13:23
@pashagolub pashagolub self-assigned this Sep 2, 2026
@pashagolub pashagolub added the enhancement New feature or request label Sep 2, 2026
@pashagolub
pashagolub merged commit 2e86ae5 into main Sep 2, 2026
15 checks passed
@pashagolub
pashagolub deleted the fix/ac-019-scaling-measurement branch September 2, 2026 13:29
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

enhancement New feature or request

Projects

None yet

Development

Successfully merging this pull request may close these issues.

AC-019: ParallelScan scales to ~4x at 8 workers, not the required 6x

1 participant