Reference: The audit latency harness¶
Every audit figure in this documentation came out of one harness, and the harness is more interesting than most of the figures. It exists because a benchmark that cannot prove what it measured is worth less than no benchmark — a claim this project has had to make good on repeatedly.
The kit lives with the analyser, in tools/bench/latency-kit/.
What it is¶
| script | what it answers |
|---|---|
measure.sh |
what does this arm cost — or a refusal |
compare-arms.sh |
do two arms differ, holding everything else equal |
validate-controls.sh |
is this machine still producing the recorded numbers |
describe-control.sh |
what exactly was a figure taken against |
index-binaries.sh |
which binary is which |
control-bands.tsv holds the bands; RECORDED-BASELINES.md holds the measurements and the
configuration that produced each.
It refuses more than it reports¶
That is the design, not a limitation. measure.sh declines to print a number when:
- the machine is not idle — load average above 4 on ten cores
- the arm is not repeatable — three batches of six, gated on the coefficient of variation of the batch minima: 2% native, 6% JIT
- the result carries no harness version or runtime identity — every
RESULTline stamps both
The refusals earn their keep. Read the JIT threshold in particular: measured repeatability on this graph is 0.05% native and 5.49% JIT. A JIT difference under about 6% is not a difference, and the harness will not let you report one.
What the benchmark itself asserts¶
The harness in the benchmark refuses to print a RESULT line unless it can prove what it ran:
- the requested clock mode and record type actually took effect — resolved values are echoed and cross-checked against what was asked for
- the audit sink saw records, and the records were non-empty
- the graph produced the expected checksum, so two arms did the same work
Each of those assertions exists because its absence produced a plausible wrong number:
| the assertion | the failure it now catches |
|---|---|
| clock mode took effect | -D placed after the main class is a program argument, not a system property. Native parses it; the JVM ignores it. Two arms silently ran different configurations. |
| the sink saw records | LOW_LATENCY_AUDIT once disabled node registration and therefore the audit log. The benchmark got much faster because it was measuring nothing. |
| the checksum matches | An arm was compared against a different arm's graph. |
| harness version stamped | An h5 binary passed an h3 band. Comparing a declared value against another declared value checks nothing — the version is read from the binary's own output. |
Native: build three times, and use the mean¶
The single most important fact for anyone measuring a native image here: rebuilding the same configuration moves an audited figure by up to ±8 ns. The PGO profile decides which regime a build lands in, and profile collection is itself a measurement — two collections of one workload minutes apart differ in over a thousand call-count contexts.
So an effect smaller than about 8 ns cannot be established by one build per arm, however repeatable that one binary is. Build three, and:
- minimise within a build — that removes measurement noise, and is what
measure.shdoes - average across builds — minimising across builds samples the lucky tail of the lottery and reports a figure no deployment will see
A useful non-parametric check with three builds each: if all three of one arm fall below all three of the other, that is 9 of 9 pairings, p ≈ 0.05 under a no-effect null. Anything less and the arms are not separated.
Change one thing¶
Known inputs that move an audited figure, to be varied one at a time:
| input | effect |
|---|---|
| processor escaping the loop method | 4.3× on native, nothing on JIT |
-H:-SpawnIsolates |
−24 ns audited on GraalVM 25.0; the flag is refused from 25.3, where no penalty was measured without it |
| record format, text vs binary | 3.2× sparse, 9.5× dense |
| audit density | the variable behind most of the spread |
| GC epsilon vs serial | 0–14 ns |
| PGO profile SHA | decides which regime a build lands in |
| build lottery, same config rebuilt | ±8 ns audited |
Profile before you optimise — and measure before you believe the profile¶
Both halves matter, and this project learned the second one the hard way.
Two rounds of harness discipline — interleaving, build lotteries, runtime digests, refusing unrepeatable results — never found that 56% of the audited path was resolving names that never change. One JFR profile did, and fixing what it named took 24% off the JIT figure.
But the same profile also showed EventLogger.info as the leaf frame in 71% of samples on the
no-audit control. Building an arm with the audit call sites physically deleted put the real cost at
1.40 ns across 11.75 call sites. HotSpot had inlined the node's arithmetic into info, and the
sampler reported the inlined frame as the leaf.
A sampling profiler gives you proportions, never magnitudes, and its attribution is only as honest as the inlining underneath it. It is also safepoint-biased, which under-reports exactly the tight straight-line code a latency path is made of.
Use a profile to generate hypotheses. Use a differential measurement to size them. In the round that produced these figures, four hypotheses came from profiles; three were real and one was a phantom, and only the measurement could tell them apart.