DEV Community

Cover image for A node that reported Ready and started nothing: four parts, one containerd fix
Nahum Litvin
Nahum Litvin

Posted on Originally published at catchkill9.dev on

A node that reported Ready and started nothing: four parts, one containerd fix

What happened

In July one of our Kubernetes nodes stopped starting pods for 4.5 hours. It reported Ready the entire time. The scheduler kept placing pods on it, every new container hung in creation, and nothing on the node's health path looked wrong.

We run untrusted user code at Wix, one site per sandbox, so pods come and go all day. A node that silently stops starting them is worse than a node that dies: the scheduler keeps feeding it.

The easy answer was a file descriptor limit. The snapshotter logs were full of "too many open files". Raise the limit, restart, move on. I almost shipped that.

This is the whole story in one place: the outage, the two bugs, the fix that got reverted, and the one that stays.

Why it happens

Two bugs lined up.

The first was in containerd. During snapshot garbage collection, containerd calls the snapshotter's Remove while holding that snapshotter's write lock in containerd's metadata layer, with no deadline. It even drops the caller's cancellation. If the snapshotter never answers, the lock is held forever, and every snapshot operation on the node queues behind it, including the one that starts a new pod sandbox. Nothing on the readiness path takes that lock, which is why the node kept saying Ready.

Readiness is a separate path. Kubelet asks the runtime for its status, the runtime answers from memory, and nobody touches the snapshot metadata. So the node was healthy by every check we had, and useless by the only one that mattered: can it start a container.

The second was the trigger, in AWS's soci-snapshotter, the plugin that lazily loads container images. Every file verified on first access opened a reader from the span cache and never closed it. The sibling function about 45 lines up closes the exact same reader. One leaked file descriptor per file, on every node running lazy-loaded images. Under a burst of pod starts the snapshotter hit its limit of 65,535 and stopped answering. containerd was waiting on it, holding the lock.

A proxy snapshotter like soci runs in its own process, and containerd talks to it over gRPC. That boundary is where the real problem lived, though it took me two more PRs to see it.

The goroutine dumps told the story once we knew where to look. Hundreds of goroutines parked on that snapshotter lock, and one GC goroutine holding it, waiting for a gRPC header from the snapshotter that was never coming. The node was not broken. It was waiting, politely and forever.

What we got wrong first

I got the diagnosis wrong twice before I got it right. After the storm the file descriptor count looked low, 151 out of 65,535, so I concluded the limit theory was wrong. Then I flip-flopped back. The leaked descriptors had been reclaimed once Go's finalizers ran, so the steady state hid the peak.

I did most of that investigation with Claude, reading goroutine dumps from the wedged node and two unfamiliar codebases side by side. It didn't write the fix. It made the investigation cheap enough to do properly, including catching my own wrong conclusion.

The bigger mistake came later. My first containerd fix put a timeout on the one call that hung on my nodes, the GC's Remove. It was correct for my incident. It got merged after 40 days and 30 review rounds, and I wrote about it as a win.

Those 30 rounds were the real engineering. The timeout's config key got renamed twice, because in a project with hundreds of keys a name is an API commitment. The default went from 30 minutes to 5 and back to 30. I pushed hard for 5. A maintainer pushed back: the old behavior was unbounded, so on upgrade the least surprising default is the big one, and anyone running remote snapshotters can tune it down. He was thinking about thousands of clusters upgrading. I was thinking about mine.

My test got rewritten around Go's synctest, so it runs in milliseconds on a fake clock instead of sleeping and mutating global state. And when CI wedged in the merge queue, Michael Brown restarted the buckets, herded reviewers and queued it again until it landed.

Then I opened a second PR to cover another call that could hang the same way. Working through it with the maintainers, we saw that I was patching symptoms one call at a time. The thing that hangs is an external plugin, and it can hang on any of its calls. With a release about to be cut, Michael Brown reverted my first fix 13 days after it merged, so it never shipped. I agreed with the call.

The suggestion that changed the plan came in that second PR's thread: stop bounding components one by one, and put the bound where containerd talks to the plugin. Michael agreed. Reverting my first fix was the price of doing it that way, because two mechanisms bounding the same call would have been worse than one.

The fix

  1. soci-snapshotter: close the reader in file Verify. One line, defer r.Close(), merged upstream in July.
  2. containerd, first attempt: bound the GC path's Remove with a configurable timeout. Merged, then reverted before release, because it fixed one call out of many.
  3. containerd, the fix that stays: a default_timeout setting on proxy plugins. When it is set, every call containerd makes to a proxy snapshotter gets that deadline if the incoming context has none. A caller that brings its own deadline keeps it. Leave it empty and nothing changes on upgrade.

The proxy snapshotter has 10 gRPC methods and none of them had a deadline unless the caller already set one. Putting the bound at the client covers all 10 at once, including the GC path my first fix targeted. It also covers paths I never hit in production, which is the point.

Streaming calls needed a decision. Walk gets one deadline for the whole stream, not one per message, so time spent in callbacks counts against it. The content store proxy has the same gap but a different shape: a writer outlives the call that created it, so a per-call deadline would cut an ingest that is still being written. That one needs its own setting and its own PR.

The review on the final PR was shorter, and it still taught me something. I had added an options argument to the exported constructor. Compatible, I thought. The maintainer pointed out it still breaks anyone who stores that function as a value, so the old constructor stays untouched and a new one takes the options.

The SOCI side was the quick part. The PR went in on July 15 and AWS merged it five days later. The containerd side took three PRs and two months. The difference is not the size of the change. A one-line fix to an obvious leak has one right answer. A timeout in a runtime that thousands of clusters run has many plausible answers, and the review is where you find out which one the project can live with.

It doesn't fix everything, and the PR says so. A GC pass over many slow snapshots can still add up while it holds the lock, because each call finishes just under the limit. That needs the lock itself reworked, and it is the next piece.

Four posts, three PRs, one revert. The fix that finally lands is smaller than the one that got reverted, and it covers more. That is usually how it goes when the review is doing its job.

Lessons

  • A patch that is correct for your incident and a patch that is correct for everyone running the project are different things. The review is the distance between them.
  • Review doesn't stop at merge. Mine got reverted, and the revert was the right engineering.
  • Put the bound at the boundary. One deadline where containerd talks to the plugin covers every call; one deadline per call never ends.
  • The steady state lies. Look at the peak, not the numbers after the storm.
  • Maintainers do invisible work daily, for free, for strangers. Say so when they do it for you.

Credits and links

Top comments (0)