Five ways our own benchmark lied to us

In the previous post we spent weeks trying to make Nona use less memory and mostly failed. What we left out of that story is that a good part of the time we were not even measuring what we thought we were measuring.

Nothing crashed. Nothing warned us. A monster you can see is not what sinks you - you simply steer around it. What sinks you is the crew doing something helpful below deck while you sleep. Here are the five, in the order they hurt.

1. Our harness warmed the heap before it measured it

Our benchmark runs a matrix - 1, 100 and 10,000 keys, at 1 and 50 concurrent users. Before any of that, it sanity-checks that each dataset returns the number of keys it should. Reasonable. Here it is:

if (scenarios.Any(scenario => scenario.Operation == HttpReadOperation.FullEnvironment))
{
    foreach (var keyCount in DatabaseSeeder.DatasetRows.Values)
    {
        await ValidateDatasetAsync(client, keyCount, cancellationSource.Token);
    }
}

Read it again. It validates every dataset, including the 10,000-key one, before the first measurement is taken. That is a 164MB response pulled through the process while nobody is looking. By the time we sampled the very first scenario - one key, one user, the lightest thing in the matrix - the garbage collector had already expanded to swallow a 164MB payload and had no reason to give any of it back.

So we published a table where a container that idles at 62MiB was reported as using 459MiB to serve a single 117-byte response. We stared at that number and theorised about it. The number was fiction.

The fix was to stop trying to measure six scenarios in one process. Every row in our sizing table now gets a brand new container, and the readiness probe deliberately hits the smallest dataset so it cannot pre-warm the big one. Idle came back as 61-62MiB on every single row, which is what a configuration service should look like when it is doing nothing.

2. Docker counted the database as our memory

We reached for the obvious tool to see how much memory the container was using, and got a number that made no sense:

$ docker stats --no-stream
361.1MiB / 1GiB          <- "our" memory

$ docker top nona-size -o pid,rss,args
PID     RSS       COMMAND
2510    63696     ./Nona.WebApi     <- 62 MiB

A 300MB gap between two readings taken seconds apart. The answer is that docker stats reports cgroup memory usage, and cgroup memory usage includes the page cache. We had baked a 341MB SQLite database into the image. Every page of that file the kernel had read was being counted as memory our application was using.

It is reclaimable. The kernel will drop it the moment anything needs the room. It is not our process holding it. But it looks exactly like a memory problem on a dashboard, and if you are hunting a memory problem you will find one.

This one is worth knowing even if you never write a benchmark: if you size a container from docker stats on a service that reads a large file, you will provision for memory your application never asked for.

3. We spent an afternoon benchmarking WSL2

We ran the load generator on Windows against a container, through a published port, the way everyone does it. Then we ran the same load generator inside a container on the same Docker network, and the numbers moved:

Forty-three seconds versus seven. Same image, same workload, same machine. The only difference is that 164MB per response had to cross the boundary between Windows and the Linux VM through a userspace proxy.

Notice the shape of it: at one key the penalty is invisible, at 10,000 keys with fifty clients it is six times. The distortion scales with payload, so it hides in exactly the small-payload tests where you would go looking for it and explodes in the big ones you are trying to reason about.

4. Debug builds have opinions

Everyone knows not to benchmark a Debug build. We had been told, we had told other people, and we did it anyway for longer than we would like - because the harness was already wired up that way, and we were hungry for a number. The oldest way to sink a ship is to eat the one thing you were warned not to touch, and to do it because waiting was inconvenient.

What makes this worse than a flat slowdown is that the penalty is not even. We were comparing two approaches: buffer the whole response, or stream it through four nested async iterators, ten thousand iterations per request. Debug disables the optimisations that make state machines cheap and keeps locals alive longer, which inflates what the collector sees. It punishes the streaming path hard and the buffering path barely at all.

We were, in other words, running a race where one runner was carrying our luggage. The conclusion survived the move to Release - streaming really was worse - but the margin was wrong, and we made several decisions on that margin before we caught it. We got off that island. It was luck, not judgement.

5. The build system said yes when the answer was no

This is the one that still bothers us. Building the solution reported success. Building the individual project inside that solution, seconds later, did not:

$ dotnet build NonaConfig.slnx --no-incremental
EXIT=0                          # "Build succeeded. 0 Warning(s) 0 Error(s)"

$ dotnet build core/src/Infrastructure/Infrastructure.csproj --no-incremental
error CS0738: 'LibsqlConfigReleaseRepository' does not implement interface member
'IConfigReleaseRepository.ListEntriesAsync(...)' ... does not have the matching
return type of 'Task<IReadOnlyList<ConfigReleaseEntry>>'
EXIT=1

The code did not compile. The solution build said it did. It happened twice during the same week, on two different changes, and both times we briefly believed a change was fine and moved on.

We are not going to pretend we have fully explained this one - our best guess is up-to-date checks and project graph caching interacting badly with the newer solution format. But the working rule we adopted is dull and effective: a green solution build is a hint, and the project build is the answer. If a change matters, build the project it lives in.

What we do differently now

None of this is clever, and that is rather the point. You do not beat any of it by being sharper than the instrument. You beat it by making it impossible for anyone to open the bag. Fresh container per measured row, so nothing bleeds between them. Process RSS rather than cgroup totals, because we want our memory and not the kernel's. Load generator on the same network as the thing it is loading. Release builds, always, even for a quick look. And a project build before believing anything.

The uncomfortable part is that every one of these produced a number that looked fine. A 62MiB service reported 459MiB and off we went to explain why, building a whole theory on top of it. Instruments rarely fail loudly. They hand you something plausible and a following wind, and let you sail confidently in the wrong direction.

Next time we are looking at what Native AOT costs us, which is a subject everyone writes the good half of and nobody writes the bill for.