Reduce CoreMark benchmark noise in CI - #124
Conversation
The benchmark job measured the PR and main once each and reported the difference to three decimal places, which reads as a precise result but is not one. Across the 41 PRs that carry a bot comment, the reported delta ranges from -13.23% to +13.39%, and PRs that only touch docs, the README, the logo or CI config still move it by as much as 3.80%. Two things make the measurement worse than it needs to be. A single CoreMark run scores itself from wall-clock time over roughly fifteen seconds on a shared runner, so one sample carries several percent of noise on its own. On top of that main was always measured second: the mean delta over those 41 PRs is -1.13% and 27 of them are negative, which a sign test puts at p = 0.03 against an even split. Build both bench binaries up front, stage each one next to the wasm it loads, then run them alternately and report the median of five samples per side. Swapping which side goes first on every other sample keeps the ordering from favoring either one. The comment now carries the observed sample range and marks a delta that falls inside it as noise. This does not make scores comparable between runs and cannot: baseline scores for main span 230 to 498 depending on which CPU model the runner lands on. Co-authored-by: Cursor <cursoragent@cursor.com>
|
Welcome, new contributor! Please make sure you've read our contributing guide, as well as our policy regarding AI usage, and we look forward to reviewing your pull request shortly |
CoreMark Benchmark ResultsCurrent Score: 265.252 |
Code Coverage ReportCurrent Coverage: 95.38% |
|
The main thing CoreMark benchmarks should measure is how much extra work a PR adds. Instruction counts should be a good enough stand-in that isn't affected by the hypervisor, and you should be able to get them via |
A CoreMark score mostly measures how fast the runner is. What a PR can change is how much work the interpreter does, and instructions retired measures that directly: it does not move with the CPU model the runner landed on or with whoever else is on the machine, so one run per side resolves a difference that no number of timed samples can. Hardware counters are not an option here. GitHub runners are Azure VMs whose hypervisor does not expose the PMU, so perf reports cycles, instructions and branches as unsupported, and reading a counter through ptrace is out for the same reason. Count under callgrind instead, which is pure user-space instrumentation and needs no counters at all. Counting first needs a workload that does not depend on the clock. CoreMark sizes itself by timing ten iterations, multiplying by ten until that takes at least a second, then settling on iterations * (1 + 10 / floor(seconds)). The divisor is an integer, so a calibration round of 1.9s and one of 2.1s differ by nearly 2x in the work that follows. Counting that without pinning it would be worse than timing it. COREMARK_FIXED_CLOCK feeds the module a fixed table of timestamps instead, which holds it at 110 iterations with an eleven second measured window: still a valid CoreMark run, and one that scores exactly 10.0 every time. The bench asserts that score, so a module that starts timing itself differently fails the job rather than producing two counts that describe different work. The score stays, at three samples per side rather than five. It is still worth reporting what the runner managed, but it is no longer the number a regression has to be read out of. This also increments CLOCK_CALL_COUNT, which nothing ever incremented before, since the fixed clock indexes its table by it. Co-authored-by: Cursor <cursoragent@cursor.com>
A bench binary built before COREMARK_FIXED_CLOCK existed ignores it and sizes itself from the clock, so counting it against one that pins its workload compares two different amounts of work. That is the situation for this PR's own baseline, and for any branch that predates it, so the step probes each side first: a pinned run scores exactly 10.000 and costs a fraction of a second, which is a cheaper way to find out than the callgrind run it would otherwise spoil. Skip the counts with a warning in that case rather than fail, leaving the timed comparison to stand on its own as it did before. Co-authored-by: Cursor <cursoragent@cursor.com>
|
Good call, thanks. I've pushed 07a2d16, which adds an instruction count and moves the timed score down to being context. Two things got in the way of doing it quite the way you suggested, so I'll write them down here. I couldn't get at hardware counters from these runners. They're Azure VMs and the hypervisor doesn't expose the PMU, so perf reports cycles, instructions and branches as The other thing is that the workload isn't fixed today, and counting an unfixed workload would have been worse than timing it. CoreMark picks its own iteration count from the clock. It times ten iterations, multiplies by ten until that takes at least a second, then settles on So the bench now has a Two caveats I'd rather state up front than have you find. Ir says nothing about cache or branch behaviour, and for a dispatch loop that's a fair part of what decides how long the work takes. I'd read it as a gate on work added rather than a measure of speed. Adding Also, a bench binary built before this lands ignores the variable and can't be pinned, so the step checks each side first and skips the counts with a warning instead of comparing two different workloads. That covers this PR's own baseline from On cost, AI usage, per AI_POLICY.md. As with the rest of this PR, Cursor's agent wrote the implementation and a draft of this comment. I checked the runner PMU limitation and the calibration behaviour myself before writing them down. |
|
@suthat I prepared a focused follow-up for this PR: suthat#1 issues in PR #124:
followup pull request to complete fix from PR #124It gives both builds the same benchmark, fails invalid comparisons, and reports timed results without calling them a confidence limit. Both builds produced the expected Callgrind counts instructions for the fixed workload, but it does not measure cache or branch performance. AI usage disclosure: OpenAI Codex was used to analyze specific PR #124 escape issues and devise testing protocol for fix. It was also used in implement the two workflow changes. Manually validated and reviewed the commit. AI assisted draft cross-fork PR and draft of this comment before alterations. The diff is submitted for author and maintainer review. Validationincludes Actionlint 1.7.12, workflow YAML/Bash/JavaScript syntax, formatting, bench-target Cargo check and Clippy, and an actual bootstrap check: both the PR build and current The contribution is a draft for your review. It contains one commit and changes only |
3 participants
Closes #76.
Problem
The benchmark job measures the PR and
mainonce each, then reports the difference to three decimal places. One CoreMark run can't support that kind of precision. The score is worked out inside the wasm module fromclock_mswall clock time over roughly fifteen seconds, on a runner shared with other tenants.To get a sense of how big the effect is, I scraped the bot's comment from every PR that has one, 75 of them, and worked out the reported delta.
The clearest cases are the PRs that can't have changed the code the benchmark exercises at all, so docs, the README, the logo and CI configuration.
There's a bias in the ordering as well.
mainis always measured second, and 48 of the 75 deltas are negative, which a two-sided sign test puts at p = 0.02 against an even split. That isn't proof on its own, but it is what you would expect if the second run tends to land on a warmer machine.@Robbepop's point about runner hardware shows up in the same data. Baseline scores for
mainrange from 223 to 498, a factor of 2.23, in clusters that look like distinct CPU models. It doesn't affect the delta, since both sides are already measured in the same job, but it does mean the absolute score is meaningless outside its own run, which the comment never said.What this changes
Counting instructions
Following @h313's review, the figure the comment leads with is now the number of instructions each side executes, counted once per side under
valgrind --tool=callgrind. It doesn't move with the CPU model the runner landed on, or with whoever else is on the machine, so a difference of any size in it is work this PR added or removed.Hardware counters can't do this job here. GitHub runners are Azure VMs whose hypervisor doesn't expose the PMU, so
perfreportscycles,instructionsandbranchesas<not supported>(runner-images#4974), and reading a counter throughptraceruns into the same wall.PTRACE_SINGLESTEPdoes count instructions on any machine, but at roughly a microsecond each it's minutes for the small workload below and days for a full run. Callgrind needs no counters, being user space instrumentation.Counting also needs a workload that doesn't depend on the clock, and this one did. CoreMark picks its own iteration count by timing ten iterations, multiplying by ten until that takes at least a second, then settling on
iterations * (1 + 10 / floor(seconds)). The divisor is an integer, so a calibration round that takes 1.9s and one that takes 2.1s end up doing nearly twice as much work as each other. Counted unpinned, a PR that changed nothing could have come out +80%.COREMARK_FIXED_CLOCK=1hands the module a fixed table of timestamps instead, which holds it at 110 iterations with an eleven second measured window. That's still a valid CoreMark run, since it clears the ten second minimum and the CRC checks pass, and it scores exactly 10.0 every time. The bench asserts that score, so a module that starts timing itself differently fails the job rather than quietly yielding two counts taken from different work.A binary built before that variable existed ignores it, which is the case for this PR's own baseline and for any branch that predates it. The step checks each side for a pinned run first, costing a fraction of a second, and skips the counts with a warning rather than reporting a comparison between two different workloads.
One limit worth stating, and the comment states it too. Instructions retired says nothing about cache or branch behaviour, and for a dispatch loop that's a fair part of what decides how long the work takes. I'd read it as a gate on work added rather than a measure of speed.
The timed score
Both bench binaries are built up front and staged next to the wasm they load, so neither side needs its revision checked out again at measurement time. They're then run alternately, three samples each, and the reported figure is the median. Which side goes first is swapped on every other sample, so the ordering doesn't favour either one.
The comment now shows the sample range next to each median, and marks a delta that falls inside the range observed in that run as noise. The band comes from the samples themselves rather than a fixed threshold, so a quiet runner still gets a tight bound and a noisy one is honest about it.
I kept the score because it's the only figure here in units anyone cares about, but it isn't what a regression has to be read out of any more, which is why three samples rather than five. Job time lands close to where it started, four fewer timed runs of roughly fifteen seconds against two callgrind runs of roughly twenty and a
valgrindinstall. The number of builds is unchanged, andBENCH_SAMPLESis still a single knob.Two things I deliberately didn't do. The score stays wall clock based, matching the reference wasm3 implementation, rather than switching
clock_msto CPU time, since that changes what the benchmark means and is worth deciding separately. And the baseline staysmainrather than the merge base, to keep this change to the measurement itself.Testing
Run locally on an Apple M4 with Rust 1.97.1 and jq 1.7.1.
End to end, against the real benchmark
The ten runs below were collected while this PR touched only
.github/, so the bench binary built from this branch and the one built frommainwere byte identical, and I verified the sha256. That made the workflow's own comparison an A/A test whose true delta is exactly zero, so whatever it reported is measurement error and nothing else. The branch changes the bench source now as well, so its own run isn't A/A any more. What follows stands as a measurement of what the timed runs can resolve, not of this branch.I pulled the
Build benchmark binaries,Run CoreMark benchmarkandSave benchmark resultsstep bodies verbatim out ofci.ymland ran them under bash withRUNNER_TEMPandGITHUB_OUTPUTpointed at a scratch directory, then fed the resulting artifact to thegithub-scriptbody fromcomment.ymlwith the REST calls stubbed out. Ten real CoreMark runs, 3m30s in total, withBENCH_SAMPLESat five.Taking one sample per side, as the current workflow does, and applying that to each pair in turn, would have reported anywhere from -3.75% to +3.57% for a change of exactly zero. The comment rendered from the medians instead reads
A near zero median difference, and a band wide enough to say so.
Cases too slow to reach with the real benchmark
Four minutes per case is impractical, so these were driven with a stub binary emitting a known sequence of scores. The median and range for odd and even sample counts, the alternating order, the path where no baseline was staged, and that a run producing no score still fails the step. On the comment side I rendered artifacts for a missing baseline, a regression larger than the noise band,
samples=1, an artifact in the pre-change format, which is what a comment run picking up a CI run started before this merges would see, and an existing bot comment, which is updated in place rather than duplicated.The pinned workload and the instruction count
I checked the fixed clock against the real benchmark.
COREMARK_FIXED_CLOCK=1scores exactly 10.000 with fourclock_mscalls, twice in a row, and runs in 0.229s and 0.201s. The same binary without it scores 591.239 over 20.473s. Two orders of magnitude less work, and the same amount of it every time, which is what makes it affordable to count and meaningful to compare.Valgrind doesn't run on an Apple M4, so the step body was extracted from
ci.ymlas before and driven with a stubvalgrindthat writes a callgrind output file. Both sides staged, no baseline staged, a baseline that predates the fixed clock, the PR itself predating it, a bench binary that exits non-zero, and an output file with nosummary:line. The first two report counts, the next three skip with a warning and leave the timed comparison alone, and the last fails the step rather than reporting an empty count. On the comment side I rendered artifacts with a small difference, a difference over 1%, no baseline, and the pre-change format with no count in it at all.Toolchain and lint
cargo test --workspacepasses, 382 tests, withwast2jsonpresent for the spec suite.cargo fmt --checkandcargo clippy --workspace --all-targetsare clean.actionlintover the two workflows drops from 8 shellcheck findings onmainto 4, and the remaining 4 are pre-existing, in the coverage job this PR doesn't touch.What local testing can't cover
My machine's sample to sample spread (7.45%, CV 2.8%) isn't a GitHub runner's, so how wide the noise band comes out in CI remains to be seen. I couldn't time callgrind here either, so the twenty seconds per side is an estimate from the pinned workload's 0.2s and callgrind's usual overhead. This PR touches
ci.yml, so its own benchmark job runs the new code and prints the counts and every sample in the job log, with the counts skipped on this run since the baseline it builds frommaincan't pin its workload yet.Total clock_ms calls: 0, which I flagged earlier as out of scope, is fixed here as a side effect, since the fixed clock indexes its table byCLOCK_CALL_COUNTand so has to increment it.AI usage disclosure, per AI_POLICY.md. Cursor's coding agent (Claude) was used to collect and analyse the historical bot comments, to write the workflow changes, the fixed clock bench mode and the test harnesses described above, and to draft this description. Scope is
.github/workflows/ci.yml,.github/workflows/comment.ymlandcrates/spacewasm_std/benches/coremark.rs, and nothing undersrc/is touched. All of it was reviewed and adjusted before submitting, the statistics were re-derived from the raw scraped scores rather than taken on trust, and the workflow logic was executed locally as described rather than assumed correct.