Fifteen Green Gates and the Question None of Them Asked

Two days after writing up a container stack, I went looking for leftovers. I found a default disk that every test had avoided, a number I had printed because I could not explain it, a capability I had called meaningless without asking the kernel, and a help text that deleted two commands when I documented one option. All four had a check sitting next to them, agreeing with the others.

merecontainerstestingverificationsystemsdogfood

Three days ago I wrote up a container stack built in a language of my own — a VMM, a daemon speaking the Docker Engine API, an OCI runtime, a registry — and ended with a section called the bugs that only real use could find. Then I went back and asked the boring question: is anything left?

Four things were. I want to describe them together, because they are the same shape, and the shape is not “I forgot to write a test”. Every one of them had a test sitting next to it. The tests were green. They had all quietly agreed to ask something slightly easier.

I have written before that guardrails protect one program and gates protect the question. This is the failure mode on the other side of that sentence: a gate that protects a question, and not the one a person would ask.

1. The path every test avoided

mvm start, with no arguments, makes a 20 GiB disk. That disk was corrupt from the moment mke2fs reported success:

disk: mke2fs ok
EXT4-fs error (device vda): bg 32: bad block bitmap checksum
EXT4-fs error (device vda): ... bg 49 ... bg 64 ... bg 96 ... bg 128 ...
disk: done                      ← it says it worked

Next boot, the kernel panicked with Block bitmap for group 0 not in group (block 4294967295). That number is 2³² − 1, and the damaged groups — 32, 49, 64, 96, 128 — are exactly the ones living above the 4 GiB line.

The cause is a declaration. My language’s int is 64 bits, but the extern prototype its C backend emits for one says plain int, while the shim defined the parameter as long long:

extern int hv_guest_to_file(const char*, int, const char*, int);      /* what the caller compiles against */
long long  hv_guest_to_file(const char*, int, const char*, long long); /* what defines it */

Both files compile clean. The caller truncates the argument on the way in, and nothing is visible at the call site. I measured it before changing anything: of 34,341 writes to a 20 GiB disk, not one landed past 4 GiB. The maximum was 4,294,963,200 — 2³² minus one page. Everything above the line folded back onto live data.

The fix is one line of convention: the offset crosses as a hex string, the way the guest address sitting next to it in the same function already did. After it, 33,144 of 34,397 accesses go past 4 GiB, the format is clean, and data written above the line survives a machine restart.

Why nothing caught it. I had fourteen gates. Here is what they pass:

test/lifecycle.sh  --disk-size 2048
test/scale.sh      --disk-size 4096
test/build.sh      --disk-size 1024 / 2048 / 1024
test/outward.sh    --disk-size 4096
test/vcpus.sh      --disk-size 4096

Not one of them omits the flag. Every one overrides the default, for the ordinary reason that smaller is faster, and that consistency is what hid the hole. The only path never taken was the one a person takes by typing the command with nothing after it.

This is worth saying plainly because it generalises past my project: defaults are untested precisely because every test overrides them. The fifteenth gate now starts a machine the way a person does, and carries the sed that puts the truncation back.

2. The number I printed because I could not explain it

At eighty parallel docker run, somewhere between 72 and 79 containers would come up. Every client reported success. I had measured it four times and disproved two hypotheses, so I did what felt honest: I printed the number and did not require it.

note  72 of 80 came up -- reported, not required

That is a defensible thing to do with a number you do not understand. It is also how a known-unknown becomes a permanent resident.

What broke it open was not a fifth measurement of the same thing. All four had counted how many containers came up — the symptom. I put a recording relay between the docker CLI and the daemon, and made it log each connection when it opened, not only when it closed. That second detail is the whole trick: logging on close shows you the requests that finished and hides the ones that did not, which is the set you are looking for.

One run, eighty clients:

POST /containers/create     opened 80   closed 80
POST /containers/ID/wait    opened 80   closed  0
POST /containers/ID/start   opened 32   closed  0

Thirty-two starts. Not eighty. Thirty-two is the number of buffer slots the daemon has, and the rest follows from one design detail I had written down myself, months earlier, in a comment: the docker CLI opens /wait on a connection of its own and sends /start only after /wait’s headers come back. So eighty waits arrive, thirty-two of them get slots and answer their headers, those thirty-two clients send /start — and every one of those starts queues for a slot that a waiting /wait is holding, waiting for a container that cannot start. A circular wait, with the cycle running through two different connections of the same client.

It is intermittent because it is a race: with forty clients the starts usually slip in before the waits take every slot. That is why more parallelism made it worse and why no threshold ever looked clean.

The fix is four lines — /wait gives its buffer slot back before it begins polling; it never needed the buffer again. Then:

clients finished /wait /start
before 0 of 80 80 opened, 0 closed 32 opened, 0 closed
after 80 of 80 80 opened, 80 closed 80 opened, 80 closed

And a number I had not gone looking for: the whole fifteen-gate suite went from 1291 seconds to 561, the scale gate alone from 765 to 54. The suite had been spending twelve minutes of every run sitting inside the deadlock. I had been calling that gate slow.

3. A capability I had called meaningless without asking

The original write-up has a section titled What it does not do, and the first bullet reads:

Outbound NAT — no upstream interface exists to translate onto

That sentence is true about NAT and wrong about the thing behind it. It is reasoning from a design I remembered, and I had never once asked the guest’s kernel what it actually has. When I did:

netfilter core present, compiled in
ip_tables, nf_nat absent
/dev/net/tun absent
loaded modules 8 — everything shipped beside the Image

So the honest statement is not “meaningless” but “six modules short”. That is a cost, and a cost can be compared against alternatives — which is exactly what “meaningless” had prevented me from doing for three sittings.

Having a number made the cheaper option visible. The capability people actually want is arbitrary outbound TCP, and SOCKS5 buys most of it for nothing: it is the same two sockets and the same copy loop as the CONNECT proxy already running, and the first byte says which protocol is being spoken, so both answer on one port. Peeking at that byte without consuming it matters — a SOCKS5 greeting is three bytes with no newline, so reading a line first waits ten seconds and then answers 405 to a client that spoke correctly.

$ docker run --rm alpine sh -c 'printf "QUIT\r\n" | curl -sS telnet://smtp.gmail.com:25'
220 smtp.gmail.com ESMTP ...

A container, with no network interface underneath it, holding a plain TCP conversation with something that has never heard of HTTP.

What it still does not carry — and this is the replacement for the sentence I got wrong — is anything speaking neither protocol: nc, ping, psql. Those want a route, and a route wants the six modules.

The gate asks in bytes rather than pages, because a proxy that accepted everything and a proxy that worked would both pass a check that fetched a page: CONNECT comes back 0x00, a command it does not implement 0x07, a name that does not exist 0x04, and a client offering an authentication method the proxy does not have gets 0xFF rather than a cheerful “none required”.

4. Documenting an option deleted two commands

The smallest one, and the purest example of the shape.

mvm --help is a comment block at the top of the script, extracted like this:

usage() { sed -n '3,14p' "$0" | sed 's/^# \{0,1\}//'; }

I added one line to that block — the line documenting a new option. It pushed mvm status and mvm doctor past line 14. The tool went on accepting both and stopped saying so.

No test could have noticed, and that is the interesting part: an option that is merely undocumented works perfectly for everyone who already knows it exists. There is no failing behaviour anywhere. The only way to see it is to compare two things that were never compared — what the argument parser answers to, and what the help prints.

So now something does. It found four more that had never been documented: --publish, --version, --kversion, --from-dir. And when I first wrote it I made the same class of mistake one layer up: it took a file argument, so it looked general, and it only worked for the one file I had written it against. Pointed at a second tool it reported “the extraction is broken” for a script whose five options were all documented correctly. One user cannot reveal a fake generalisation.

The shape

Four defects, one shape:

  • a gate existed, and it overrode the input that mattered
  • a number was reported instead of required, because I could not explain it
  • a boundary was reasoned about instead of measured
  • two artefacts that should agree were never compared

None of these is “I had no tests”. All four sat inside a suite that was green, next to checks that agreed with each other. What was missing each time was a question, and the reason it was missing was always the same: the easier question produced the same green.

Three habits came out of it, and they are cheap:

  1. Count how many of your own tests override a default. If it is all of them, the default is the one input nobody has ever tried. grep -c will tell you in a second.
  2. When a number is unexplainable, instrument the layer beneath it — not the same number a fifth time. “How many came up” is a result; “how many connections opened and how many closed” is the thing producing it. And log both ends, because logging completions hides exactly the failures you want.
  3. Ask the machine before writing “impossible”. Name the missing parts, price each one, and only then decide. The price is what makes the cheaper alternative visible.

The original piece ended by saying the most valuable output of this stack was the list of defects it found in the language. The first bug here is one more for that list — the C prototype a compiler emits for a 64-bit integer is part of the language’s contract, and mine was quietly narrowing it. But the other three were defects in how I was checking, not in what I had built, and I think those transfer further. The stack is mine and unusual. A suite of tests that have all agreed to avoid the interesting input is not.

← Back to Notes