intertwingly

It’s just data

Campfire, Cached


Two days ago I published a benchmark page whose headline was that Rails wins, and ended the post by naming what would change it:

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.

That is done. On the room page, deployed Campfire serves 344 requests a second and the binary serves 538. The number on that page was 56.

deployed Rails the binary
/rooms/1 346 req/s 538
/rooms/1/messages 679 req/s 897
p99, room page 162 ms 68 ms
memory (PSS) 1,800 MB 268 MB
cold start to a page 4,533 ms 363 ms
1,000 WebSockets, time to connect 2.22 s 0.72 s
1,000 idle WebSockets, CPU 0.011 cores 0.009 cores
1,000 idle WebSockets, memory 598 MB 156 MB
delivering to 1,000 sockets 0.169 cores 0.038 cores

The comparison has not been made easier. That rails lane is still Campfire as its own Dockerfile runs it: Thruster in front of Puma, Campfire's own worker formula — eight on this box — five threads each, jemalloc, resque-pool alongside, and Redis serving the fragments. The binary is one process.

One of our processes beats their eight.

What it took

Campfire renders its message list as render partial: …, cached: true, and each message partial wraps its whole body in <% cache [message, "presentation-v2"] %>. With Redis up, Rails reads those forty fragments back instead of rendering them. We rendered all forty, every request.

The lowering now serves them from a process-local store. The mechanical part was small; the parts worth naming are the three places it could have gone quietly wrong.

Invalidation had to land first. belongs_to :message, touch: true was parsed by nothing — Campfire's Boost and Message both declare it, and both were silently no-ops. Without that, boosting a message never moves its updated_at, the fragment key never changes, and the cache serves the wrong page forever. No behavioural test can see it, because nothing renders updated_at. Base#touch now fires after_touch, which is what makes the cascade transitive: a boost touches its Message, and Message's own touch: true carries it to the Room.

The key builder declines rather than guesses. It claims exactly two shapes — a literal, and a name that is both one of the view's locals and a model's singular. Anything else renders transparently, as it did before there was a store. A key that misses costs a render; a key that collides serves the wrong bytes, and nothing in the repository would catch that, because the comparison harness renders each lane once from cold.

Request renders and broadcast renders cannot share an entry. The same partial is rendered both for a page and for a WebSocket broadcast, and the broadcast deliberately omits the CSRF input. Cached under one key, whichever render arrives first decides for everyone. Rails has this hazard and lives with it — it is the one divergence our comparison harness forgives by name — and a namespace in the key costs one prefix and removes it.

/rooms/1/messages went from 127 SQLite round trips to 7. Rails spends 7. That page was never a language story: Campfire's messages index preloads only with_creator, so boosts, rich text and attachments are N+1 in Rails too — its own renderer costs the same 127. Its 7 was Redis. Ours is now a hash lookup.

Two parts, and the page can price them separately

This is the part I find most useful, and it exists only because the same emitted application runs on two runtimes. Roundhouse lowers Rails to ordinary Ruby; Spinel compiles that Ruby to a binary. Those are different pieces of work by different people, and the benchmark can separate them.

Hold the runtime fixed and vary only the framework. rails-1p and ruby-1p are both CRuby 4.0.5, both Puma, both one worker of five threads, both jemalloc, the same SQLite file, the same seed, the same page, neither carrying a proxy or a job runner. The single variable is Rails against roundhouse's lowered output:

per process /rooms/1 /rooms/1/messages
Rails 41 req/s 83 req/s
+ the lowering 187 (4.6x) 417 (5.0x)
+ the compiler 538 (2.9x) 897 (2.2x)
against Rails' one process 13.3x 10.8x

The factors multiply out: 4.6 × 2.9 = 13.3. And 538 against their eight processes plus Thruster plus resque-pool plus Redis is the 1.55x at the top of this post.

The same split, on a different axis

The socket tier used to run two lanes. It runs three now, and the third settles a question the other two could not: is our WebSocket layer cheap because of the design, or because of the compiler?

Both emit lanes run the same cable.rb — one event loop, one shared heartbeat, a thread per connection doing ordinary blocking reads. Only the runtime underneath differs. 1,000 sockets, 50 per room, pinned to four cores:

connect idle memory delivering frames
deployed Rails 2.2 s 0.0110 598 MB 0.169 cores 1500/1500
the emit on CRuby 1.0 s 0.0080 197 MB 0.042 cores 1500/1500
the binary 0.7 s 0.0090 156 MB 0.038 cores 1500/1500

On the two axes that matter for holding connections open — what it costs to sit idle and what it costs to deliver — the two emit lanes are indistinguishable, and Rails costs 4.3x more to deliver through. Same design, two runtimes, same answer. So "our cable is cheap" is a claim about the design, and it would survive being compiled by something else. What the binary adds on top is memory: 152 MB against 194, and against Rails' 604.

And one row where we lost, which turned out to be the most useful row on the page. The binary took six seconds to accept a thousand connections where the same code on CRuby took one, on a quarter the workers, while burning only two seconds of CPU — waiting, not computing.

It was not the accept loop, which does about ten thousand accepts a second, and not the listen backlog, which is a thousand deep. Campfire writes a presence row per connection, and the storm was one fsync per write: with presence writes disabled it fell from 5.87s to 0.32s, and a thousand WAL commits on that box cost 5.573s at synchronous=FULL against 0.046s at NORMAL. The 5.55 seconds of difference and the 5.57 seconds of raw fsync are the same number.

The part I did not expect is that this was in nobody's code. Asked directly, Rails' live connection answers synchronous = 1, and so does the CRuby emit's — which sets no pragmas at all. Both link the sqlite3 gem's bundled SQLite, whose WAL default is NORMAL. The binary links its own, which defaults to FULL. Three lanes on one benchmark were running two different durability settings, decided by a compile-time default nobody had written down. So it was not only slow, it was not a like-for-like comparison: every write-path number was measuring our durability guarantee against theirs.

All three now state it rather than agreeing by accident. Connect went 6.13s to 0.72s, which makes the binary the fastest lane on that axis rather than the slowest, and the fan-out median fell from 32.0 to 9.2 ms — its p99 from 80 to 56 — because posting a message is a write too.

That column is the reason to run three lanes instead of two. With one implementation of a design you cannot tell a design's cost from a runtime's bug — and with two, the one that disagreed is what pointed at a setting neither of them had chosen.

What the second column is not

It is tempting to read "2.8x" as "the compiled code is 2.8x faster." It is not, and the honest version is more interesting.

Compare one core against one core — one Spinel OS worker against one CRuby worker — and the two are close: 1.24x on the room page and 0.98x on the messages page. The 2.8x is almost entirely that CRuby needs eight processes to use eight cores and Spinel uses six in one. The GVL is the whole column.

That is also why the fragment cache is possible at all. One process is one cache, one Action Cable registry, no Redis. The compiler's contribution here is not that it emits faster instructions; it is that it removes the reason to run more than one process — and everything in-process follows from that.

I want to be careful about the per-core number, because it is the kind of measurement that invites a conclusion it cannot support. It does not say Spinel's code generation is at parity with YJIT. The input to Spinel's compiler is roundhouse's output; if we emit polymorphic slots or untyped dispatch or needless string churn, that measurement bills our lowering to their backend. Separating the two needs a run of a different application at one core each, which we have not done. What is attributable, because it was measured directly: on this page the binary spends 49% of wall time in the collector, with the mark phase dominant and growing as workers are added. Neither codegen nor lowering explains that away.

What did not get fixed

The ruby lane — the same emitted application on CRuby — serves 1,551 req/s on the room page, which is 4.6x deployed Rails. I am not going to claim that one, because that lane runs eight Puma processes, and the emitted tree cannot honestly deploy at eight: its Action Cable registry is per-process, so a broadcast reaches only the subscribers who happen to share a process with the poster. Its deployable shape today is one worker, and one worker loses to eight of theirs.

The fix is not large — a transport behind the Broadcasts.set_transport seam that already exists, which for CRuby means Redis, the same answer Rails reached for the same reason. It is on the list, and the benchmark page now says so beside the lane rather than leaving a reader to assume.

The part I did not expect

The last post was a story about one person filing issues against another person's compiler. That is not what this week was.

Matz filed three issues against roundhouse — a count after group typed as an integer, a format.turbo_stream that failed to dispatch, and a doctor command that could not find wrk on Debian. All three are closed. The maintainer of the compiler is now filing bugs against the thing that feeds it.

Someone neither of us asked showed up. Bart Leusink profiled the emitted Campfire binary, found that under threads the remembered-set clear walked the entire old heap on every non-full collection — work proportional to live data for a job proportional to stores — and deleted four lines. It was worth 45% at moderate concurrency and 67% at high on his box, and 18% on ours. His note explains why he used our application: "Nothing in benchmark/ exercises the collector under concurrency, so this is the only threaded-GC workload I could find."

Then he shipped the instrument that found it: a flag that splits collector time into mark, old sweep, slot sweep, remembered clear, string sweep and trim. He had held it back so the fix could stand on its own, and asked whether it was worth a pull request of its own.

It was. We armed it on a worker ladder the same evening and it said something the totals could not: as workers go from one to twelve, the sweep that gets the parked workers halves per collection while mark doubles — with the live object heap flat at 18 MB throughout. I filed that as an issue against Spinel, with his counter as the evidence, and the benchmark now captures the phase split nightly, because it cannot be recovered after the fact.

Then Matz corrected the half of it I had guessed at.

The title was right and duller than I thought: nothing distributes the mark. The young sweep is handed to the parked workers explicitly; the mark runs on the collector thread alone, by design. So the control I was proud of was measuring the difference between a phase that was distributed and one that was not.

But I had also written that mark grew because there were more worker stacks to scan, flagged as a guess. It was not merely unproven, it was wrong — the collector's roots are thread-local, so it walks only its own. He held the live heap and the green-thread count fixed, varied only the worker count, and mark came out flat. What it actually tracks is suspended fibers: every parked green thread's saved stack is a root set, and its size is how deep that thread was when it yielded. On a server the worker count is a proxy for how many requests are mid-render at once.

He asked for one experiment — pin the workers, vary the concurrency instead — and it confirmed his reading on the application, more sharply than his own synthetic could:

connections mark ms/request slot sweep ms/request
4 0.317 0.195
16 0.525 0.153
64 0.812 0.190

Mark rises 2.6x per unit of work; the sweep beside it does not move. That also explains the thing I had noticed and could not place — the live heap staying flat while mark grew. The graph was not growing. The root set was.

And there is a version of this I did not expect at all. Asked when Spinel gets a 0.1, Matz listed three things. Two are done — the subset is documented, the behaviour is pinned by 2587 programs diffed against CRuby. The third is open:

The runtime holds up on a real application. … the way that is going is one defect at a time against a Rails-shaped app someone else is running. … So: after the collector is default-on and that application runs clean.

The app is this one. So this week the generational collector went from "opt-in, and we file what it breaks" to something I could put evidence behind: under SPINEL_GC_MINOR=1 the room page is byte-identical, the write barrier demonstrably fires, and across five interleaved rounds it is not merely clean but 4% faster, winning every round — with the gain landing in mark, which is the phase it exists to shrink. That is filed too, including the part that argues against it: what our fragment cache retains is strings, and mark walks the object heap, so this is a weaker test of whole-heap marking than the word "retention" suggests.

So the traffic runs three ways now: Matz filing against us, a contributor we had never met improving the compiler using our application as the workload, and us filing back using the instrument he wrote — and correcting a mechanism I had guessed at. A fix in either repository shows up on the same page within a day. That is a better position than being fast.

What's next

The ruby lane's cross-process pubsub, so that column is a deployment claim and not only a runtime comparison.

The fiber root scan, which is now the ceiling: throughput plateaus at eight workers and the process holds about six of twelve cores. The sweep beside it is already handed to the parked workers; the root walk is not, and whether it can be is a design question rather than a patch. That is upstream, and it is filed.

And the honest gap in the second column above — one run of a second application at one core each, so the next time someone asks whether that parity is the compiler or the code we hand it, the page answers instead of me.

One more thing the connect storm changed my mind about. I had filed it in my head as a runtime bug to chase upstream, and it was a line of configuration on our side that made every write-path number on the page incomparable. The lanes that look wrong are worth more than the lanes that look right, and they are worth most when there are enough of them to disagree.


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