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 mystery where mlvpn-rs seemed to lose data under load, even though every counter it kept on itself stayed at zero the whole time. It survived several releases without me ever finding the real cause. It's closed now, and it turns out nothing was ever actually lost — it was delay, and everything downstream was badly misreading that delay as loss.

The culprit was the part of the tunnel that puts 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 waiting for a specific packet that almost never actually showed up, so it ended up holding nearly everything back for almost the full delay window, every time, in both directions. That added about 110 milliseconds of pure, needless delay — exactly the kind of thing that can look like lost data to anything timing a connection.

I 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 only worked until the tunnel's routine security refresh (every two minutes by default), which reset some internal counting the fix depended on. So the first refresh after a restart silently undid the fix, and it got slightly worse with every refresh after that. I caught this by measuring a healthy connection right after restart, then watching it degrade back to the old bad numbers a few minutes later, while a plain ping on the same physical link never budged. Fixed it properly this time, and confirmed it by sitting there and watching the connection survive a real security refresh and stay healthy the whole time.

A real slowdown, caught live, not yet fully fixed

While all that was going out to production, I went looking at exactly how efficiently the program was using the computer's processor on the real routers. What I found: it was spending somewhere around 75 to 80 percent of its time waiting in line for access to shared data, instead of actually moving traffic. That's a real bottleneck, capping real speed well below what the connections could actually carry, and it was invisible without watching the program run live — nothing about it showed up as an error or lost data anywhere.

I shipped two same-night follow-up fixes that each cut down on how often that 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 real-world testing.

Smaller things, and a personal update

Also in this stretch: raised the size of an internal holding area the tunnel uses on its way out to the network, since the old limit could start dropping bursts of traffic before the rest of the program 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 how releases get built: tagging a release was always treated as something brand new, so every tagged release was forced through a slow, from- scratch rebuild even when the exact same code had just been built minutes earlier. Now a tagged release reuses that earlier 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.