Primary-Link Failover, a Real Latency Mystery Finally Closed, and a New Job

Closing a mystery that's been open for months

Long-time readers of this blog (or anyone who's heard me complain about it in person) know about the "real UDP loss, zero counters" mystery — real-world packet loss showing up under load, while every single counter mlvpn-rs keeps on itself stayed at zero the whole time. It survived several releases without ever getting root-caused. It's closed now, and it turned out to never have been loss at all — it was delay, badly misread by everything downstream as loss.

The culprit was the piece of the tunnel responsible for putting packets back in the right order when they arrive out of sequence — think of it as a bouncer at the door, holding a packet back briefly if it looks like it arrived ahead of one that should have come first. The bug: it was comparing each real chunk of data against a counter that's actually shared by every kind of message the tunnel sends, not just real data — so the specific number it was waiting for almost never showed up as an actual data packet, and it ended up holding nearly everything back for almost the full delay window, every time, in both directions. That's around 110 milliseconds of pure, needless added delay, which is exactly the kind of thing a tool like iperf3 can mistake for loss when a retransmit timer fires early.

Fixed that in one release, watched it work great right after a fresh restart — then watched it quietly break itself again a couple minutes later. The fix kept track of the highest sequence number it had ever seen, but that tracking doesn't survive the tunnel's own routine security key rotation (every two minutes by default), which restarts its own numbering from near zero. So the first rotation after a restart permanently stranded the tracking above where real traffic could ever reach it again, silently undoing the fix — and getting slightly worse with every rotation after that. Caught this for real: measured a healthy connection right after restart, watched it degrade back to the old bad numbers a few minutes later, while a plain ping on the same physical link never budged. Fixed by resetting that tracking whenever a new security session starts, and confirmed by sitting there and watching it survive a real key rotation with the connection staying healthy the whole time.

A real performance bug, caught live, not yet fully fixed

While all that was going out to production, went looking at exactly how efficiently the daemon was actually using the CPU on the real routers — using a tool that watches, moment by moment, what a running program is actually doing. What it found: the daemon was spending somewhere around 75 to 80 percent of its time waiting to get exclusive access to shared internal data, rather than actually moving traffic. That's a real bottleneck, capping real throughput well below what the underlying links can actually carry, and it was invisible without watching the program run live — nothing about it showed up as an error or a dropped packet anywhere.

Shipped two same-night follow-up fixes that each cut down on how often that contention happens. Being straightforward about where this stands: it's better, but it isn't fully resolved yet. This is exactly the kind of bug where I'd rather say "meaningfully improved, more work still to do" than claim it's solved before I've actually proven that with more measurement on the real hardware.

Smaller things, and a personal update

Also in this stretch: raised the size of an internal queue the tunnel uses on its way out to the network, since the old default could start dropping bursts of traffic before the rest of the pipeline even got a chance to handle them — cheap insurance against a whole class of bursty-traffic problems. And fixed a smaller but real annoyance in the build pipeline: pushing a release tag was always treated as a brand-new, never-before-seen branch for caching purposes, so every single tagged release was forced through a slow, fully-cold rebuild even when the exact same code had just been built minutes earlier on the main branch. Now a tagged release reuses that work instead of redoing it.

On the personal side: tomorrow I start a new part-time job as a sales representative at the Ace Hardware here in Zion. Different kind of work than anything above — good to have something that isn't a keyboard for a few hours a week.