intertwingly

Four days ago Campfire chatted, and I wrote that the sockets would get measured "when the measurement can't quietly lie." The page is up:

It is rebuilt from a run that takes over an hour, and it publishes the lanes that make me look bad next to the ones that don't.

The headline is that Rails wins

On /rooms/1 — a 420 KB room page — deployed Campfire serves 345 requests a second and the binary serves 56. Rails is six times faster, and the reason is not subtle: Campfire renders its message list as render partial: …, cached: true, so with Redis up those forty fragments are read back rather than rendered. We have no fragment cache, so we render all forty, every time.

That gap is mine to close, not a framing problem to write around. The page carries a rails-nocache lane that renders the same fragments — it serves 26 req/s, and the binary's 56 is more than twice that — but that lane is a diagnostic, not the score. A deployment is a worker count, an allocator, a proxy and a cache. Comparing against a Rails configured worse than Basecamp ships it would be a way of losing while sounding like winning.

Where the binary does win, it wins on the axes a self-hoster feels:

And one row I did not expect: per process, the binary now serves 36 req/s against the CRuby transpile's 24. This morning those were level.

What the four days actually were

The socket number was the promise. What consumed the time was a different question: the binary got nothing from twelve OS workers. On the room page it did 25 req/s with one worker and 24.6 with twelve, while per-request CPU went from 40 ms to 97 ms. The process never exceeded 1.3 cores on a 6c/12t box.

I filed that upstream as an allocator problem, with a standalone repro: two threads building strings ran slower than one. Matz found it, and the diagnosis was better than mine. Every allocation asked the collector whether it should run; the ask was refused 99.99% of the time — 7.2 million asks for 941 collections — and every refusal took the global scheduler lock on the way to being refused. A worker that was told no did not record having asked, so it asked again on its very next allocation. The fix makes a refused worker wait one threshold's worth of allocation before asking again. Two threads stopped being slower than one.

Our numbers moved with it: the deployed lane went 28.1 → 30.1 → 43.8 req/s across three runs while the single-worker lane moved 6%, which is exactly the shape a contention fix predicts.

And the binary still would not use more than about 1.4 of 12 cores.

The part where it turns out to be mine

So I filed a second issue — a cheap authenticated request pinning the server to two OS workers, with eight times the concurrency buying 7% — and I attached a mechanism: requests too short to park stay on the worker that accepted them.

Then I built the minimal reproduction I should have built before filing. Seventy lines: TCPServer, a thread per connection, a knob for how much CPU the handler burns. It spread across eleven workers at every request cost, from 35 microseconds to 314. My mechanism was dead, killed by my own repro.

One line brought the shape back. A single process-global Mutex, taken twice per request around an empty critical section:

Two workers holding 99% of the CPU while ten sat idle — not blocked, idle. That was Campfire's signature exactly, and Campfire had exactly that mutex: Db.with_connection wrapped every request in one process-global pool lock, lease on the way in and release on the way out.

Matz, meanwhile, had built his own server and could not reproduce my report at all. His first run did look like my table — 1.4 cores, two workers at 91% — and it was his client: one Python load generator is GIL-bound around 90k req/s, so his server was idle and only the workers nearest the accept path had work. Eight client processes later the same server did 239k req/s across eleven workers. He then added a shared mutex around an empty block, watched it collapse to two workers, and asked me the question that ended it: is your session lookup going through a single shared handle?

It was. The bug was ours, and it had been ours the whole time.

What changed

In Spinel, from measurements this application produced:

• the monitor's readiness set moved into the kernel — epoll, and kqueue for the BSDs. Before that, every I/O wake cost O(parked threads): 8.5 µs with none parked and 86 µs with five thousand, which is the worst possible shape for a server whose whole job is holding connections open. This is the one worth dwelling on, below.
• the refused-collection storm above (6fb02909)
• Mutex#lock and #unlock both took the global scheduler lock even when uncontended, so an uncontended acquire round-tripped through the one lock guarding every run queue: 22M → 880M ops/s (fc866b04)
• two small PRs of ours, merged: an application can name its allocator in spin.toml, and a tool that uses Thread now depends on the threaded runtime archive — without which an incremental build linked a stale one

In Roundhouse:

• the connection pool is sharded into independent pools, one bound to each thread for its life. A thread cannot simply keep a handle — Campfire holds a green thread per WebSocket, thousands of them — so the shard is a whole pool of the same unchanged class, which means no new locking to get wrong. On the cheap route: 2,449 → ~9,000 req/s.
• the emitted spin.toml names jemalloc as the application's allocator. Rails ships jemalloc in its production image; every lane on that page except ours already had it. Worth +60% at one worker and +27% at twelve.
• the benchmark harness now records how a server died. Twice this week a process vanished under load leaving an empty log, and the exit status was the only witness — 139 and 134 are different bugs.

The W-ladder that closed the issue, after the shard:

One worker with the pool fixed now beats twelve with it broken.

The gem that stopped being needed

The readiness-set change deserves more than a bullet, because of what it displaces.

Action Cable depends on nio4r. It has to: CRuby's selector is IO.select, which is O(n) in the set you hand it, so a server watching five thousand sockets pays for five thousand on every wake. nio4r is a C extension that wraps epoll and kqueue to give Ruby a kernel-managed readiness set instead, and Action Cable runs an event loop around the selector object it returns. Campfire's Gemfile.lock names it under actioncable (8.2.0.alpha), and Puma pulls it in separately.

In the four days this post covers, Spinel grew the same capability — 692e50b2 for epoll on the 4th, 1c34d424 for kqueue the same day, after the 1st made a timed readiness wait park the green thread rather than its OS worker. The 1,000-socket row in the table up top, the one reading 0.010 cores idle, is downstream of those commits. It could not have read that before them.

But "the gem got built into the compiler" undersells it. nio4r hands you a selector you then have to drive; the multiplexing stays the application's problem, which is why Action Cable has an event loop in it at all. Spinel put the readiness set in the scheduler, so a green thread blocked in recv parks and frees its OS worker, and the monitor wakes it when the fd is ready. Our server is written as one thread per connection doing ordinary blocking reads and writes. There is no event loop in it, no selector, and no callback — the code looks like the naive version you would write if you had never heard of the problem.

The gem's job did not move into the runtime. It stopped existing.

The honest footnote: the emitted tree still lists nio4r in its Gemfile, because that same tree runs under CRuby and Puma as the ruby lane on the benchmark page. The gem is not gone from the project. It is irrelevant to the binary.

Two things I'd rather have learned cheaply

A discriminator beats a mechanism. Matz nearly sent me a story about thread placement; I sent him one about request cost. Both wrong. What closed the issue in a single round trip was a much smaller claim: the mutex shape is flat from two workers onward and a scheduler problem is not — a question my machine could answer and his could not. A wrong mechanism costs the other person a day building a server to disprove it. A wrong discriminator costs one run.

The thing measured was not the thing changed. I added the allocator to the manifest, rebuilt, ran ldd, saw no jemalloc, and briefly concluded the merged feature didn't work. make had printed "Nothing to be done" — the manifest wasn't a prerequisite of the binary — and ldd was reading an hour-old file. Matz was caught the same week by a stale runtime archive, which is what that second PR turned out to be. Different tools, same failure.

What's next

The six-times gap is a fragment cache, and that is the next real piece of work: Campfire's own cached: true partials, served from something in-process rather than Redis.

And one candidate I want to name without claiming: there is a second process-global mutex on the query path. Preparing a statement takes it, because SQLite's out-buffer here is one eight-byte slot in static storage for the whole process — so unlike the pool, it cannot be sharded, only avoided. Today the emitted SQL inlines its literals, so the statement cache keys per value and misses reach that lock; with placeholders the key would be the query shape and the misses would mostly stop. Whether that matters depends entirely on how often it misses, which I have not measured — the profile that would have told me was taken while the pool lock was serializing everything anyway, and a second lock behind a first one costs nothing you can see. It is the same shape, one lock further down, and it is the first place I'll look.

Below that, three smaller threads. Matz's uncontended-mutex fix pays out precisely where contention has been engineered away, so the shard count — currently capped at eight — is now worth more than when I set it. Per-request CPU still rises with worker count, which is the tail of the original complaint and not yet explained. And that benchmark page measures two expensive pages only, which makes it blind to exactly the class of bug this whole hunt was about: the sharded pool was worth more than three times on a cheap route and shows as +1.9% there.

The caveats from the last post still hold. Attachments and uploaded avatars are out of scope, web push logs its failure per message on purpose, and our fan-out is in-process where deployed Campfire's crosses Redis. The socket numbers are published with the driver's own cost beside them, because a fan-out tail above a thousand sockets is a measurement of the client as much as the server.

Roundhouse is open source: dual-licensed MIT / Apache-2.0. Issues and discussion welcome.