dimhold.by
← Writing

My README said this benchmark needs a 2× difference to see anything. Given a known delay, it saw 3%

In August I measured what a live preview costs if you build it on a transaction rollback and put the harness on GitHub as preview-cost. Over 4,500 pairs the rollback was slower than an in memory copy every time, with a median difference of 6 to 7 ms. In the README I also wrote a paragraph about noise. At 40 plans the medians of 5 separate JVMs ranged from 5.43 to 7.79 ms on identical inputs. From that I concluded that if the 2 strategies had been “within 2× of each other, this harness could not have told them apart.” The same sentence added that nobody else’s single run could do it either.

I liked that sentence because it sounded modest. I never checked it. It is a claim about what the harness can see. That can be measured, if the harness gets an effect whose size I already know.

A delay with a known size

Every pair runs the same rollback preview from the repository twice. The second run gets a busy wait on top, Thread.onSpinWait() until System.nanoTime() passes a fixed deadline. So it costs d microseconds more, plus a few tens of nanoseconds. I tried 8 values of d from 0 to 500 µs. Each one got 10 fresh JVMs with 300 pairs in each, after 80 pairs of warmup. Inside a JVM the plain and the delayed preview swap order at random every pair, as in the original Bench.

This time it ran against PostgreSQL 16.14 installed locally instead of Postgres in Docker, on OpenJDK 21.0.12.1 in a virtual machine with 4 vCPU. The repository asks Gradle for JDK 25, but the classes I needed use nothing newer than records and text blocks, so I compiled them with plain javac next to a new runner. On this setup a rollback preview costs between 0.7 and 1.1 ms instead of 6.5. The original comparison still holds: rollback was slower in 2,998 of 3,000 pairs.

The spread came back too. With d = 0 both previews in a pair are identical and the medians of the 10 JVMs went from 746 to 1,005 µs. That is a third of the value for the same command on the same machine. The in memory copy in the original comparison had one JVM at 278 µs while the other 9 sat between 77 and 102.

median of the plain preview, µs paired difference, µs 700 800 900 1000 0 25 50 true +25
By construction the delayed preview is 25 µs slower. The JVMs disagree about the plain one by about 210 µs, but in each of them the pairs put the difference above zero.

What one JVM can see

For every JVM I took the per pair differences and a bootstrap interval on their median, 2,000 resamples. I count the delay as seen when the whole interval sits above zero.

true delayJVMs that saw itall 3,000 pairs, median and 95% interval
0 µs0 of 100.6 µs [−3.1, 3.7]
5 µs3 of 108.1 µs [5.1, 11.1]
10 µs6 of 1012.2 µs [8.1, 15.3]
25 µs10 of 1025.0 µs [21.5, 28.7]

25 µs on top of roughly 800 is 3% and all 10 JVMs found it. The medians of the plain preview in those same JVMs differed by about 210 µs. At no delay did a JVM put its whole interval below zero, the A/A run included. So for this harness my sentence was about 30 times too cautious, 2× against 3%.

The pairing explains it. Across the 10 JVMs the median of the plain preview and the median of the delayed one move together. The correlation is between 0.95 and 0.996, depending on the delay. My guess is that whatever makes one JVM slower is paid by both halves of a pair, so the difference cancels most of it.

Where the sentence is right

Its second half is right and it describes a different procedure. That procedure is the one I use most of the time: run the thing, change something, run it again, compare 2 medians. I simulated it by taking the plain median from one JVM and the delayed median from another. 10 JVMs give 90 such combinations.

true delay, µs 0 5 10 25 50 100 250 500 paired, one JVM 0/10 3/10 6/10 10/10 10/10 10/10 10/10 10/10 2 separate runs 47/90 50/90 46/90 52/90 62/90 68/90 90/90 90/90 blocks, one JVM 2/10 3/10 0/10 4/10 3/10 6/10 10/10 10/10
How often each method said the delayed preview is slower. Paired counts a JVM only when the whole 95% interval is above zero; the other 2 rows count the sign of a difference of medians. At 0 µs both previews are identical and every count is a false report.

At 100 µs, which is 12% of the value, 68 of 90 comparisons got the sign right. Their estimates went from −157 to +385 µs. At 50 µs it was 62 of 90 and with no delay at all 47 of 90 said the second one is slower. Only at 250 µs, close to the spread between JVMs, did all 90 point the right way.

The first version

The first version of the harness measured all of the rollback previews and then all of the in memory ones, inside one JVM. It went out as a gist on 14 August with one median per configuration, 4.85, 4.96 and 7.79 ms. Less than 2 hours later I had replaced it with the paired one, because I knew the blocked order was wrong in principle. I did not know by how much, so I ran that order too. My runner keeps the warmup of the new version, so it repeats the order of the old one and not all of it.

In the A/A case the second block came out faster than the first in 8 of 10 JVMs, by 119 to 173 µs. In the other 2 it was slower by 10 and 16. With a true delay of 50 µs on the second block, 7 of 10 JVMs called it faster. At 100 µs it was 4 of 10. I can’t separate the order from the time the JVM had already spent running, since in this design they are the same thing. Next to the 6 ms of August a bias of this size would not change anything, but I never measured it on that setup.

What I did not check

I don’t know why the JVMs differ by a third. I did not look at JIT logs or at what else runs on this virtual machine. There is also a small thing I cannot explain. At 250 and 500 µs the pooled estimate is 244.7 and 488.5 and neither interval reaches the true value. A busy wait cannot finish before its deadline, so part of the difference goes missing somewhere else. My runner does not record which preview went first, so I can’t say where. At 5 µs the estimate is 8.1. That is above the truth and I can’t explain it either. All the numbers come from one pass of the grid, not from a median of several passes.

None of this is new as a method. Georges, Buytaert and Eeckhout argued for intervals over several VM invocations in 2007. Kalibera and Jones worked out in 2013 how many repetitions each level needs. What I checked is my own sentence on my own code. If I wrote that README line today, it would talk about 2 separate runs. On this setup they could not tell apart things within about 30% of each other. Inside one JVM 25 µs was enough.