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: truepartials, 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.